Invalid order events treatment #2124

squadgazzz · 2023-12-05T18:02:30Z

Description

Closes pt2 of the issue #1977:

special treatment for invalid events (maybe only store another invalid event when the order was previously NOT invalid; meaning only store state changes)

Changes

Insert Invalid order event if the latest order event label is not Invalid.

How to test

Covered with an e2e test.

squadgazzz · 2023-12-06T13:41:58Z

crates/e2e/tests/e2e/tracking_insufficient_funds.rs

+        events_a.last().map(|o| o.label) == Some(OrderEventLabel::Traded)
+            && events_b.last().map(|o| o.label) == Some(OrderEventLabel::Traded)
+            && check_non_consecutive_invalid_events(&events_a)
+            && check_non_consecutive_invalid_events(&events_b)


This test doesn't pass on the main branch.

squadgazzz · 2023-12-06T13:42:55Z

crates/e2e/tests/e2e/tracking_insufficient_funds.rs

+        events_a.len() > 2
+            && check_non_consecutive_invalid_events(&events_a)
+            && order_b_correct_events


This test doesn't pass on the main branch.

squadgazzz · 2023-12-07T08:50:20Z

crates/database/src/order_events.rs

+    const QUERY: &str = r#"
+        WITH cte AS (
+            SELECT label
+            FROM order_events
+            WHERE order_uid = $1
+            ORDER BY timestamp DESC
+            LIMIT 1
+        )
+        INSERT INTO order_events (order_uid, timestamp, label)
+        SELECT $1, $2, $3
+        WHERE NOT EXISTS (
+            SELECT 1
+            FROM cte
+            WHERE label = 'invalid'
+        )


In staging, this query takes around ~~60ms~~(after other PRs are merged) ~5ms.

This is concerning because that doesn't bode well for prod. 😬
Currently we discard around 520 orders from every auction because the owner does not have enough balance. If we go down this path we should probably spawn a background task for this insert as well.

Can you execute the query like this in prod to test? Not sure if this helps, but we could add another boolean column in the table "latest" and then for every insert first update the latest record to be false. An index on this column could make lookups much faster.

According to the query planner the query used in this PR is constant time because we already have a sorted index on (order_uid, timestamp).
It simply scans the index for the given uid backwards and because we are only interested in the last row we only do a single iteration during the scan.

crates/e2e/tests/e2e/tracking_insufficient_funds.rs

MartinquaXD · 2023-12-07T13:39:00Z

crates/autopilot/src/solvable_orders.rs


        let orders = filter_dust_orders(orders, &balances, self.ethflow_contract_address);
        let removed = counter.checkpoint("dust_order", &orders);
-        order_events.extend(removed.into_iter().map(|o| (o, OrderEventLabel::Filtered)));
+        filtered_order_events.extend(removed.into_iter().map(|o| (o, OrderEventLabel::Filtered)));


I like your change to collect OrderUids into different buckets depending on the label.
This can be applied to filtered_orders as well to make the code less verbose.

MartinquaXD · 2023-12-07T13:49:16Z

crates/database/src/order_events.rs

+    const QUERY: &str = r#"
+        WITH cte AS (
+            SELECT label
+            FROM order_events
+            WHERE order_uid = $1
+            ORDER BY timestamp DESC
+            LIMIT 1
+        )
+        INSERT INTO order_events (order_uid, timestamp, label)
+        SELECT $1, $2, $3
+        WHERE NOT EXISTS (
+            SELECT 1
+            FROM cte
+            WHERE label = 'invalid'
+        )


This is concerning because that doesn't bode well for prod. 😬
Currently we discard around 520 orders from every auction because the owner does not have enough balance. If we go down this path we should probably spawn a background task for this insert as well.

Co-authored-by: Martin Beckmann <[email protected]>

# Conflicts: # crates/database/src/order_events.rs

MartinquaXD

Code looks good. 👍
I'm still a bit worried about the 60ms per order event insert.
Maybe we should consider purging the databases from all duplicated Invalid events before merging (the assumption is that this should speed up the query)?

squadgazzz · 2023-12-14T10:17:46Z

I'm still a bit worried about the 60ms per order event insert.
Maybe we should consider purging the databases from all duplicated Invalid events before merging (the assumption is that this should speed up the query)?

Tested the query once again after the order_events relief PRs are merged, and now it works way faster in staging ~5ms. We can probably skip the purging step.

fleupold

LGTM

