feat(autopilot): reduce excessive looping of main loop

[kaze-cow]

Description

Currently the run_fovever loop in autopilot will continue looping without waiting as long as there is no auction to process and the block phase is still early enough. This is ofc not efficient and makes it difficult to view debug logs in the playground as they are spammed every time a block is mined. Technically an event listener is likely to be able to process events faster than a 50ms database scanning loop (as it is now)

Changes

• Add postgresql notification on new order added to order table
• Listen to notification and trigger the main loop if it
• Update playground logs verbosity configuration to make it easier to track loop status. Now that the logs don't spam as a result of infinite looping, these changes make sense!
• Verify that the loop is being executed on block and on order in the playground

How to test

1. Run the playground as normal docker compose -f playground/docker-compose.fork.yml up --build

• you may have to delete and recreate your existing playground with docker compose -f playground/docker-compose.fork.yml down --volumes

2. When all services stabilize, run playground/test_playground.sh
3. Observe logs indicating that the order even was received

[github-actions]

Reminder: Please update the DB Readme and comment whether migrations are reversible (include rollback scripts if applicable).

• If creating new tables, update the tables list.
• When adding a new index, consider using CREATE INDEX CONCURRENTLY for tables involved in the critical execution path.
• For breaking changes, remember that during rollout k8s starts the new autopilot, runs the Flyway migration, and only then shuts down the old pod. That overlap means the previous version can still be processing requests on the migrated schema, so make it compatible first and ship the breaking DB change in the following release.

---

Caused by:

• database/sql/V094__add_order_notification_trigger.sql

[MartinquaXD]

Putting everything in one huge nested statement makes it quite hard to read. Instead you could just smaller match statements with early returns like this:

let mut listener = match sqlx::postgres::PgListener::connect_with(&pool).await {
    Ok(listener) => listener,
    Err(err) => {
        tracing::error!(?err, "failed to create PostgreSQL listener");
        tokio::time::sleep(Duration::from_secs(5)).await;
        continue;
    }
}

[kaze-cow]

it looks a bit better with the early return as you suggest, but it still not that great.

I'm torn. do you think it would be best to create a nested function for the inner loop and use ? to resolve the Results? but then we don't get specific error messages for each different place an error could happen. I wonder if there is some other way to make this nice for loops in rust...

[jmg-duarte]

LGTM

[fafk]

I would place it after line 175, after

            // caches are warmed up, we're ready to do leader work
            if let Some(startup) = self_arc.probes.startup.as_ref() {
                startup.store(true, Ordering::Release);
            }

so it doesn't wait on startup before it warms up the caches, which takes a lot of time and should be done right away. LGMT otherwise, 👌

[kaze-cow]

ooh good idea. but then wouyldn't the caches potentially be stale by the time the auction starts?

[fafk]

For networks which are not mainnet it doesn't really matter, because they have super short block times and little traffic. And for mainnet you are right, but the query on startup takes 10+ seconds, so I think we're actually increasing the likelihood of order getting into the auction earlier. 🤔 Under normal circumstances it doesn't matter, because an autopilot instance which is on standby will become leader and it will have its caches warmed up. tl;dr my suggestion is a actually a nit and not very relevant in the grand scheme of things.

[kaze-cow]

ok so if on all networks except network it is not important, and on mainnet its unclear if it would help or not... your explanation makes sense though, especially considering auctions take more than one block to get going anyway. I will go head and move it to after cache warm up as you suggest.

[squadgazzz]

Should we also account for ethflow orders then? ethflow_orders table.

[kaze-cow]

Should we also account for ethflow orders then? ethflow_orders table.

there was a previous comment about this, and it was discovered that all orders end up in the same table, including ethflow/onchain orders. I just double checked and the specific table you mentioned appears to be updated in the same loop as the orders table inserts https://github.com/cowprotocol/services/blob/main/crates/autopilot/src/database/onchain_order_events/mod.rs#L368 in append_custom_order_info_to_db

[squadgazzz]

LGTM

[kaze-cow]

the test was failing because with the recent change to put the loop wait after the cache generation, a new block is only minted once before the test verifies the condition (in this case, of an order being cancelled after being placed), and auction order cache does not repopulated. for now I have added additional block minting to the wait_for_condition loop.

(btw I wasn't able to replicate this test failure on my local machine, so seems it could be considered flaky)