Closed
Description
Why
We have noticed some timeout occurring when acquiring a pooled resource during the update of the pool for Merkle map used by the Cardano transaction prover with the following error message: Resource pool 'acquire_resource' has timed out
{"msg":"RUNNER: create artifact","v":0,"name":"slog-rs","level":20,"time":"2024-06-27T10:47:06.388041689Z","hostname":"891e6000d0f1","pid":1}
{"msg":"MithrilSignedEntityService::create_artifact","v":0,"name":"slog-rs","level":30,"time":"2024-06-27T10:47:06.388116866Z","hostname":"891e6000d0f1","pid":1,"certificate_hash":"f050a011c0076c3e0d08fb3d887698abb4b509bd71f040a14849f9eec17fd20f","signed_entity_type":"CardanoTransactions(Epoch(493), 10499340)"}
{"msg":"Prover starts computing the Merkle map pool resource of size 50","v":0,"name":"slog-rs","level":30,"time":"2024-06-27T10:47:06.388169591Z","hostname":"891e6000d0f1","pid":1}
{"msg":"Prover is computing the Merkle map pool resource 1/50","v":0,"name":"slog-rs","level":20,"time":"2024-06-27T10:47:38.521631962Z","hostname":"891e6000d0f1","pid":1}
{"msg":"Prover is computing the Merkle map pool resource 13/50","v":0,"name":"slog-rs","level":20,"time":"2024-06-27T10:47:38.521721817Z","hostname":"891e6000d0f1","pid":1}
{"msg":"Prover is computing the Merkle map pool resource 26/50","v":0,"name":"slog-rs","level":20,"time":"2024-06-27T10:47:38.521767177Z","hostname":"891e6000d0f1","pid":1}
{"msg":"Prover is computing the Merkle map pool resource 7/50","v":0,"name":"slog-rs","level":20,"time":"2024-06-27T10:47:38.521821189Z","hostname":"891e6000d0f1","pid":1}
{"msg":"Prover is computing the Merkle map pool resource 4/50","v":0,"name":"slog-rs","level":20,"time":"2024-06-27T10:47:38.521979007Z","hostname":"891e6000d0f1","pid":1}
{"msg":"Prover is computing the Merkle map pool resource 2/50","v":0,"name":"slog-rs","level":20,"time":"2024-06-27T10:47:38.522083133Z","hostname":"891e6000d0f1","pid":1}
{"msg":"Prover is computing the Merkle map pool resource 19/50","v":0,"name":"slog-rs","level":20,"time":"2024-06-27T10:47:38.522274007Z","hostname":"891e6000d0f1","pid":1}
{"msg":"Prover is computing the Merkle map pool resource 5/50","v":0,"name":"slog-rs","level":20,"time":"2024-06-27T10:47:38.522338633Z","hostname":"891e6000d0f1","pid":1}
{"msg":"proof_cardano_transaction","v":0,"name":"slog-rs","level":40,"time":"2024-06-27T10:47:39.510267605Z","hostname":"891e6000d0f1","pid":1,"error":"Resource pool 'acquire_resource' has timed out\n\nCaused by:\n Acquire resource has timed out\n\nStack backtrace:\n 0: anyhow::context::<impl anyhow::Context<T,E> for core::result::Result<T,E>>::with_context\n 1: <mithril_aggregator::services::prover::MithrilProverService as mithril_aggregator::services::prover::ProverService>::compute_transactions_proofs::{{closure}}\n 2: <warp::filter::and_then::AndThenFuture<T,F> as core::future::future::Future>::poll\n 3: <warp::filter::or::EitherFuture<T,U> as core::future::future::Future>::poll\n 4: <warp::filter::or::EitherFuture<T,U> as core::future::future::Future>::poll\n 5: <warp::filters::cors::internal::WrappedFuture<F> as core::future::future::Future>::poll\n 6: <warp::filter::and::AndFuture<T,U> as core::future::future::Future>::poll\n 7: <warp::filter::recover::RecoverFuture<T,F> as core::future::future::Future>::poll\n 8: <warp::filter::and::AndFuture<T,U> as core::future::future::Future>::poll\n 9: scoped_tls::ScopedKey<T>::set\n 10: hyper::proto::h1::dispatch::Dispatcher<D,Bs,I,T>::poll_catch\n 11: <hyper::server::conn::upgrades::UpgradeableConnection<I,S,E> as core::future::future::Future>::poll\n 12: <hyper::server::server::new_svc::NewSvcTask<I,N,S,E,W> as core::future::future::Future>::poll\n 13: tokio::runtime::task::core::Core<T,S>::poll\n 14: tokio::runtime::task::harness::Harness<T,S>::poll\n 15: tokio::runtime::scheduler::multi_thread::worker::Context::run_task\n 16: tokio::runtime::scheduler::multi_thread::worker::Context::run\n 17: tokio::runtime::context::set_scheduler\n 18: tokio::runtime::context::runtime::enter_runtime\n 19: tokio::runtime::scheduler::multi_thread::worker::run\n 20: tokio::runtime::task::core::Core<T,S>::poll\n 21: tokio::runtime::task::harness::Harness<T,S>::poll\n 22: tokio::runtime::blocking::pool::Inner::run\n 23: std::sys_common::backtrace::__rust_begin_short_backtrace\n 24: core::ops::function::FnOnce::call_once{{vtable.shim}}\n 25: std::sys::pal::unix::thread::Thread::new::thread_start\n 26: start_thread\n 27: clone"}
{"msg":"Prover is computing the Merkle map pool resource 27/50","v":0,"name":"slog-rs","level":20,"time":"2024-06-27T10:47:41.882412993Z","hostname":"891e6000d0f1","pid":1}
{"msg":"Prover is computing the Merkle map pool resource 14/50","v":0,"name":"slog-rs","level":20,"time":"2024-06-27T10:47:41.904647361Z","hostname":"891e6000d0f1","pid":1}
{"msg":"Prover is computing the Merkle map pool resource 3/50","v":0,"name":"slog-rs","level":20,"time":"2024-06-27T10:47:41.933232198Z","hostname":"891e6000d0f1","pid":1}
{"msg":"Prover is computing the Merkle map pool resource 8/50","v":0,"name":"slog-rs","level":20,"time":"2024-06-27T10:47:41.998983424Z","hostname":"891e6000d0f1","pid":1}
{"msg":"Prover is computing the Merkle map pool resource 6/50","v":0,"name":"slog-rs","level":20,"time":"2024-06-27T10:47:42.000366253Z","hostname":"891e6000d0f1","pid":1}
{"msg":"Prover is computing the Merkle map pool resource 20/50","v":0,"name":"slog-rs","level":20,"time":"2024-06-27T10:47:42.055171076Z","hostname":"891e6000d0f1","pid":1}
{"msg":"Prover is computing the Merkle map pool resource 22/50","v":0,"name":"slog-rs","level":20,"time":"2024-06-27T10:47:42.113399149Z","hostname":"891e6000d0f1","pid":1}
{"msg":"Prover is computing the Merkle map pool resource 38/50","v":0,"name":"slog-rs","level":20,"time":"2024-06-27T10:47:42.175434075Z","hostname":"891e6000d0f1","pid":1}
{"msg":"Prover is computing the Merkle map pool resource 21/50","v":0,"name":"slog-rs","level":20,"time":"2024-06-27T10:47:45.463168133Z","hostname":"891e6000d0f1","pid":1}
{"msg":"Prover is computing the Merkle map pool resource 10/50","v":0,"name":"slog-rs","level":20,"time":"2024-06-27T10:47:45.487506925Z","hostname":"891e6000d0f1","pid":1}
{"msg":"Prover is computing the Merkle map pool resource 28/50","v":0,"name":"slog-rs","level":20,"time":"2024-06-27T10:47:45.487578015Z","hostname":"891e6000d0f1","pid":1}
{"msg":"Prover is computing the Merkle map pool resource 11/50","v":0,"name":"slog-rs","level":20,"time":"2024-06-27T10:47:45.488120671Z","hostname":"891e6000d0f1","pid":1}
{"msg":"Prover is computing the Merkle map pool resource 15/50","v":0,"name":"slog-rs","level":20,"time":"2024-06-27T10:47:45.492877779Z","hostname":"891e6000d0f1","pid":1}
{"msg":"Prover is computing the Merkle map pool resource 9/50","v":0,"name":"slog-rs","level":20,"time":"2024-06-27T10:47:45.510640611Z","hostname":"891e6000d0f1","pid":1}
{"msg":"Prover is computing the Merkle map pool resource 23/50","v":0,"name":"slog-rs","level":20,"time":"2024-06-27T10:47:45.668370243Z","hostname":"891e6000d0f1","pid":1}
{"msg":"Prover is computing the Merkle map pool resource 39/50","v":0,"name":"slog-rs","level":20,"time":"2024-06-27T10:47:45.743569198Z","hostname":"891e6000d0f1","pid":1}
{"msg":"Prover is computing the Merkle map pool resource 12/50","v":0,"name":"slog-rs","level":20,"time":"2024-06-27T10:47:48.933314298Z","hostname":"891e6000d0f1","pid":1}
{"msg":"Prover is computing the Merkle map pool resource 29/50","v":0,"name":"slog-rs","level":20,"time":"2024-06-27T10:47:48.93675814Z","hostname":"891e6000d0f1","pid":1}
{"msg":"Prover is computing the Merkle map pool resource 16/50","v":0,"name":"slog-rs","level":20,"time":"2024-06-27T10:47:48.985102574Z","hostname":"891e6000d0f1","pid":1}
{"msg":"Prover is computing the Merkle map pool resource 44/50","v":0,"name":"slog-rs","level":20,"time":"2024-06-27T10:47:49.001679286Z","hostname":"891e6000d0f1","pid":1}
{"msg":"Prover is computing the Merkle map pool resource 24/50","v":0,"name":"slog-rs","level":20,"time":"2024-06-27T10:47:49.006415203Z","hostname":"891e6000d0f1","pid":1}
{"msg":"Prover is computing the Merkle map pool resource 32/50","v":0,"name":"slog-rs","level":20,"time":"2024-06-27T10:47:49.029531628Z","hostname":"891e6000d0f1","pid":1}
{"msg":"Prover is computing the Merkle map pool resource 41/50","v":0,"name":"slog-rs","level":20,"time":"2024-06-27T10:47:49.112880572Z","hostname":"891e6000d0f1","pid":1}
{"msg":"Prover is computing the Merkle map pool resource 40/50","v":0,"name":"slog-rs","level":20,"time":"2024-06-27T10:47:49.225194259Z","hostname":"891e6000d0f1","pid":1}
{"msg":"Prover is computing the Merkle map pool resource 30/50","v":0,"name":"slog-rs","level":20,"time":"2024-06-27T10:47:52.411024349Z","hostname":"891e6000d0f1","pid":1}
{"msg":"Prover is computing the Merkle map pool resource 25/50","v":0,"name":"slog-rs","level":20,"time":"2024-06-27T10:47:52.47380472Z","hostname":"891e6000d0f1","pid":1}
{"msg":"Prover is computing the Merkle map pool resource 45/50","v":0,"name":"slog-rs","level":20,"time":"2024-06-27T10:47:52.47851289Z","hostname":"891e6000d0f1","pid":1}
{"msg":"Prover is computing the Merkle map pool resource 35/50","v":0,"name":"slog-rs","level":20,"time":"2024-06-27T10:47:52.517424012Z","hostname":"891e6000d0f1","pid":1}
{"msg":"Prover is computing the Merkle map pool resource 17/50","v":0,"name":"slog-rs","level":20,"time":"2024-06-27T10:47:52.566630573Z","hostname":"891e6000d0f1","pid":1}
{"msg":"Prover is computing the Merkle map pool resource 33/50","v":0,"name":"slog-rs","level":20,"time":"2024-06-27T10:47:52.570959019Z","hostname":"891e6000d0f1","pid":1}
{"msg":"Prover is computing the Merkle map pool resource 42/50","v":0,"name":"slog-rs","level":20,"time":"2024-06-27T10:47:52.681594923Z","hostname":"891e6000d0f1","pid":1}
{"msg":"Prover is computing the Merkle map pool resource 18/50","v":0,"name":"slog-rs","level":20,"time":"2024-06-27T10:47:52.737741052Z","hostname":"891e6000d0f1","pid":1}
{"msg":"Prover is computing the Merkle map pool resource 31/50","v":0,"name":"slog-rs","level":20,"time":"2024-06-27T10:47:56.011017205Z","hostname":"891e6000d0f1","pid":1}
{"msg":"Prover is computing the Merkle map pool resource 46/50","v":0,"name":"slog-rs","level":20,"time":"2024-06-27T10:47:56.062633936Z","hostname":"891e6000d0f1","pid":1}
{"msg":"Prover is computing the Merkle map pool resource 36/50","v":0,"name":"slog-rs","level":20,"time":"2024-06-27T10:47:56.084361339Z","hostname":"891e6000d0f1","pid":1}
{"msg":"Prover is computing the Merkle map pool resource 37/50","v":0,"name":"slog-rs","level":20,"time":"2024-06-27T10:47:56.149688538Z","hostname":"891e6000d0f1","pid":1}
{"msg":"Prover is computing the Merkle map pool resource 34/50","v":0,"name":"slog-rs","level":20,"time":"2024-06-27T10:47:56.162409016Z","hostname":"891e6000d0f1","pid":1}
{"msg":"Prover is computing the Merkle map pool resource 43/50","v":0,"name":"slog-rs","level":20,"time":"2024-06-27T10:47:56.250375375Z","hostname":"891e6000d0f1","pid":1}
{"msg":"Prover is computing the Merkle map pool resource 47/50","v":0,"name":"slog-rs","level":20,"time":"2024-06-27T10:47:56.295771827Z","hostname":"891e6000d0f1","pid":1}
{"msg":"Prover is computing the Merkle map pool resource 49/50","v":0,"name":"slog-rs","level":20,"time":"2024-06-27T10:47:56.329845209Z","hostname":"891e6000d0f1","pid":1}
{"msg":"Prover is computing the Merkle map pool resource 48/50","v":0,"name":"slog-rs","level":20,"time":"2024-06-27T10:47:59.432799051Z","hostname":"891e6000d0f1","pid":1}
{"msg":"Prover is computing the Merkle map pool resource 50/50","v":0,"name":"slog-rs","level":20,"time":"2024-06-27T10:47:59.510723937Z","hostname":"891e6000d0f1","pid":1}
What
Handle the rotation of the resources in the pool so that there is no downtime where the pool is empty and new resources are being computed: the new resources (or a share of them) should be computed before the pool is drained.
How
- Investigate the timeout
- Fix the resource pool refresh strategy by computing new resource items before draining the pool.