fleupold · 2023-12-15T18:40:55Z

crates/autopilot/src/solvable_orders.rs


        let orders = filter_mispriced_limit_orders(orders, &prices, &self.limit_order_price_factor);
        let removed = counter.checkpoint("out_of_market", &orders);
-        order_events.extend(removed.into_iter().map(|o| (o, OrderEventLabel::Filtered)));
+        filtered_order_events.extend(removed);


Oh wow, the code is quite lavish with the reasons for which it excludes orders. Would love to see all of those go away (and be done in the driver eventually). This has nothing to with this PR of course.

fleupold · 2023-12-15T18:44:06Z

crates/autopilot/src/solvable_orders.rs

+        let db = self.database.clone();
+        tokio::spawn(async move {
+            db.store_invalid_order_events(&invalid_order_uids).await;
+            db.store_order_events(


Shouldn't we also store just state changes for Filtered orders? What's the point of seeing multiple Filtered events in a row? This would make the insert code more consistent.

Could not analyze prod data since SQL queries are a bit complex to find occurrences of subsequent invalid/filtered labels within a single order. Staging data was used to calculate the ratio of subsequent events with the same label, while prod data was used to determine the ratio between events with different labels:

There are around 45% of invalid events where ~99% are subsequent, meaning the table size is expected to be decreased by ~45%(14GB).

Around 22% of filtered events will remain in the table and ~70% are subsequent. So, approximately ~15% could be additionally removed(2.5GB) from the remaining data.

In summary: 45% or reduction with invalid retreatment only and 55% including filtered.

fleupold · 2023-12-15T18:46:09Z

crates/database/src/order_events.rs

+    const QUERY: &str = r#"
+        WITH cte AS (
+            SELECT label
+            FROM order_events
+            WHERE order_uid = $1
+            ORDER BY timestamp DESC
+            LIMIT 1
+        )
+        INSERT INTO order_events (order_uid, timestamp, label)
+        SELECT $1, $2, $3
+        WHERE NOT EXISTS (
+            SELECT 1
+            FROM cte
+            WHERE label = 'invalid'
+        )


Can you execute the query like this in prod to test? Not sure if this helps, but we could add another boolean column in the table "latest" and then for every insert first update the latest record to be false. An index on this column could make lookups much faster.

# Conflicts: # crates/autopilot/src/solvable_orders.rs # crates/e2e/tests/e2e/tracking_insufficient_funds.rs

fleupold

Looks good. I'd still slightly prefer if all order events are handled the same way, but not blocking this PR.

fleupold · 2023-12-26T18:55:27Z

crates/autopilot/src/solvable_orders.rs

@@ -231,9 +232,23 @@ impl SolvableOrdersCache {
            prices,
        };
        let removed = counter.record(&auction.orders);
-        order_events.extend(removed.into_iter().map(|o| (o, OrderEventLabel::Filtered)));
-
-        self.database.store_order_events(&order_events).await;


Do we still need the old method (I feel like all order events should only be updated if non-subsequent). If so, the method could also be called more neutral (ie, keep store_order_events but make it only store non subsequent events)

It was already mentioned here: #1977 (comment). And I think it was additionally discussed with @MartinquaXD. Filtering other labels such as Ready, Considered extends the time period between the events. If that won't harm metrics/debugging, we can apply this logic to all the events.

Filtering other labels such as Ready, Considered extends the time period between the events.

Do you see any way in which this could make a difference? If I understand correctly ready, considered, considered, traded would become ready, considered, traded which seems fine. To me this metric should allow to track the state machine for the lifecycle of an order.

@MartinquaXD mentioned that the current metric where order_evets table is used is going to be improved. But I don't have enough context in which way.
Currently, we have something like ready->ready->ready->traded where we can clearly see the time difference between the latest ready and traded events. With filtering ready events, the difference becomes bigger. For some of the subsequent labels, we can only update their timestamps. But for the invalid label, for example, we care about the initial timestamp rather than the latest one. Anyways, would need more context from Martin 🙂

I'm pretty sure we always care about the initial timestamp (for ready -> ready -> traded, we should measure our performance from when your order first became ready).

Given Martin is off until the 8th feel free to merge either with or without the unification (but please follow up before closing the issue)

crates/database/src/order_events.rs

Invalid order events treatment

9d11db8

squadgazzz force-pushed the invalid-order-events-treatment branch from 189b96c to 9d11db8 Compare December 6, 2023 13:33

squadgazzz changed the base branch from store-market-order-events-only to main December 6, 2023 13:34

squadgazzz marked this pull request as ready for review December 6, 2023 13:37

squadgazzz requested a review from a team as a code owner December 6, 2023 13:37

squadgazzz commented Dec 6, 2023

View reviewed changes

squadgazzz commented Dec 7, 2023

View reviewed changes

MartinquaXD reviewed Dec 7, 2023

View reviewed changes

squadgazzz and others added 5 commits December 7, 2023 14:56

Update crates/e2e/tests/e2e/tracking_insufficient_funds.rs

4ce979d

Co-authored-by: Martin Beckmann <[email protected]>

Update crates/e2e/tests/e2e/tracking_insufficient_funds.rs

93d3ee1

Co-authored-by: Martin Beckmann <[email protected]>

Review fixes

7c29222

Comment

87d5848

Merge branch 'main' into invalid-order-events-treatment

6d462a8

# Conflicts: # crates/database/src/order_events.rs

squadgazzz requested review from MartinquaXD and a team and removed request for MartinquaXD December 13, 2023 16:54

MartinquaXD approved these changes Dec 13, 2023

View reviewed changes

squadgazzz marked this pull request as draft December 13, 2023 18:03

squadgazzz marked this pull request as ready for review December 14, 2023 10:16

squadgazzz added 2 commits December 14, 2023 10:18

Merge branch 'main' into invalid-order-events-treatment

0e971b0

Merge fix

66aa3ef

fleupold approved these changes Dec 15, 2023

View reviewed changes

squadgazzz added 3 commits December 25, 2023 11:02

Merge branch 'main' into invalid-order-events-treatment

0ae3163

# Conflicts: # crates/autopilot/src/solvable_orders.rs # crates/e2e/tests/e2e/tracking_insufficient_funds.rs

Merge fix

309ac73

Filtered order events

5a2e026

squadgazzz requested a review from a team December 25, 2023 12:13

fleupold approved these changes Dec 26, 2023

View reviewed changes

Redundant param

00e1b43

Merge branch 'main' into invalid-order-events-treatment

fbfb16d

squadgazzz enabled auto-merge (squash) December 28, 2023 19:00

squadgazzz merged commit c509f76 into main Dec 28, 2023
8 checks passed

squadgazzz deleted the invalid-order-events-treatment branch December 28, 2023 19:04

github-actions bot locked and limited conversation to collaborators Dec 28, 2023

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Invalid order events treatment #2124

Invalid order events treatment #2124

squadgazzz commented Dec 5, 2023 •

edited

Loading

squadgazzz Dec 6, 2023

squadgazzz Dec 6, 2023

squadgazzz Dec 7, 2023 •

edited

Loading

MartinquaXD Dec 7, 2023

fleupold Dec 15, 2023

MartinquaXD Dec 18, 2023 •

edited

Loading

MartinquaXD Dec 7, 2023

MartinquaXD Dec 7, 2023

MartinquaXD left a comment •

edited

Loading

squadgazzz commented Dec 14, 2023

fleupold left a comment

fleupold Dec 15, 2023

fleupold Dec 15, 2023

squadgazzz Dec 25, 2023 •

edited

Loading

fleupold Dec 15, 2023

fleupold left a comment

fleupold Dec 26, 2023

squadgazzz Dec 26, 2023 •

edited

Loading

fleupold Dec 27, 2023

squadgazzz Dec 27, 2023

fleupold Dec 27, 2023

Invalid order events treatment #2124

Invalid order events treatment #2124

Conversation

squadgazzz commented Dec 5, 2023 • edited Loading

Description

Changes

How to test

Choose a reason for hiding this comment

Choose a reason for hiding this comment

squadgazzz Dec 7, 2023 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

MartinquaXD Dec 18, 2023 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

MartinquaXD left a comment • edited Loading

Choose a reason for hiding this comment

squadgazzz commented Dec 14, 2023

fleupold left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

squadgazzz Dec 25, 2023 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

fleupold left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

squadgazzz Dec 26, 2023 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

squadgazzz commented Dec 5, 2023 •

edited

Loading

squadgazzz Dec 7, 2023 •

edited

Loading

MartinquaXD Dec 18, 2023 •

edited

Loading

MartinquaXD left a comment •

edited

Loading

squadgazzz Dec 25, 2023 •

edited

Loading

squadgazzz Dec 26, 2023 •

edited

Loading