thread 'active_key_is_retired_not_outstanding_new_key_is_set_node_activated' panicked at fog/overseer/server/tests/retired_key_not_outstanding_idles_have_same_key.rs:47:12:
Timed out waiting for active node to process data; recovery_db has 6 blocks, target is 12
stack backtrace:
2024-09-30 20:40:35.038663486 UTC DEBG Checking up on peers..., mc.node_id: 2, mc.test_name: retired_key_not_outstanding_idles_have_same_key::active_key_is_retired_not_outstanding_new_key_is_set_node_activated, mc.module: mc_fog_ingest_server::worker, mc.src: fog/ingest/server/src/worker.rs:235
   0: rust_begin_unwind
             at /rustc/ca62d2c445628587660ae48013f460b08b1f5552/library/std/src/panicking.rs:597:5
   1: core::panicking::panic_fmt
             at /rustc/ca62d2c445628587660ae48013f460b08b1f5552/library/core/src/panicking.rs:72:14
   2: mc_fog_ingest_server_test_utils::IngestServerTestHelper::wait_till_recovery_db_callback
             at /__w/mobilecoin/mobilecoin/fog/ingest/server/test-utils/src/lib.rs:308:13
   3: mc_fog_ingest_server_test_utils::IngestServerTestHelper::wait_till_recovery_db_in_sync_up_to
             at /__w/mobilecoin/mobilecoin/fog/ingest/server/test-utils/src/lib.rs:279:9
   4: mc_fog_ingest_server_test_utils::IngestServerTestHelper::wait_till_recovery_db_in_sync
             at /__w/mobilecoin/mobilecoin/fog/ingest/server/test-utils/src/lib.rs:272:9
   5: retired_key_not_outstanding_idles_have_same_key::__wrapped_active_key_is_retired_not_outstanding_new_key_is_set_node_activated
             at ./tests/retired_key_not_outstanding_idles_have_same_key.rs:47:5
   6: retired_key_not_outstanding_idles_have_same_key::active_key_is_retired_not_outstanding_new_key_is_set_node_activated::{{closure}}
             at ./tests/retired_key_not_outstanding_idles_have_same_key.rs:18:1
   7: slog_scope::scope
             at /opt/cargo/registry/src/index.crates.io-6f17d22bba15001f/slog-scope-4.4.0/lib.rs:248:5
   8: retired_key_not_outstanding_idles_have_same_key::active_key_is_retired_not_outstanding_new_key_is_set_node_activated
             at ./tests/retired_key_not_outstanding_idles_have_same_key.rs:18:1
   9: retired_key_not_outstanding_idles_have_same_key::active_key_is_retired_not_outstanding_new_key_is_set_node_activated::{{closure}}
             at ./tests/retired_key_not_outstanding_idles_have_same_key.rs:18:1
  10: core::ops::function::FnOnce::call_once
             at /rustc/ca62d2c445628587660ae48013f460b08b1f5552/library/core/src/ops/function.rs:250:5
  11: core::ops::function::FnOnce::call_once
             at /rustc/ca62d2c445628587660ae48013f460b08b1f5552/library/core/src/ops/function.rs:250:5
note: Some details are omitted, run with `RUST_BACKTRACE=full` for a verbose backtrace.
2024-09-30 20:40:35.178969756 UTC INFO Disabling overseer worker, mc.test_name: retired_key_not_outstanding_idles_have_same_key::active_key_is_retired_not_outstanding_new_key_is_set_node_activated, mc.module: mc_fog_overseer_server::service, mc.src: fog/overseer/server/src/service.rs:114
2024-09-30 20:40:37.041121046 UTC DEBG Checking on peer: insecure-igp://0.0.0.0:8811/, mc.node_id: 0, mc.test_name: retired_key_not_outstanding_idles_have_same_key::active_key_is_retired_not_outstanding_new_key_is_set_node_activated, mc.module: mc_fog_ingest_server::controller, mc.src: fog/ingest/server/src/controller.rs:1363
2024-09-30 20:40:37.041231684 UTC WARN Creating insecure gRPC connection to 0.0.0.0:8811, mc.peers.addr: 0.0.0.0:8811, mc.node_id: 0, mc.test_name: retired_key_not_outstanding_idles_have_same_key::active_key_is_retired_not_outstanding_new_key_is_set_node_activated, mc.module: mc_util_grpc::grpcio_extensions, mc.src: util/grpc/src/grpcio_extensions.rs:48
2024-09-30 20:40:37.076795129 UTC DEBG Now ingesting block #6 (id = BlockID(556d297a69b9737405024e965f3d53461bb907058d217a078e393d27276f5ebd)), mc.node_id: 0, mc.test_name: retired_key_not_outstanding_idles_have_same_key::active_key_is_retired_not_outstanding_new_key_is_set_node_activated, mc.module: mc_fog_ingest_server::controller, mc.src: fog/ingest/server/src/controller.rs:428
2024-09-30 20:40:37.080711596 UTC INFO publishing report to DB, mc.node_id: 0, mc.test_name: retired_key_not_outstanding_idles_have_same_key::active_key_is_retired_not_outstanding_new_key_is_set_node_activated, mc.module: mc_fog_ingest_server::controller, mc.src: fog/ingest/server/src/controller.rs:1250
2024-09-30 20:40:37.081407265 UTC INFO update was a no-op, mc.test_name: retired_key_not_outstanding_idles_have_same_key::active_key_is_retired_not_outstanding_new_key_is_set_node_activated, mc.module: mc_fog_sql_recovery_db, mc.src: fog/sql_recovery_db/src/lib.rs:1194
2024-09-30 20:40:37.081531809 UTC INFO check ingress key passed, mc.test_name: retired_key_not_outstanding_idles_have_same_key::active_key_is_retired_not_outstanding_new_key_is_set_node_activated, mc.module: mc_fog_sql_recovery_db, mc.src: fog/sql_recovery_db/src/lib.rs:1197
2024-09-30 20:40:37.081587594 UTC INFO Got status for key: IngressPublicKeyStatus { start_block: 1, pubkey_expiry: 11, retired: true, lost: false }, mc.test_name: retired_key_not_outstanding_idles_have_same_key::active_key_is_retired_not_outstanding_new_key_is_set_node_activated, mc.module: mc_fog_sql_recovery_db, mc.src: fog/sql_recovery_db/src/lib.rs:1214
2024-09-30 20:40:37.081639912 UTC INFO Cannot publish key because it is retired, mc.test_name: retired_key_not_outstanding_idles_have_same_key::active_key_is_retired_not_outstanding_new_key_is_set_node_activated, mc.module: mc_fog_sql_recovery_db, mc.src: fog/sql_recovery_db/src/lib.rs:1216
2024-09-30 20:40:37.081787530 UTC DEBG Peer backup insecure-igp://0.0.0.0:8811/ was confirmed, mc.node_id: 0, mc.test_name: retired_key_not_outstanding_idles_have_same_key::active_key_is_retired_not_outstanding_new_key_is_set_node_activated, mc.module: mc_fog_ingest_server::controller, mc.src: fog/ingest/server/src/controller.rs:1378
2024-09-30 20:40:37.082314401 UTC DEBG Checking on peer: insecure-igp://0.0.0.0:8816/, mc.node_id: 0, mc.test_name: retired_key_not_outstanding_idles_have_same_key::active_key_is_retired_not_outstanding_new_key_is_set_node_activated, mc.module: mc_fog_ingest_server::controller, mc.src: fog/ingest/server/src/controller.rs:1363
2024-09-30 20:40:37.082402617 UTC WARN Creating insecure gRPC connection to 0.0.0.0:8816, mc.peers.addr: 0.0.0.0:8816, mc.node_id: 0, mc.test_name: retired_key_not_outstanding_idles_have_same_key::active_key_is_retired_not_outstanding_new_key_is_set_node_activated, mc.module: mc_util_grpc::grpcio_extensions, mc.src: util/grpc/src/grpcio_extensions.rs:48
2024-09-30 20:40:37.282918584 UTC DEBG Ingesting block #6: 4/4 txs ingested, mc.node_id: 0, mc.test_name: retired_key_not_outstanding_idles_have_same_key::active_key_is_retired_not_outstanding_new_key_is_set_node_activated, mc.module: mc_fog_ingest_server::controller, mc.src: fog/ingest/server/src/controller.rs:587
2024-09-30 20:40:37.282982134 UTC INFO add_block_data, mc.node_id: 0, mc.test_name: retired_key_not_outstanding_idles_have_same_key::active_key_is_retired_not_outstanding_new_key_is_set_node_activated, mc.module: mc_fog_ingest_server::controller, mc.src: fog/ingest/server/src/controller.rs:596
2024-09-30 20:40:37.291447277 UTC DEBG Peer backup insecure-igp://0.0.0.0:8816/ was confirmed, mc.node_id: 0, mc.test_name: retired_key_not_outstanding_idles_have_same_key::active_key_is_retired_not_outstanding_new_key_is_set_node_activated, mc.module: mc_fog_ingest_server::controller, mc.src: fog/ingest/server/src/controller.rs:1378
2024-09-30 20:40:38.038410752 UTC INFO Succeeded writing block 6 to the database, invocation id Some(IngestInvocationId(1)) ingress key CompressedRistrettoPublic(584efa1999c26f8ca467fee078038d111affe905dd4b3c58d6c359f2e03ecd73), mc.node_id: 0, mc.test_name: retired_key_not_outstanding_idles_have_same_key::active_key_is_retired_not_outstanding_new_key_is_set_node_activated, mc.module: mc_fog_ingest_server::controller, mc.src: fog/ingest/server/src/controller.rs:636
2024-09-30 20:40:38.038508616 UTC DEBG Incremented next block index: 7, mc.node_id: 0, mc.test_name: retired_key_not_outstanding_idles_have_same_key::active_key_is_retired_not_outstanding_new_key_is_set_node_activated, mc.module: mc_fog_ingest_server::controller_state, mc.src: fog/ingest/server/src/controller_state.rs:155
2024-09-30 20:40:38.038583617 UTC DEBG Controller state: { mode: Active, next_block_index: 7, pubkey_expiry_window: 10, ingest_invocation_id: 1, peers: [insecure-igp://0.0.0.0:8806/, insecure-igp://0.0.0.0:8811/, insecure-igp://0.0.0.0:8816/] }, mc.node_id: 0, mc.test_name: retired_key_not_outstanding_idles_have_same_key::active_key_is_retired_not_outstanding_new_key_is_set_node_activated, mc.module: mc_fog_ingest_server::controller, mc.src: fog/ingest/server/src/controller.rs:647
2024-09-30 20:40:38.038649992 UTC INFO Finished ingesting block #6, mc.node_id: 0, mc.test_name: retired_key_not_outstanding_idles_have_same_key::active_key_is_retired_not_outstanding_new_key_is_set_node_activated, mc.module: mc_fog_ingest_server::controller, mc.src: fog/ingest/server/src/controller.rs:659
2024-09-30 20:40:38.055553658 UTC DEBG Writing state file to StateFile { file_path: "/tmp/.tmp1hWspb/mc-fog-ingest-state-0" }, mc.node_id: 0, mc.test_name: retired_key_not_outstanding_idles_have_same_key::active_key_is_retired_not_outstanding_new_key_is_set_node_activated, mc.module: mc_fog_ingest_server::controller, mc.src: fog/ingest/server/src/controller.rs:1314
2024-09-30 20:40:38.086521018 UTC DEBG Checking up on peers..., mc.node_id: 1, mc.test_name: retired_key_not_outstanding_idles_have_same_key::active_key_is_retired_not_outstanding_new_key_is_set_node_activated, mc.module: mc_fog_ingest_server::worker, mc.src: fog/ingest/server/src/worker.rs:235
2024-09-30 20:40:38.109174120 UTC DEBG Now ingesting block #7 (id = BlockID(9709571e3d1140fc33b85c1c870e055b92756953ff42aa7e5299cafc78dde285)), mc.node_id: 0, mc.test_name: retired_key_not_outstanding_idles_have_same_key::active_key_is_retired_not_outstanding_new_key_is_set_node_activated, mc.module: mc_fog_ingest_server::controller, mc.src: fog/ingest/server/src/controller.rs:428
2024-09-30 20:40:38.113126324 UTC INFO publishing report to DB, mc.node_id: 0, mc.test_name: retired_key_not_outstanding_idles_have_same_key::active_key_is_retired_not_outstanding_new_key_is_set_node_activated, mc.module: mc_fog_ingest_server::controller, mc.src: fog/ingest/server/src/controller.rs:1250
2024-09-30 20:40:38.113790042 UTC INFO update was a no-op, mc.test_name: retired_key_not_outstanding_idles_have_same_key::active_key_is_retired_not_outstanding_new_key_is_set_node_activated, mc.module: mc_fog_sql_recovery_db, mc.src: fog/sql_recovery_db/src/lib.rs:1194
2024-09-30 20:40:38.113875984 UTC INFO check ingress key passed, mc.test_name: retired_key_not_outstanding_idles_have_same_key::active_key_is_retired_not_outstanding_new_key_is_set_node_activated, mc.module: mc_fog_sql_recovery_db, mc.src: fog/sql_recovery_db/src/lib.rs:1197
2024-09-30 20:40:38.113934624 UTC INFO Got status for key: IngressPublicKeyStatus { start_block: 1, pubkey_expiry: 11, retired: true, lost: false }, mc.test_name: retired_key_not_outstanding_idles_have_same_key::active_key_is_retired_not_outstanding_new_key_is_set_node_activated, mc.module: mc_fog_sql_recovery_db, mc.src: fog/sql_recovery_db/src/lib.rs:1214
2024-09-30 20:40:38.113992673 UTC INFO Cannot publish key because it is retired, mc.test_name: retired_key_not_outstanding_idles_have_same_key::active_key_is_retired_not_outstanding_new_key_is_set_node_activated, mc.module: mc_fog_sql_recovery_db, mc.src: fog/sql_recovery_db/src/lib.rs:1216
2024-09-30 20:40:38.291968360 UTC DEBG Checking up on peers..., mc.node_id: 0, mc.test_name: retired_key_not_outstanding_idles_have_same_key::active_key_is_retired_not_outstanding_new_key_is_set_node_activated, mc.module: mc_fog_ingest_server::worker, mc.src: fog/ingest/server/src/worker.rs:235
2024-09-30 20:40:38.292057207 UTC DEBG Checking on peer: insecure-igp://0.0.0.0:8811/, mc.node_id: 0, mc.test_name: retired_key_not_outstanding_idles_have_same_key::active_key_is_retired_not_outstanding_new_key_is_set_node_activated, mc.module: mc_fog_ingest_server::controller, mc.src: fog/ingest/server/src/controller.rs:1363
2024-09-30 20:40:38.292128862 UTC WARN Creating insecure gRPC connection to 0.0.0.0:8811, mc.peers.addr: 0.0.0.0:8811, mc.node_id: 0, mc.test_name: retired_key_not_outstanding_idles_have_same_key::active_key_is_retired_not_outstanding_new_key_is_set_node_activated, mc.module: mc_util_grpc::grpcio_extensions, mc.src: util/grpc/src/grpcio_extensions.rs:48
2024-09-30 20:40:38.315290769 UTC DEBG Ingesting block #7: 4/4 txs ingested, mc.node_id: 0, mc.test_name: retired_key_not_outstanding_idles_have_same_key::active_key_is_retired_not_outstanding_new_key_is_set_node_activated, mc.module: mc_fog_ingest_server::controller, mc.src: fog/ingest/server/src/controller.rs:587
2024-09-30 20:40:38.315384556 UTC INFO add_block_data, mc.node_id: 0, mc.test_name: retired_key_not_outstanding_idles_have_same_key::active_key_is_retired_not_outstanding_new_key_is_set_node_activated, mc.module: mc_fog_ingest_server::controller, mc.src: fog/ingest/server/src/controller.rs:596
2024-09-30 20:40:38.323519558 UTC DEBG Peer backup insecure-igp://0.0.0.0:8811/ was confirmed, mc.node_id: 0, mc.test_name: retired_key_not_outstanding_idles_have_same_key::active_key_is_retired_not_outstanding_new_key_is_set_node_activated, mc.module: mc_fog_ingest_server::controller, mc.src: fog/ingest/server/src/controller.rs:1378
2024-09-30 20:40:38.323941922 UTC DEBG Checking on peer: insecure-igp://0.0.0.0:8816/, mc.node_id: 0, mc.test_name: retired_key_not_outstanding_idles_have_same_key::active_key_is_retired_not_outstanding_new_key_is_set_node_activated, mc.module: mc_fog_ingest_server::controller, mc.src: fog/ingest/server/src/controller.rs:1363
2024-09-30 20:40:38.324030108 UTC WARN Creating insecure gRPC connection to 0.0.0.0:8816, mc.peers.addr: 0.0.0.0:8816, mc.node_id: 0, mc.test_name: retired_key_not_outstanding_idles_have_same_key::active_key_is_retired_not_outstanding_new_key_is_set_node_activated, mc.module: mc_util_grpc::grpcio_extensions, mc.src: util/grpc/src/grpcio_extensions.rs:48
2024-09-30 20:40:38.352051084 UTC DEBG Peer backup insecure-igp://0.0.0.0:8816/ was confirmed, mc.node_id: 0, mc.test_name: retired_key_not_outstanding_idles_have_same_key::active_key_is_retired_not_outstanding_new_key_is_set_node_activated, mc.module: mc_fog_ingest_server::controller, mc.src: fog/ingest/server/src/controller.rs:1378
2024-09-30 20:40:38.392354308 UTC INFO Succeeded writing block 7 to the database, invocation id Some(IngestInvocationId(1)) ingress key CompressedRistrettoPublic(584efa1999c26f8ca467fee078038d111affe905dd4b3c58d6c359f2e03ecd73), mc.node_id: 0, mc.test_name: retired_key_not_outstanding_idles_have_same_key::active_key_is_retired_not_outstanding_new_key_is_set_node_activated, mc.module: mc_fog_ingest_server::controller, mc.src: fog/ingest/server/src/controller.rs:636
2024-09-30 20:40:38.392448735 UTC DEBG Incremented next block index: 8, mc.node_id: 0, mc.test_name: retired_key_not_outstanding_idles_have_same_key::active_key_is_retired_not_outstanding_new_key_is_set_node_activated, mc.module: mc_fog_ingest_server::controller_state, mc.src: fog/ingest/server/src/controller_state.rs:155
2024-09-30 20:40:38.392522434 UTC DEBG Controller state: { mode: Active, next_block_index: 8, pubkey_expiry_window: 10, ingest_invocation_id: 1, peers: [insecure-igp://0.0.0.0:8806/, insecure-igp://0.0.0.0:8811/, insecure-igp://0.0.0.0:8816/] }, mc.node_id: 0, mc.test_name: retired_key_not_outstanding_idles_have_same_key::active_key_is_retired_not_outstanding_new_key_is_set_node_activated, mc.module: mc_fog_ingest_server::controller, mc.src: fog/ingest/server/src/controller.rs:647
2024-09-30 20:40:38.392591093 UTC INFO Finished ingesting block #7, mc.node_id: 0, mc.test_name: retired_key_not_outstanding_idles_have_same_key::active_key_is_retired_not_outstanding_new_key_is_set_node_activated, mc.module: mc_fog_ingest_server::controller, mc.src: fog/ingest/server/src/controller.rs:659
2024-09-30 20:40:38.409352622 UTC DEBG Writing state file to StateFile { file_path: "/tmp/.tmp1hWspb/mc-fog-ingest-state-0" }, mc.node_id: 0, mc.test_name: retired_key_not_outstanding_idles_have_same_key::active_key_is_retired_not_outstanding_new_key_is_set_node_activated, mc.module: mc_fog_ingest_server::controller, mc.src: fog/ingest/server/src/controller.rs:1314
2024-09-30 20:40:38.550200831 UTC DEBG Now ingesting block #8 (id = BlockID(b74dfb15765961a68c0af8b7e9c81616ba0aa54c2cfb204e4d508e99f32511d4)), mc.node_id: 0, mc.test_name: retired_key_not_outstanding_idles_have_same_key::active_key_is_retired_not_outstanding_new_key_is_set_node_activated, mc.module: mc_fog_ingest_server::controller, mc.src: fog/ingest/server/src/controller.rs:428
2024-09-30 20:40:38.554085836 UTC INFO publishing report to DB, mc.node_id: 0, mc.test_name: retired_key_not_outstanding_idles_have_same_key::active_key_is_retired_not_outstanding_new_key_is_set_node_activated, mc.module: mc_fog_ingest_server::controller, mc.src: fog/ingest/server/src/controller.rs:1250
2024-09-30 20:40:38.554708920 UTC INFO update was a no-op, mc.test_name: retired_key_not_outstanding_idles_have_same_key::active_key_is_retired_not_outstanding_new_key_is_set_node_activated, mc.module: mc_fog_sql_recovery_db, mc.src: fog/sql_recovery_db/src/lib.rs:1194
2024-09-30 20:40:38.554836160 UTC INFO check ingress key passed, mc.test_name: retired_key_not_outstanding_idles_have_same_key::active_key_is_retired_not_outstanding_new_key_is_set_node_activated, mc.module: mc_fog_sql_recovery_db, mc.src: fog/sql_recovery_db/src/lib.rs:1197
2024-09-30 20:40:38.554892726 UTC INFO Got status for key: IngressPublicKeyStatus { start_block: 1, pubkey_expiry: 11, retired: true, lost: false }, mc.test_name: retired_key_not_outstanding_idles_have_same_key::active_key_is_retired_not_outstanding_new_key_is_set_node_activated, mc.module: mc_fog_sql_recovery_db, mc.src: fog/sql_recovery_db/src/lib.rs:1214
2024-09-30 20:40:38.554944553 UTC INFO Cannot publish key because it is retired, mc.test_name: retired_key_not_outstanding_idles_have_same_key::active_key_is_retired_not_outstanding_new_key_is_set_node_activated, mc.module: mc_fog_sql_recovery_db, mc.src: fog/sql_recovery_db/src/lib.rs:1216
2024-09-30 20:40:38.756305157 UTC DEBG Ingesting block #8: 4/4 txs ingested, mc.node_id: 0, mc.test_name: retired_key_not_outstanding_idles_have_same_key::active_key_is_retired_not_outstanding_new_key_is_set_node_activated, mc.module: mc_fog_ingest_server::controller, mc.src: fog/ingest/server/src/controller.rs:587
2024-09-30 20:40:38.756391690 UTC INFO add_block_data, mc.node_id: 0, mc.test_name: retired_key_not_outstanding_idles_have_same_key::active_key_is_retired_not_outstanding_new_key_is_set_node_activated, mc.module: mc_fog_ingest_server::controller, mc.src: fog/ingest/server/src/controller.rs:596
2024-09-30 20:40:39.137218040 UTC INFO Succeeded writing block 8 to the database, invocation id Some(IngestInvocationId(1)) ingress key CompressedRistrettoPublic(584efa1999c26f8ca467fee078038d111affe905dd4b3c58d6c359f2e03ecd73), mc.node_id: 0, mc.test_name: retired_key_not_outstanding_idles_have_same_key::active_key_is_retired_not_outstanding_new_key_is_set_node_activated, mc.module: mc_fog_ingest_server::controller, mc.src: fog/ingest/server/src/controller.rs:636
2024-09-30 20:40:39.137292850 UTC DEBG Incremented next block index: 9, mc.node_id: 0, mc.test_name: retired_key_not_outstanding_idles_have_same_key::active_key_is_retired_not_outstanding_new_key_is_set_node_activated, mc.module: mc_fog_ingest_server::controller_state, mc.src: fog/ingest/server/src/controller_state.rs:155
2024-09-30 20:40:39.137351249 UTC DEBG Controller state: { mode: Active, next_block_index: 9, pubkey_expiry_window: 10, ingest_invocation_id: 1, peers: [insecure-igp://0.0.0.0:8806/, insecure-igp://0.0.0.0:8811/, insecure-igp://0.0.0.0:8816/] }, mc.node_id: 0, mc.test_name: retired_key_not_outstanding_idles_have_same_key::active_key_is_retired_not_outstanding_new_key_is_set_node_activated, mc.module: mc_fog_ingest_server::controller, mc.src: fog/ingest/server/src/controller.rs:647
2024-09-30 20:40:39.137407424 UTC INFO Finished ingesting block #8, mc.node_id: 0, mc.test_name: retired_key_not_outstanding_idles_have_same_key::active_key_is_retired_not_outstanding_new_key_is_set_node_activated, mc.module: mc_fog_ingest_server::controller, mc.src: fog/ingest/server/src/controller.rs:659
2024-09-30 20:40:39.154484528 UTC DEBG Writing state file to StateFile { file_path: "/tmp/.tmp1hWspb/mc-fog-ingest-state-0" }, mc.node_id: 0, mc.test_name: retired_key_not_outstanding_idles_have_same_key::active_key_is_retired_not_outstanding_new_key_is_set_node_activated, mc.module: mc_fog_ingest_server::controller, mc.src: fog/ingest/server/src/controller.rs:1314
2024-09-30 20:40:40.039176448 UTC DEBG Checking up on peers..., mc.node_id: 2, mc.test_name: retired_key_not_outstanding_idles_have_same_key::active_key_is_retired_not_outstanding_new_key_is_set_node_activated, mc.module: mc_fog_ingest_server::worker, mc.src: fog/ingest/server/src/worker.rs:235
2024-09-30 20:40:41.206259852 UTC DEBG Now ingesting block #9 (id = BlockID(80c2681e49aa451497dc1a2fc85e0a3efab69bf1ab630333c61e8dd9960d312c)), mc.node_id: 0, mc.test_name: retired_key_not_outstanding_idles_have_same_key::active_key_is_retired_not_outstanding_new_key_is_set_node_activated, mc.module: mc_fog_ingest_server::controller, mc.src: fog/ingest/server/src/controller.rs:428
2024-09-30 20:40:41.210247683 UTC INFO publishing report to DB, mc.node_id: 0, mc.test_name: retired_key_not_outstanding_idles_have_same_key::active_key_is_retired_not_outstanding_new_key_is_set_node_activated, mc.module: mc_fog_ingest_server::controller, mc.src: fog/ingest/server/src/controller.rs:1250
2024-09-30 20:40:41.210977220 UTC INFO update was a no-op, mc.test_name: retired_key_not_outstanding_idles_have_same_key::active_key_is_retired_not_outstanding_new_key_is_set_node_activated, mc.module: mc_fog_sql_recovery_db, mc.src: fog/sql_recovery_db/src/lib.rs:1194
2024-09-30 20:40:41.211126107 UTC INFO check ingress key passed, mc.test_name: retired_key_not_outstanding_idles_have_same_key::active_key_is_retired_not_outstanding_new_key_is_set_node_activated, mc.module: mc_fog_sql_recovery_db, mc.src: fog/sql_recovery_db/src/lib.rs:1197
2024-09-30 20:40:41.211179867 UTC INFO Got status for key: IngressPublicKeyStatus { start_block: 1, pubkey_expiry: 11, retired: true, lost: false }, mc.test_name: retired_key_not_outstanding_idles_have_same_key::active_key_is_retired_not_outstanding_new_key_is_set_node_activated, mc.module: mc_fog_sql_recovery_db, mc.src: fog/sql_recovery_db/src/lib.rs:1214
2024-09-30 20:40:41.211229530 UTC INFO Cannot publish key because it is retired, mc.test_name: retired_key_not_outstanding_idles_have_same_key::active_key_is_retired_not_outstanding_new_key_is_set_node_activated, mc.module: mc_fog_sql_recovery_db, mc.src: fog/sql_recovery_db/src/lib.rs:1216
2024-09-30 20:40:41.412765798 UTC DEBG Ingesting block #9: 4/4 txs ingested, mc.node_id: 0, mc.test_name: retired_key_not_outstanding_idles_have_same_key::active_key_is_retired_not_outstanding_new_key_is_set_node_activated, mc.module: mc_fog_ingest_server::controller, mc.src: fog/ingest/server/src/controller.rs:587
2024-09-30 20:40:41.412841970 UTC INFO add_block_data, mc.node_id: 0, mc.test_name: retired_key_not_outstanding_idles_have_same_key::active_key_is_retired_not_outstanding_new_key_is_set_node_activated, mc.module: mc_fog_ingest_server::controller, mc.src: fog/ingest/server/src/controller.rs:596
2024-09-30 20:40:41.587913835 UTC INFO Succeeded writing block 9 to the database, invocation id Some(IngestInvocationId(1)) ingress key CompressedRistrettoPublic(584efa1999c26f8ca467fee078038d111affe905dd4b3c58d6c359f2e03ecd73), mc.node_id: 0, mc.test_name: retired_key_not_outstanding_idles_have_same_key::active_key_is_retired_not_outstanding_new_key_is_set_node_activated, mc.module: mc_fog_ingest_server::controller, mc.src: fog/ingest/server/src/controller.rs:636
2024-09-30 20:40:41.587993584 UTC DEBG Incremented next block index: 10, mc.node_id: 0, mc.test_name: retired_key_not_outstanding_idles_have_same_key::active_key_is_retired_not_outstanding_new_key_is_set_node_activated, mc.module: mc_fog_ingest_server::controller_state, mc.src: fog/ingest/server/src/controller_state.rs:155
2024-09-30 20:40:41.588053746 UTC DEBG Controller state: { mode: Active, next_block_index: 10, pubkey_expiry_window: 10, ingest_invocation_id: 1, peers: [insecure-igp://0.0.0.0:8806/, insecure-igp://0.0.0.0:8811/, insecure-igp://0.0.0.0:8816/] }, mc.node_id: 0, mc.test_name: retired_key_not_outstanding_idles_have_same_key::active_key_is_retired_not_outstanding_new_key_is_set_node_activated, mc.module: mc_fog_ingest_server::controller, mc.src: fog/ingest/server/src/controller.rs:647
2024-09-30 20:40:41.588111694 UTC INFO Finished ingesting block #9, mc.node_id: 0, mc.test_name: retired_key_not_outstanding_idles_have_same_key::active_key_is_retired_not_outstanding_new_key_is_set_node_activated, mc.module: mc_fog_ingest_server::controller, mc.src: fog/ingest/server/src/controller.rs:659
2024-09-30 20:40:41.605439597 UTC DEBG Writing state file to StateFile { file_path: "/tmp/.tmp1hWspb/mc-fog-ingest-state-0" }, mc.node_id: 0, mc.test_name: retired_key_not_outstanding_idles_have_same_key::active_key_is_retired_not_outstanding_new_key_is_set_node_activated, mc.module: mc_fog_ingest_server::controller, mc.src: fog/ingest/server/src/controller.rs:1314
2024-09-30 20:40:41.634361934 UTC DEBG Now ingesting block #10 (id = BlockID(390585c43fab974064b1d8724532ff7197c9cec719134a529bc823483e82a7fb)), mc.node_id: 0, mc.test_name: retired_key_not_outstanding_idles_have_same_key::active_key_is_retired_not_outstanding_new_key_is_set_node_activated, mc.module: mc_fog_ingest_server::controller, mc.src: fog/ingest/server/src/controller.rs:428
2024-09-30 20:40:41.638309429 UTC INFO publishing report to DB, mc.node_id: 0, mc.test_name: retired_key_not_outstanding_idles_have_same_key::active_key_is_retired_not_outstanding_new_key_is_set_node_activated, mc.module: mc_fog_ingest_server::controller, mc.src: fog/ingest/server/src/controller.rs:1250
2024-09-30 20:40:41.638914775 UTC INFO update was a no-op, mc.test_name: retired_key_not_outstanding_idles_have_same_key::active_key_is_retired_not_outstanding_new_key_is_set_node_activated, mc.module: mc_fog_sql_recovery_db, mc.src: fog/sql_recovery_db/src/lib.rs:1194
2024-09-30 20:40:41.639041441 UTC INFO check ingress key passed, mc.test_name: retired_key_not_outstanding_idles_have_same_key::active_key_is_retired_not_outstanding_new_key_is_set_node_activated, mc.module: mc_fog_sql_recovery_db, mc.src: fog/sql_recovery_db/src/lib.rs:1197
2024-09-30 20:40:41.639106793 UTC INFO Got status for key: IngressPublicKeyStatus { start_block: 1, pubkey_expiry: 11, retired: true, lost: false }, mc.test_name: retired_key_not_outstanding_idles_have_same_key::active_key_is_retired_not_outstanding_new_key_is_set_node_activated, mc.module: mc_fog_sql_recovery_db, mc.src: fog/sql_recovery_db/src/lib.rs:1214
2024-09-30 20:40:41.639172896 UTC INFO Cannot publish key because it is retired, mc.test_name: retired_key_not_outstanding_idles_have_same_key::active_key_is_retired_not_outstanding_new_key_is_set_node_activated, mc.module: mc_fog_sql_recovery_db, mc.src: fog/sql_recovery_db/src/lib.rs:1216
2024-09-30 20:40:41.853034529 UTC DEBG Ingesting block #10: 4/4 txs ingested, mc.node_id: 0, mc.test_name: retired_key_not_outstanding_idles_have_same_key::active_key_is_retired_not_outstanding_new_key_is_set_node_activated, mc.module: mc_fog_ingest_server::controller, mc.src: fog/ingest/server/src/controller.rs:587
2024-09-30 20:40:41.853130247 UTC INFO add_block_data, mc.node_id: 0, mc.test_name: retired_key_not_outstanding_idles_have_same_key::active_key_is_retired_not_outstanding_new_key_is_set_node_activated, mc.module: mc_fog_ingest_server::controller, mc.src: fog/ingest/server/src/controller.rs:596
2024-09-30 20:40:41.871747998 UTC INFO Succeeded writing block 10 to the database, invocation id Some(IngestInvocationId(1)) ingress key CompressedRistrettoPublic(584efa1999c26f8ca467fee078038d111affe905dd4b3c58d6c359f2e03ecd73), mc.node_id: 0, mc.test_name: retired_key_not_outstanding_idles_have_same_key::active_key_is_retired_not_outstanding_new_key_is_set_node_activated, mc.module: mc_fog_ingest_server::controller, mc.src: fog/ingest/server/src/controller.rs:636
2024-09-30 20:40:41.871820263 UTC DEBG Incremented next block index: 11, mc.node_id: 0, mc.test_name: retired_key_not_outstanding_idles_have_same_key::active_key_is_retired_not_outstanding_new_key_is_set_node_activated, mc.module: mc_fog_ingest_server::controller_state, mc.src: fog/ingest/server/src/controller_state.rs:155
2024-09-30 20:40:41.871879112 UTC DEBG Controller state: { mode: Active, next_block_index: 11, pubkey_expiry_window: 10, ingest_invocation_id: 1, peers: [insecure-igp://0.0.0.0:8806/, insecure-igp://0.0.0.0:8811/, insecure-igp://0.0.0.0:8816/] }, mc.node_id: 0, mc.test_name: retired_key_not_outstanding_idles_have_same_key::active_key_is_retired_not_outstanding_new_key_is_set_node_activated, mc.module: mc_fog_ingest_server::controller, mc.src: fog/ingest/server/src/controller.rs:647
2024-09-30 20:40:41.871936760 UTC INFO Finished ingesting block #10, mc.node_id: 0, mc.test_name: retired_key_not_outstanding_idles_have_same_key::active_key_is_retired_not_outstanding_new_key_is_set_node_activated, mc.module: mc_fog_ingest_server::controller, mc.src: fog/ingest/server/src/controller.rs:659
2024-09-30 20:40:41.889054423 UTC DEBG Writing state file to StateFile { file_path: "/tmp/.tmp1hWspb/mc-fog-ingest-state-0" }, mc.node_id: 0, mc.test_name: retired_key_not_outstanding_idles_have_same_key::active_key_is_retired_not_outstanding_new_key_is_set_node_activated, mc.module: mc_fog_ingest_server::controller, mc.src: fog/ingest/server/src/controller.rs:1314
2024-09-30 20:40:41.912623539 UTC DEBG Now ingesting block #11 (id = BlockID(c81ef20029cdf5d31eaf0856cfbe3579f55e60b45140f27f5e32ba2e54b5e252)), mc.node_id: 0, mc.test_name: retired_key_not_outstanding_idles_have_same_key::active_key_is_retired_not_outstanding_new_key_is_set_node_activated, mc.module: mc_fog_ingest_server::controller, mc.src: fog/ingest/server/src/controller.rs:428
2024-09-30 20:40:41.916583075 UTC INFO publishing report to DB, mc.node_id: 0, mc.test_name: retired_key_not_outstanding_idles_have_same_key::active_key_is_retired_not_outstanding_new_key_is_set_node_activated, mc.module: mc_fog_ingest_server::controller, mc.src: fog/ingest/server/src/controller.rs:1250
2024-09-30 20:40:41.917037651 UTC INFO update was a no-op, mc.test_name: retired_key_not_outstanding_idles_have_same_key::active_key_is_retired_not_outstanding_new_key_is_set_node_activated, mc.module: mc_fog_sql_recovery_db, mc.src: fog/sql_recovery_db/src/lib.rs:1194
2024-09-30 20:40:41.917163415 UTC INFO check ingress key passed, mc.test_name: retired_key_not_outstanding_idles_have_same_key::active_key_is_retired_not_outstanding_new_key_is_set_node_activated, mc.module: mc_fog_sql_recovery_db, mc.src: fog/sql_recovery_db/src/lib.rs:1197
2024-09-30 20:40:41.917215342 UTC INFO Got status for key: IngressPublicKeyStatus { start_block: 1, pubkey_expiry: 11, retired: true, lost: false }, mc.test_name: retired_key_not_outstanding_idles_have_same_key::active_key_is_retired_not_outstanding_new_key_is_set_node_activated, mc.module: mc_fog_sql_recovery_db, mc.src: fog/sql_recovery_db/src/lib.rs:1214
2024-09-30 20:40:41.917265816 UTC INFO Cannot publish key because it is retired, mc.test_name: retired_key_not_outstanding_idles_have_same_key::active_key_is_retired_not_outstanding_new_key_is_set_node_activated, mc.module: mc_fog_sql_recovery_db, mc.src: fog/sql_recovery_db/src/lib.rs:1216
2024-09-30 20:40:42.100246730 UTC INFO Overseer worker thread stopping., mc.test_name: retired_key_not_outstanding_idles_have_same_key::active_key_is_retired_not_outstanding_new_key_is_set_node_activated, mc.module: mc_fog_overseer_server::worker, mc.src: fog/overseer/server/src/worker.rs:165
2024-09-30 20:40:42.127163034 UTC DEBG Ingesting block #11: 4/4 txs ingested, mc.node_id: 0, mc.test_name: retired_key_not_outstanding_idles_have_same_key::active_key_is_retired_not_outstanding_new_key_is_set_node_activated, mc.module: mc_fog_ingest_server::controller, mc.src: fog/ingest/server/src/controller.rs:587
2024-09-30 20:40:42.127314045 UTC INFO add_block_data, mc.node_id: 0, mc.test_name: retired_key_not_outstanding_idles_have_same_key::active_key_is_retired_not_outstanding_new_key_is_set_node_activated, mc.module: mc_fog_ingest_server::controller, mc.src: fog/ingest/server/src/controller.rs:596
2024-09-30 20:40:42.146577074 UTC INFO Succeeded writing block 11 to the database, invocation id Some(IngestInvocationId(1)) ingress key CompressedRistrettoPublic(584efa1999c26f8ca467fee078038d111affe905dd4b3c58d6c359f2e03ecd73), mc.node_id: 0, mc.test_name: retired_key_not_outstanding_idles_have_same_key::active_key_is_retired_not_outstanding_new_key_is_set_node_activated, mc.module: mc_fog_ingest_server::controller, mc.src: fog/ingest/server/src/controller.rs:636
2024-09-30 20:40:42.146648317 UTC DEBG Incremented next block index: 12, mc.node_id: 0, mc.test_name: retired_key_not_outstanding_idles_have_same_key::active_key_is_retired_not_outstanding_new_key_is_set_node_activated, mc.module: mc_fog_ingest_server::controller_state, mc.src: fog/ingest/server/src/controller_state.rs:155
2024-09-30 20:40:42.146699031 UTC DEBG Controller state: { mode: Active, next_block_index: 12, pubkey_expiry_window: 10, ingest_invocation_id: 1, peers: [insecure-igp://0.0.0.0:8806/, insecure-igp://0.0.0.0:8811/, insecure-igp://0.0.0.0:8816/] }, mc.node_id: 0, mc.test_name: retired_key_not_outstanding_idles_have_same_key::active_key_is_retired_not_outstanding_new_key_is_set_node_activated, mc.module: mc_fog_ingest_server::controller, mc.src: fog/ingest/server/src/controller.rs:647
2024-09-30 20:40:42.146748974 UTC INFO Finished ingesting block #11, mc.node_id: 0, mc.test_name: retired_key_not_outstanding_idles_have_same_key::active_key_is_retired_not_outstanding_new_key_is_set_node_activated, mc.module: mc_fog_ingest_server::controller, mc.src: fog/ingest/server/src/controller.rs:659
2024-09-30 20:40:42.166580495 UTC DEBG Writing state file to StateFile { file_path: "/tmp/.tmp1hWspb/mc-fog-ingest-state-0" }, mc.node_id: 0, mc.test_name: retired_key_not_outstanding_idles_have_same_key::active_key_is_retired_not_outstanding_new_key_is_set_node_activated, mc.module: mc_fog_ingest_server::controller, mc.src: fog/ingest/server/src/controller.rs:1314
2024-09-30 20:40:42.186065938 UTC INFO Stop Requested: Polling loop stopped at block number 12, is_idle false, mc.node_id: 0, mc.test_name: retired_key_not_outstanding_idles_have_same_key::active_key_is_retired_not_outstanding_new_key_is_set_node_activated, mc.module: mc_fog_ingest_server::worker, mc.src: fog/ingest/server/src/worker.rs:75
2024-09-30 20:40:42.352861062 UTC DEBG Peer checkup thread stop requested., mc.node_id: 0, mc.test_name: retired_key_not_outstanding_idles_have_same_key::active_key_is_retired_not_outstanding_new_key_is_set_node_activated, mc.module: mc_fog_ingest_server::worker, mc.src: fog/ingest/server/src/worker.rs:229
2024-09-30 20:40:42.843389253 UTC DEBG Report cache thread stop requested., mc.node_id: 0, mc.test_name: retired_key_not_outstanding_idles_have_same_key::active_key_is_retired_not_outstanding_new_key_is_set_node_activated, mc.module: mc_fog_ingest_server::worker, mc.src: fog/ingest/server/src/worker.rs:289
2024-09-30 20:40:43.087016713 UTC DEBG Checking up on peers..., mc.node_id: 1, mc.test_name: retired_key_not_outstanding_idles_have_same_key::active_key_is_retired_not_outstanding_new_key_is_set_node_activated, mc.module: mc_fog_ingest_server::worker, mc.src: fog/ingest/server/src/worker.rs:235
2024-09-30 20:40:43.659323156 UTC INFO Stop Requested: Polling loop stopped at block number 0, is_idle true, mc.node_id: 1, mc.test_name: retired_key_not_outstanding_idles_have_same_key::active_key_is_retired_not_outstanding_new_key_is_set_node_activated, mc.module: mc_fog_ingest_server::worker, mc.src: fog/ingest/server/src/worker.rs:75
2024-09-30 20:40:44.087320430 UTC DEBG Peer checkup thread stop requested., mc.node_id: 1, mc.test_name: retired_key_not_outstanding_idles_have_same_key::active_key_is_retired_not_outstanding_new_key_is_set_node_activated, mc.module: mc_fog_ingest_server::worker, mc.src: fog/ingest/server/src/worker.rs:229
2024-09-30 20:40:45.039634132 UTC DEBG Checking up on peers..., mc.node_id: 2, mc.test_name: retired_key_not_outstanding_idles_have_same_key::active_key_is_retired_not_outstanding_new_key_is_set_node_activated, mc.module: mc_fog_ingest_server::worker, mc.src: fog/ingest/server/src/worker.rs:235
2024-09-30 20:40:45.086317193 UTC DEBG Report cache thread stop requested., mc.node_id: 1, mc.test_name: retired_key_not_outstanding_idles_have_same_key::active_key_is_retired_not_outstanding_new_key_is_set_node_activated, mc.module: mc_fog_ingest_server::worker, mc.src: fog/ingest/server/src/worker.rs:289
2024-09-30 20:40:45.869470615 UTC INFO Stop Requested: Polling loop stopped at block number 0, is_idle true, mc.node_id: 2, mc.test_name: retired_key_not_outstanding_idles_have_same_key::active_key_is_retired_not_outstanding_new_key_is_set_node_activated, mc.module: mc_fog_ingest_server::worker, mc.src: fog/ingest/server/src/worker.rs:75
2024-09-30 20:40:46.039748938 UTC DEBG Peer checkup thread stop requested., mc.node_id: 2, mc.test_name: retired_key_not_outstanding_idles_have_same_key::active_key_is_retired_not_outstanding_new_key_is_set_node_activated, mc.module: mc_fog_ingest_server::worker, mc.src: fog/ingest/server/src/worker.rs:229
2024-09-30 20:40:47.038971116 UTC DEBG Report cache thread stop requested., mc.node_id: 2, mc.test_name: retired_key_not_outstanding_idles_have_same_key::active_key_is_retired_not_outstanding_new_key_is_set_node_activated, mc.module: mc_fog_ingest_server::worker, mc.src: fog/ingest/server/src/worker.rs:289

thread 'inactive_oustanding_key_idle_node_has_original_key_node_is_activated_and_key_is_not_reported_lost_or_retired' panicked at fog/overseer/server/tests/inactive_outstanding_key_idle_has_key.rs:43:12:
Timed out waiting for active node to process data; recovery_db has 5 blocks, target is 12
stack backtrace:
   0: rust_begin_unwind
             at /rustc/ca62d2c445628587660ae48013f460b08b1f5552/library/std/src/panicking.rs:597:5
   1: core::panicking::panic_fmt
             at /rustc/ca62d2c445628587660ae48013f460b08b1f5552/library/core/src/panicking.rs:72:14
   2: mc_fog_ingest_server_test_utils::IngestServerTestHelper::wait_till_recovery_db_callback
             at /__w/mobilecoin/mobilecoin/fog/ingest/server/test-utils/src/lib.rs:308:13
   3: mc_fog_ingest_server_test_utils::IngestServerTestHelper::wait_till_recovery_db_in_sync_up_to
             at /__w/mobilecoin/mobilecoin/fog/ingest/server/test-utils/src/lib.rs:279:9
   4: mc_fog_ingest_server_test_utils::IngestServerTestHelper::wait_till_recovery_db_in_sync
             at /__w/mobilecoin/mobilecoin/fog/ingest/server/test-utils/src/lib.rs:272:9
   5: inactive_outstanding_key_idle_has_key::__wrapped_inactive_oustanding_key_idle_node_has_original_key_node_is_activated_and_key_is_not_reported_lost_or_retired
             at ./tests/inactive_outstanding_key_idle_has_key.rs:43:5
   6: inactive_outstanding_key_idle_has_key::inactive_oustanding_key_idle_node_has_original_key_node_is_activated_and_key_is_not_reported_lost_or_retired::{{closure}}
             at ./tests/inactive_outstanding_key_idle_has_key.rs:18:1
   7: slog_scope::scope
             at /opt/cargo/registry/src/index.crates.io-6f17d22bba15001f/slog-scope-4.4.0/lib.rs:248:5
   8: inactive_outstanding_key_idle_has_key::inactive_oustanding_key_idle_node_has_original_key_node_is_activated_and_key_is_not_reported_lost_or_retired
             at ./tests/inactive_outstanding_key_idle_has_key.rs:18:1
   9: inactive_outstanding_key_idle_has_key::inactive_oustanding_key_idle_node_has_original_key_node_is_activated_and_key_is_not_reported_lost_or_retired::{{closure}}
             at ./tests/inactive_outstanding_key_idle_has_key.rs:18:1
  10: core::ops::function::FnOnce::call_once
             at /rustc/ca62d2c445628587660ae48013f460b08b1f5552/library/core/src/ops/function.rs:250:5
  11: core::ops::function::FnOnce::call_once
             at /rustc/ca62d2c445628587660ae48013f460b08b1f5552/library/core/src/ops/function.rs:250:5
note: Some details are omitted, run with `RUST_BACKTRACE=full` for a verbose backtrace.
2024-09-30 20:40:34.672730007 UTC INFO Disabling overseer worker, mc.test_name: inactive_outstanding_key_idle_has_key::inactive_oustanding_key_idle_node_has_original_key_node_is_activated_and_key_is_not_reported_lost_or_retired, mc.module: mc_fog_overseer_server::service, mc.src: fog/overseer/server/src/service.rs:114
2024-09-30 20:40:35.034629348 UTC DEBG Checking up on peers..., mc.node_id: 2, mc.test_name: inactive_outstanding_key_idle_has_key::inactive_oustanding_key_idle_node_has_original_key_node_is_activated_and_key_is_not_reported_lost_or_retired, mc.module: mc_fog_ingest_server::worker, mc.src: fog/ingest/server/src/worker.rs:235
2024-09-30 20:40:37.058304478 UTC DEBG Checking on peer: insecure-igp://0.0.0.0:8611/, mc.node_id: 0, mc.test_name: inactive_outstanding_key_idle_has_key::inactive_oustanding_key_idle_node_has_original_key_node_is_activated_and_key_is_not_reported_lost_or_retired, mc.module: mc_fog_ingest_server::controller, mc.src: fog/ingest/server/src/controller.rs:1363
2024-09-30 20:40:37.058434112 UTC WARN Creating insecure gRPC connection to 0.0.0.0:8611, mc.peers.addr: 0.0.0.0:8611, mc.node_id: 0, mc.test_name: inactive_outstanding_key_idle_has_key::inactive_oustanding_key_idle_node_has_original_key_node_is_activated_and_key_is_not_reported_lost_or_retired, mc.module: mc_util_grpc::grpcio_extensions, mc.src: util/grpc/src/grpcio_extensions.rs:48
2024-09-30 20:40:37.076668692 UTC DEBG Now ingesting block #5 (id = BlockID(26896b894efe6ac354c492b33a71354b209732d404b0eb40891d5b92a71dff65)), mc.node_id: 0, mc.test_name: inactive_outstanding_key_idle_has_key::inactive_oustanding_key_idle_node_has_original_key_node_is_activated_and_key_is_not_reported_lost_or_retired, mc.module: mc_fog_ingest_server::controller, mc.src: fog/ingest/server/src/controller.rs:428
2024-09-30 20:40:37.080620054 UTC INFO publishing report to DB, mc.node_id: 0, mc.test_name: inactive_outstanding_key_idle_has_key::inactive_oustanding_key_idle_node_has_original_key_node_is_activated_and_key_is_not_reported_lost_or_retired, mc.module: mc_fog_ingest_server::controller, mc.src: fog/ingest/server/src/controller.rs:1250
2024-09-30 20:40:37.081380785 UTC INFO Got status for key: IngressPublicKeyStatus { start_block: 1, pubkey_expiry: 15, retired: false, lost: false }, mc.test_name: inactive_outstanding_key_idle_has_key::inactive_oustanding_key_idle_node_has_original_key_node_is_activated_and_key_is_not_reported_lost_or_retired, mc.module: mc_fog_sql_recovery_db, mc.src: fog/sql_recovery_db/src/lib.rs:1214
2024-09-30 20:40:37.998827563 UTC DEBG Peer backup insecure-igp://0.0.0.0:8611/ was confirmed, mc.node_id: 0, mc.test_name: inactive_outstanding_key_idle_has_key::inactive_oustanding_key_idle_node_has_original_key_node_is_activated_and_key_is_not_reported_lost_or_retired, mc.module: mc_fog_ingest_server::controller, mc.src: fog/ingest/server/src/controller.rs:1378
2024-09-30 20:40:37.999461395 UTC DEBG Checking on peer: insecure-igp://0.0.0.0:8616/, mc.node_id: 0, mc.test_name: inactive_outstanding_key_idle_has_key::inactive_oustanding_key_idle_node_has_original_key_node_is_activated_and_key_is_not_reported_lost_or_retired, mc.module: mc_fog_ingest_server::controller, mc.src: fog/ingest/server/src/controller.rs:1363
2024-09-30 20:40:37.999526257 UTC WARN Creating insecure gRPC connection to 0.0.0.0:8616, mc.peers.addr: 0.0.0.0:8616, mc.node_id: 0, mc.test_name: inactive_outstanding_key_idle_has_key::inactive_oustanding_key_idle_node_has_original_key_node_is_activated_and_key_is_not_reported_lost_or_retired, mc.module: mc_util_grpc::grpcio_extensions, mc.src: util/grpc/src/grpcio_extensions.rs:48
2024-09-30 20:40:38.086200263 UTC DEBG Checking up on peers..., mc.node_id: 1, mc.test_name: inactive_outstanding_key_idle_has_key::inactive_oustanding_key_idle_node_has_original_key_node_is_activated_and_key_is_not_reported_lost_or_retired, mc.module: mc_fog_ingest_server::worker, mc.src: fog/ingest/server/src/worker.rs:235
2024-09-30 20:40:38.200444048 UTC DEBG Ingesting block #5: 4/4 txs ingested, mc.node_id: 0, mc.test_name: inactive_outstanding_key_idle_has_key::inactive_oustanding_key_idle_node_has_original_key_node_is_activated_and_key_is_not_reported_lost_or_retired, mc.module: mc_fog_ingest_server::controller, mc.src: fog/ingest/server/src/controller.rs:587
2024-09-30 20:40:38.200515643 UTC INFO add_block_data, mc.node_id: 0, mc.test_name: inactive_outstanding_key_idle_has_key::inactive_oustanding_key_idle_node_has_original_key_node_is_activated_and_key_is_not_reported_lost_or_retired, mc.module: mc_fog_ingest_server::controller, mc.src: fog/ingest/server/src/controller.rs:596
2024-09-30 20:40:38.208992610 UTC DEBG Peer backup insecure-igp://0.0.0.0:8616/ was confirmed, mc.node_id: 0, mc.test_name: inactive_outstanding_key_idle_has_key::inactive_oustanding_key_idle_node_has_original_key_node_is_activated_and_key_is_not_reported_lost_or_retired, mc.module: mc_fog_ingest_server::controller, mc.src: fog/ingest/server/src/controller.rs:1378
2024-09-30 20:40:38.303309222 UTC INFO Succeeded writing block 5 to the database, invocation id Some(IngestInvocationId(1)) ingress key CompressedRistrettoPublic(74fdd3896795ae3339f0f23ad825565c84eadb67a0e6cedecf35571dbed56755), mc.node_id: 0, mc.test_name: inactive_outstanding_key_idle_has_key::inactive_oustanding_key_idle_node_has_original_key_node_is_activated_and_key_is_not_reported_lost_or_retired, mc.module: mc_fog_ingest_server::controller, mc.src: fog/ingest/server/src/controller.rs:636
2024-09-30 20:40:38.303392589 UTC DEBG Incremented next block index: 6, mc.node_id: 0, mc.test_name: inactive_outstanding_key_idle_has_key::inactive_oustanding_key_idle_node_has_original_key_node_is_activated_and_key_is_not_reported_lost_or_retired, mc.module: mc_fog_ingest_server::controller_state, mc.src: fog/ingest/server/src/controller_state.rs:155
2024-09-30 20:40:38.303439347 UTC DEBG Controller state: { mode: Active, next_block_index: 6, pubkey_expiry_window: 10, ingest_invocation_id: 1, peers: [insecure-igp://0.0.0.0:8606/, insecure-igp://0.0.0.0:8611/, insecure-igp://0.0.0.0:8616/] }, mc.node_id: 0, mc.test_name: inactive_outstanding_key_idle_has_key::inactive_oustanding_key_idle_node_has_original_key_node_is_activated_and_key_is_not_reported_lost_or_retired, mc.module: mc_fog_ingest_server::controller, mc.src: fog/ingest/server/src/controller.rs:647
2024-09-30 20:40:38.303485704 UTC INFO Finished ingesting block #5, mc.node_id: 0, mc.test_name: inactive_outstanding_key_idle_has_key::inactive_oustanding_key_idle_node_has_original_key_node_is_activated_and_key_is_not_reported_lost_or_retired, mc.module: mc_fog_ingest_server::controller, mc.src: fog/ingest/server/src/controller.rs:659
2024-09-30 20:40:38.320256841 UTC DEBG Writing state file to StateFile { file_path: "/tmp/.tmpbQtKFd/mc-fog-ingest-state-0" }, mc.node_id: 0, mc.test_name: inactive_outstanding_key_idle_has_key::inactive_oustanding_key_idle_node_has_original_key_node_is_activated_and_key_is_not_reported_lost_or_retired, mc.module: mc_fog_ingest_server::controller, mc.src: fog/ingest/server/src/controller.rs:1314
2024-09-30 20:40:38.421736576 UTC DEBG Now ingesting block #6 (id = BlockID(556d297a69b9737405024e965f3d53461bb907058d217a078e393d27276f5ebd)), mc.node_id: 0, mc.test_name: inactive_outstanding_key_idle_has_key::inactive_oustanding_key_idle_node_has_original_key_node_is_activated_and_key_is_not_reported_lost_or_retired, mc.module: mc_fog_ingest_server::controller, mc.src: fog/ingest/server/src/controller.rs:428
2024-09-30 20:40:38.425690374 UTC INFO publishing report to DB, mc.node_id: 0, mc.test_name: inactive_outstanding_key_idle_has_key::inactive_oustanding_key_idle_node_has_original_key_node_is_activated_and_key_is_not_reported_lost_or_retired, mc.module: mc_fog_ingest_server::controller, mc.src: fog/ingest/server/src/controller.rs:1250
2024-09-30 20:40:38.426785564 UTC INFO Got status for key: IngressPublicKeyStatus { start_block: 1, pubkey_expiry: 16, retired: false, lost: false }, mc.test_name: inactive_outstanding_key_idle_has_key::inactive_oustanding_key_idle_node_has_original_key_node_is_activated_and_key_is_not_reported_lost_or_retired, mc.module: mc_fog_sql_recovery_db, mc.src: fog/sql_recovery_db/src/lib.rs:1214
2024-09-30 20:40:38.657110019 UTC DEBG Ingesting block #6: 4/4 txs ingested, mc.node_id: 0, mc.test_name: inactive_outstanding_key_idle_has_key::inactive_oustanding_key_idle_node_has_original_key_node_is_activated_and_key_is_not_reported_lost_or_retired, mc.module: mc_fog_ingest_server::controller, mc.src: fog/ingest/server/src/controller.rs:587
2024-09-30 20:40:38.657193847 UTC INFO add_block_data, mc.node_id: 0, mc.test_name: inactive_outstanding_key_idle_has_key::inactive_oustanding_key_idle_node_has_original_key_node_is_activated_and_key_is_not_reported_lost_or_retired, mc.module: mc_fog_ingest_server::controller, mc.src: fog/ingest/server/src/controller.rs:596
2024-09-30 20:40:39.128790420 UTC INFO Succeeded writing block 6 to the database, invocation id Some(IngestInvocationId(1)) ingress key CompressedRistrettoPublic(74fdd3896795ae3339f0f23ad825565c84eadb67a0e6cedecf35571dbed56755), mc.node_id: 0, mc.test_name: inactive_outstanding_key_idle_has_key::inactive_oustanding_key_idle_node_has_original_key_node_is_activated_and_key_is_not_reported_lost_or_retired, mc.module: mc_fog_ingest_server::controller, mc.src: fog/ingest/server/src/controller.rs:636
2024-09-30 20:40:39.128873896 UTC DEBG Incremented next block index: 7, mc.node_id: 0, mc.test_name: inactive_outstanding_key_idle_has_key::inactive_oustanding_key_idle_node_has_original_key_node_is_activated_and_key_is_not_reported_lost_or_retired, mc.module: mc_fog_ingest_server::controller_state, mc.src: fog/ingest/server/src/controller_state.rs:155
2024-09-30 20:40:39.128941151 UTC DEBG Controller state: { mode: Active, next_block_index: 7, pubkey_expiry_window: 10, ingest_invocation_id: 1, peers: [insecure-igp://0.0.0.0:8606/, insecure-igp://0.0.0.0:8611/, insecure-igp://0.0.0.0:8616/] }, mc.node_id: 0, mc.test_name: inactive_outstanding_key_idle_has_key::inactive_oustanding_key_idle_node_has_original_key_node_is_activated_and_key_is_not_reported_lost_or_retired, mc.module: mc_fog_ingest_server::controller, mc.src: fog/ingest/server/src/controller.rs:647
2024-09-30 20:40:39.129017945 UTC INFO Finished ingesting block #6, mc.node_id: 0, mc.test_name: inactive_outstanding_key_idle_has_key::inactive_oustanding_key_idle_node_has_original_key_node_is_activated_and_key_is_not_reported_lost_or_retired, mc.module: mc_fog_ingest_server::controller, mc.src: fog/ingest/server/src/controller.rs:659
2024-09-30 20:40:39.146230612 UTC DEBG Writing state file to StateFile { file_path: "/tmp/.tmpbQtKFd/mc-fog-ingest-state-0" }, mc.node_id: 0, mc.test_name: inactive_outstanding_key_idle_has_key::inactive_oustanding_key_idle_node_has_original_key_node_is_activated_and_key_is_not_reported_lost_or_retired, mc.module: mc_fog_ingest_server::controller, mc.src: fog/ingest/server/src/controller.rs:1314
2024-09-30 20:40:39.209627434 UTC DEBG Checking up on peers..., mc.node_id: 0, mc.test_name: inactive_outstanding_key_idle_has_key::inactive_oustanding_key_idle_node_has_original_key_node_is_activated_and_key_is_not_reported_lost_or_retired, mc.module: mc_fog_ingest_server::worker, mc.src: fog/ingest/server/src/worker.rs:235
2024-09-30 20:40:40.035581048 UTC DEBG Checking up on peers..., mc.node_id: 2, mc.test_name: inactive_outstanding_key_idle_has_key::inactive_oustanding_key_idle_node_has_original_key_node_is_activated_and_key_is_not_reported_lost_or_retired, mc.module: mc_fog_ingest_server::worker, mc.src: fog/ingest/server/src/worker.rs:235
2024-09-30 20:40:41.188166495 UTC DEBG Checking on peer: insecure-igp://0.0.0.0:8611/, mc.node_id: 0, mc.test_name: inactive_outstanding_key_idle_has_key::inactive_oustanding_key_idle_node_has_original_key_node_is_activated_and_key_is_not_reported_lost_or_retired, mc.module: mc_fog_ingest_server::controller, mc.src: fog/ingest/server/src/controller.rs:1363
2024-09-30 20:40:41.188274947 UTC WARN Creating insecure gRPC connection to 0.0.0.0:8611, mc.peers.addr: 0.0.0.0:8611, mc.node_id: 0, mc.test_name: inactive_outstanding_key_idle_has_key::inactive_oustanding_key_idle_node_has_original_key_node_is_activated_and_key_is_not_reported_lost_or_retired, mc.module: mc_util_grpc::grpcio_extensions, mc.src: util/grpc/src/grpcio_extensions.rs:48
2024-09-30 20:40:41.206526138 UTC DEBG Now ingesting block #7 (id = BlockID(9709571e3d1140fc33b85c1c870e055b92756953ff42aa7e5299cafc78dde285)), mc.node_id: 0, mc.test_name: inactive_outstanding_key_idle_has_key::inactive_oustanding_key_idle_node_has_original_key_node_is_activated_and_key_is_not_reported_lost_or_retired, mc.module: mc_fog_ingest_server::controller, mc.src: fog/ingest/server/src/controller.rs:428
2024-09-30 20:40:41.210496476 UTC INFO publishing report to DB, mc.node_id: 0, mc.test_name: inactive_outstanding_key_idle_has_key::inactive_oustanding_key_idle_node_has_original_key_node_is_activated_and_key_is_not_reported_lost_or_retired, mc.module: mc_fog_ingest_server::controller, mc.src: fog/ingest/server/src/controller.rs:1250
2024-09-30 20:40:41.211161183 UTC INFO Got status for key: IngressPublicKeyStatus { start_block: 1, pubkey_expiry: 17, retired: false, lost: false }, mc.test_name: inactive_outstanding_key_idle_has_key::inactive_oustanding_key_idle_node_has_original_key_node_is_activated_and_key_is_not_reported_lost_or_retired, mc.module: mc_fog_sql_recovery_db, mc.src: fog/sql_recovery_db/src/lib.rs:1214
2024-09-30 20:40:41.583860514 UTC DEBG Peer backup insecure-igp://0.0.0.0:8611/ was confirmed, mc.node_id: 0, mc.test_name: inactive_outstanding_key_idle_has_key::inactive_oustanding_key_idle_node_has_original_key_node_is_activated_and_key_is_not_reported_lost_or_retired, mc.module: mc_fog_ingest_server::controller, mc.src: fog/ingest/server/src/controller.rs:1378
2024-09-30 20:40:41.584496978 UTC DEBG Checking on peer: insecure-igp://0.0.0.0:8616/, mc.node_id: 0, mc.test_name: inactive_outstanding_key_idle_has_key::inactive_oustanding_key_idle_node_has_original_key_node_is_activated_and_key_is_not_reported_lost_or_retired, mc.module: mc_fog_ingest_server::controller, mc.src: fog/ingest/server/src/controller.rs:1363
2024-09-30 20:40:41.584589099 UTC WARN Creating insecure gRPC connection to 0.0.0.0:8616, mc.peers.addr: 0.0.0.0:8616, mc.node_id: 0, mc.test_name: inactive_outstanding_key_idle_has_key::inactive_oustanding_key_idle_node_has_original_key_node_is_activated_and_key_is_not_reported_lost_or_retired, mc.module: mc_util_grpc::grpcio_extensions, mc.src: util/grpc/src/grpcio_extensions.rs:48
2024-09-30 20:40:41.798627561 UTC DEBG Ingesting block #7: 4/4 txs ingested, mc.node_id: 0, mc.test_name: inactive_outstanding_key_idle_has_key::inactive_oustanding_key_idle_node_has_original_key_node_is_activated_and_key_is_not_reported_lost_or_retired, mc.module: mc_fog_ingest_server::controller, mc.src: fog/ingest/server/src/controller.rs:587
2024-09-30 20:40:41.798773903 UTC INFO add_block_data, mc.node_id: 0, mc.test_name: inactive_outstanding_key_idle_has_key::inactive_oustanding_key_idle_node_has_original_key_node_is_activated_and_key_is_not_reported_lost_or_retired, mc.module: mc_fog_ingest_server::controller, mc.src: fog/ingest/server/src/controller.rs:596
2024-09-30 20:40:41.806171391 UTC INFO Succeeded writing block 7 to the database, invocation id Some(IngestInvocationId(1)) ingress key CompressedRistrettoPublic(74fdd3896795ae3339f0f23ad825565c84eadb67a0e6cedecf35571dbed56755), mc.node_id: 0, mc.test_name: inactive_outstanding_key_idle_has_key::inactive_oustanding_key_idle_node_has_original_key_node_is_activated_and_key_is_not_reported_lost_or_retired, mc.module: mc_fog_ingest_server::controller, mc.src: fog/ingest/server/src/controller.rs:636
2024-09-30 20:40:41.806321571 UTC DEBG Incremented next block index: 8, mc.node_id: 0, mc.test_name: inactive_outstanding_key_idle_has_key::inactive_oustanding_key_idle_node_has_original_key_node_is_activated_and_key_is_not_reported_lost_or_retired, mc.module: mc_fog_ingest_server::controller_state, mc.src: fog/ingest/server/src/controller_state.rs:155
2024-09-30 20:40:41.806427238 UTC DEBG Controller state: { mode: Active, next_block_index: 8, pubkey_expiry_window: 10, ingest_invocation_id: 1, peers: [insecure-igp://0.0.0.0:8606/, insecure-igp://0.0.0.0:8611/, insecure-igp://0.0.0.0:8616/] }, mc.node_id: 0, mc.test_name: inactive_outstanding_key_idle_has_key::inactive_oustanding_key_idle_node_has_original_key_node_is_activated_and_key_is_not_reported_lost_or_retired, mc.module: mc_fog_ingest_server::controller, mc.src: fog/ingest/server/src/controller.rs:647
2024-09-30 20:40:41.806491206 UTC INFO Finished ingesting block #7, mc.node_id: 0, mc.test_name: inactive_outstanding_key_idle_has_key::inactive_oustanding_key_idle_node_has_original_key_node_is_activated_and_key_is_not_reported_lost_or_retired, mc.module: mc_fog_ingest_server::controller, mc.src: fog/ingest/server/src/controller.rs:659
2024-09-30 20:40:41.827577332 UTC DEBG Writing state file to StateFile { file_path: "/tmp/.tmpbQtKFd/mc-fog-ingest-state-0" }, mc.node_id: 0, mc.test_name: inactive_outstanding_key_idle_has_key::inactive_oustanding_key_idle_node_has_original_key_node_is_activated_and_key_is_not_reported_lost_or_retired, mc.module: mc_fog_ingest_server::controller, mc.src: fog/ingest/server/src/controller.rs:1314
2024-09-30 20:40:41.847573567 UTC DEBG Peer backup insecure-igp://0.0.0.0:8616/ was confirmed, mc.node_id: 0, mc.test_name: inactive_outstanding_key_idle_has_key::inactive_oustanding_key_idle_node_has_original_key_node_is_activated_and_key_is_not_reported_lost_or_retired, mc.module: mc_fog_ingest_server::controller, mc.src: fog/ingest/server/src/controller.rs:1378
2024-09-30 20:40:41.866469543 UTC DEBG Now ingesting block #8 (id = BlockID(b74dfb15765961a68c0af8b7e9c81616ba0aa54c2cfb204e4d508e99f32511d4)), mc.node_id: 0, mc.test_name: inactive_outstanding_key_idle_has_key::inactive_oustanding_key_idle_node_has_original_key_node_is_activated_and_key_is_not_reported_lost_or_retired, mc.module: mc_fog_ingest_server::controller, mc.src: fog/ingest/server/src/controller.rs:428
2024-09-30 20:40:41.871557160 UTC INFO publishing report to DB, mc.node_id: 0, mc.test_name: inactive_outstanding_key_idle_has_key::inactive_oustanding_key_idle_node_has_original_key_node_is_activated_and_key_is_not_reported_lost_or_retired, mc.module: mc_fog_ingest_server::controller, mc.src: fog/ingest/server/src/controller.rs:1250
2024-09-30 20:40:41.872852591 UTC INFO Got status for key: IngressPublicKeyStatus { start_block: 1, pubkey_expiry: 18, retired: false, lost: false }, mc.test_name: inactive_outstanding_key_idle_has_key::inactive_oustanding_key_idle_node_has_original_key_node_is_activated_and_key_is_not_reported_lost_or_retired, mc.module: mc_fog_sql_recovery_db, mc.src: fog/sql_recovery_db/src/lib.rs:1214
2024-09-30 20:40:42.090800575 UTC DEBG Ingesting block #8: 4/4 txs ingested, mc.node_id: 0, mc.test_name: inactive_outstanding_key_idle_has_key::inactive_oustanding_key_idle_node_has_original_key_node_is_activated_and_key_is_not_reported_lost_or_retired, mc.module: mc_fog_ingest_server::controller, mc.src: fog/ingest/server/src/controller.rs:587
2024-09-30 20:40:42.090901373 UTC INFO add_block_data, mc.node_id: 0, mc.test_name: inactive_outstanding_key_idle_has_key::inactive_oustanding_key_idle_node_has_original_key_node_is_activated_and_key_is_not_reported_lost_or_retired, mc.module: mc_fog_ingest_server::controller, mc.src: fog/ingest/server/src/controller.rs:596
2024-09-30 20:40:42.097658336 UTC INFO Overseer worker thread stopping., mc.test_name: inactive_outstanding_key_idle_has_key::inactive_oustanding_key_idle_node_has_original_key_node_is_activated_and_key_is_not_reported_lost_or_retired, mc.module: mc_fog_overseer_server::worker, mc.src: fog/overseer/server/src/worker.rs:165
2024-09-30 20:40:42.103055581 UTC INFO Succeeded writing block 8 to the database, invocation id Some(IngestInvocationId(1)) ingress key CompressedRistrettoPublic(74fdd3896795ae3339f0f23ad825565c84eadb67a0e6cedecf35571dbed56755), mc.node_id: 0, mc.test_name: inactive_outstanding_key_idle_has_key::inactive_oustanding_key_idle_node_has_original_key_node_is_activated_and_key_is_not_reported_lost_or_retired, mc.module: mc_fog_ingest_server::controller, mc.src: fog/ingest/server/src/controller.rs:636
2024-09-30 20:40:42.103133055 UTC DEBG Incremented next block index: 9, mc.node_id: 0, mc.test_name: inactive_outstanding_key_idle_has_key::inactive_oustanding_key_idle_node_has_original_key_node_is_activated_and_key_is_not_reported_lost_or_retired, mc.module: mc_fog_ingest_server::controller_state, mc.src: fog/ingest/server/src/controller_state.rs:155
2024-09-30 20:40:42.103195502 UTC DEBG Controller state: { mode: Active, next_block_index: 9, pubkey_expiry_window: 10, ingest_invocation_id: 1, peers: [insecure-igp://0.0.0.0:8606/, insecure-igp://0.0.0.0:8611/, insecure-igp://0.0.0.0:8616/] }, mc.node_id: 0, mc.test_name: inactive_outstanding_key_idle_has_key::inactive_oustanding_key_idle_node_has_original_key_node_is_activated_and_key_is_not_reported_lost_or_retired, mc.module: mc_fog_ingest_server::controller, mc.src: fog/ingest/server/src/controller.rs:647
2024-09-30 20:40:42.103255904 UTC INFO Finished ingesting block #8, mc.node_id: 0, mc.test_name: inactive_outstanding_key_idle_has_key::inactive_oustanding_key_idle_node_has_original_key_node_is_activated_and_key_is_not_reported_lost_or_retired, mc.module: mc_fog_ingest_server::controller, mc.src: fog/ingest/server/src/controller.rs:659
2024-09-30 20:40:42.123733658 UTC DEBG Writing state file to StateFile { file_path: "/tmp/.tmpbQtKFd/mc-fog-ingest-state-0" }, mc.node_id: 0, mc.test_name: inactive_outstanding_key_idle_has_key::inactive_oustanding_key_idle_node_has_original_key_node_is_activated_and_key_is_not_reported_lost_or_retired, mc.module: mc_fog_ingest_server::controller, mc.src: fog/ingest/server/src/controller.rs:1314
2024-09-30 20:40:42.147546117 UTC INFO Stop Requested: Polling loop stopped at block number 9, is_idle false, mc.node_id: 0, mc.test_name: inactive_outstanding_key_idle_has_key::inactive_oustanding_key_idle_node_has_original_key_node_is_activated_and_key_is_not_reported_lost_or_retired, mc.module: mc_fog_ingest_server::worker, mc.src: fog/ingest/server/src/worker.rs:75
2024-09-30 20:40:42.848125188 UTC DEBG Peer checkup thread stop requested., mc.node_id: 0, mc.test_name: inactive_outstanding_key_idle_has_key::inactive_oustanding_key_idle_node_has_original_key_node_is_activated_and_key_is_not_reported_lost_or_retired, mc.module: mc_fog_ingest_server::worker, mc.src: fog/ingest/server/src/worker.rs:229
2024-09-30 20:40:43.086714624 UTC DEBG Checking up on peers..., mc.node_id: 1, mc.test_name: inactive_outstanding_key_idle_has_key::inactive_oustanding_key_idle_node_has_original_key_node_is_activated_and_key_is_not_reported_lost_or_retired, mc.module: mc_fog_ingest_server::worker, mc.src: fog/ingest/server/src/worker.rs:235
2024-09-30 20:40:43.843391942 UTC DEBG Report cache thread stop requested., mc.node_id: 0, mc.test_name: inactive_outstanding_key_idle_has_key::inactive_oustanding_key_idle_node_has_original_key_node_is_activated_and_key_is_not_reported_lost_or_retired, mc.module: mc_fog_ingest_server::worker, mc.src: fog/ingest/server/src/worker.rs:289
2024-09-30 20:40:44.641755595 UTC INFO Stop Requested: Polling loop stopped at block number 0, is_idle true, mc.node_id: 1, mc.test_name: inactive_outstanding_key_idle_has_key::inactive_oustanding_key_idle_node_has_original_key_node_is_activated_and_key_is_not_reported_lost_or_retired, mc.module: mc_fog_ingest_server::worker, mc.src: fog/ingest/server/src/worker.rs:75
2024-09-30 20:40:45.035999133 UTC DEBG Checking up on peers..., mc.node_id: 2, mc.test_name: inactive_outstanding_key_idle_has_key::inactive_oustanding_key_idle_node_has_original_key_node_is_activated_and_key_is_not_reported_lost_or_retired, mc.module: mc_fog_ingest_server::worker, mc.src: fog/ingest/server/src/worker.rs:235
2024-09-30 20:40:45.087130055 UTC DEBG Peer checkup thread stop requested., mc.node_id: 1, mc.test_name: inactive_outstanding_key_idle_has_key::inactive_oustanding_key_idle_node_has_original_key_node_is_activated_and_key_is_not_reported_lost_or_retired, mc.module: mc_fog_ingest_server::worker, mc.src: fog/ingest/server/src/worker.rs:229
2024-09-30 20:40:46.086079160 UTC DEBG Report cache thread stop requested., mc.node_id: 1, mc.test_name: inactive_outstanding_key_idle_has_key::inactive_oustanding_key_idle_node_has_original_key_node_is_activated_and_key_is_not_reported_lost_or_retired, mc.module: mc_fog_ingest_server::worker, mc.src: fog/ingest/server/src/worker.rs:289
2024-09-30 20:40:46.867632845 UTC INFO Stop Requested: Polling loop stopped at block number 0, is_idle true, mc.node_id: 2, mc.test_name: inactive_outstanding_key_idle_has_key::inactive_oustanding_key_idle_node_has_original_key_node_is_activated_and_key_is_not_reported_lost_or_retired, mc.module: mc_fog_ingest_server::worker, mc.src: fog/ingest/server/src/worker.rs:75
2024-09-30 20:40:47.036231685 UTC DEBG Peer checkup thread stop requested., mc.node_id: 2, mc.test_name: inactive_outstanding_key_idle_has_key::inactive_oustanding_key_idle_node_has_original_key_node_is_activated_and_key_is_not_reported_lost_or_retired, mc.module: mc_fog_ingest_server::worker, mc.src: fog/ingest/server/src/worker.rs:229
2024-09-30 20:40:48.034682674 UTC DEBG Report cache thread stop requested., mc.node_id: 2, mc.test_name: inactive_outstanding_key_idle_has_key::inactive_oustanding_key_idle_node_has_original_key_node_is_activated_and_key_is_not_reported_lost_or_retired, mc.module: mc_fog_ingest_server::worker, mc.src: fog/ingest/server/src/worker.rs:289

thread 'inactive_oustanding_key_idle_node_does_not_have_key_idle_node_is_activated_and_original_key_is_reported_lost' panicked at fog/overseer/server/tests/inactive_outstanding_key_idle_does_not_have_key.rs:40:12:
Timed out waiting for active node to process data; recovery_db has 4 blocks, target is 12
stack backtrace:
2024-09-30 20:40:31.080260349 UTC DEBG Checking on peer: insecure-igp://0.0.0.0:8566/, mc.node_id: 0, mc.test_name: inactive_outstanding_key_idle_does_not_have_key::inactive_oustanding_key_idle_node_does_not_have_key_idle_node_is_activated_and_original_key_is_reported_lost, mc.module: mc_fog_ingest_server::controller, mc.src: fog/ingest/server/src/controller.rs:1363
2024-09-30 20:40:31.080331992 UTC WARN Creating insecure gRPC connection to 0.0.0.0:8566, mc.peers.addr: 0.0.0.0:8566, mc.node_id: 0, mc.test_name: inactive_outstanding_key_idle_does_not_have_key::inactive_oustanding_key_idle_node_does_not_have_key_idle_node_is_activated_and_original_key_is_reported_lost, mc.module: mc_util_grpc::grpcio_extensions, mc.src: util/grpc/src/grpcio_extensions.rs:48
2024-09-30 20:40:31.289392358 UTC DEBG Ingesting block #4: 4/4 txs ingested, mc.node_id: 0, mc.test_name: inactive_outstanding_key_idle_does_not_have_key::inactive_oustanding_key_idle_node_does_not_have_key_idle_node_is_activated_and_original_key_is_reported_lost, mc.module: mc_fog_ingest_server::controller, mc.src: fog/ingest/server/src/controller.rs:587
2024-09-30 20:40:31.289467839 UTC INFO add_block_data, mc.node_id: 0, mc.test_name: inactive_outstanding_key_idle_does_not_have_key::inactive_oustanding_key_idle_node_does_not_have_key_idle_node_is_activated_and_original_key_is_reported_lost, mc.module: mc_fog_ingest_server::controller, mc.src: fog/ingest/server/src/controller.rs:596
2024-09-30 20:40:31.297684514 UTC DEBG Peer backup insecure-igp://0.0.0.0:8566/ was confirmed, mc.node_id: 0, mc.test_name: inactive_outstanding_key_idle_does_not_have_key::inactive_oustanding_key_idle_node_does_not_have_key_idle_node_is_activated_and_original_key_is_reported_lost, mc.module: mc_fog_ingest_server::controller, mc.src: fog/ingest/server/src/controller.rs:1378
   0: rust_begin_unwind
             at /rustc/ca62d2c445628587660ae48013f460b08b1f5552/library/std/src/panicking.rs:597:5
   1: core::panicking::panic_fmt
             at /rustc/ca62d2c445628587660ae48013f460b08b1f5552/library/core/src/panicking.rs:72:14
   2: mc_fog_ingest_server_test_utils::IngestServerTestHelper::wait_till_recovery_db_callback
             at /__w/mobilecoin/mobilecoin/fog/ingest/server/test-utils/src/lib.rs:308:13
   3: mc_fog_ingest_server_test_utils::IngestServerTestHelper::wait_till_recovery_db_in_sync_up_to
             at /__w/mobilecoin/mobilecoin/fog/ingest/server/test-utils/src/lib.rs:279:9
   4: mc_fog_ingest_server_test_utils::IngestServerTestHelper::wait_till_recovery_db_in_sync
             at /__w/mobilecoin/mobilecoin/fog/ingest/server/test-utils/src/lib.rs:272:9
   5: inactive_outstanding_key_idle_does_not_have_key::__wrapped_inactive_oustanding_key_idle_node_does_not_have_key_idle_node_is_activated_and_original_key_is_reported_lost
             at ./tests/inactive_outstanding_key_idle_does_not_have_key.rs:40:5
   6: inactive_outstanding_key_idle_does_not_have_key::inactive_oustanding_key_idle_node_does_not_have_key_idle_node_is_activated_and_original_key_is_reported_lost::{{closure}}
             at ./tests/inactive_outstanding_key_idle_does_not_have_key.rs:18:1
   7: slog_scope::scope
             at /opt/cargo/registry/src/index.crates.io-6f17d22bba15001f/slog-scope-4.4.0/lib.rs:248:5
   8: inactive_outstanding_key_idle_does_not_have_key::inactive_oustanding_key_idle_node_does_not_have_key_idle_node_is_activated_and_original_key_is_reported_lost
             at ./tests/inactive_outstanding_key_idle_does_not_have_key.rs:18:1
   9: inactive_outstanding_key_idle_does_not_have_key::inactive_oustanding_key_idle_node_does_not_have_key_idle_node_is_activated_and_original_key_is_reported_lost::{{closure}}
             at ./tests/inactive_outstanding_key_idle_does_not_have_key.rs:18:1
  10: core::ops::function::FnOnce::call_once
             at /rustc/ca62d2c445628587660ae48013f460b08b1f5552/library/core/src/ops/function.rs:250:5
  11: core::ops::function::FnOnce::call_once
             at /rustc/ca62d2c445628587660ae48013f460b08b1f5552/library/core/src/ops/function.rs:250:5
note: Some details are omitted, run with `RUST_BACKTRACE=full` for a verbose backtrace.
2024-09-30 20:40:31.351652698 UTC INFO Disabling overseer worker, mc.test_name: inactive_outstanding_key_idle_does_not_have_key::inactive_oustanding_key_idle_node_does_not_have_key_idle_node_is_activated_and_original_key_is_reported_lost, mc.module: mc_fog_overseer_server::service, mc.src: fog/overseer/server/src/service.rs:114
2024-09-30 20:40:32.063304782 UTC DEBG Checking up on peers..., mc.node_id: 1, mc.test_name: inactive_outstanding_key_idle_does_not_have_key::inactive_oustanding_key_idle_node_does_not_have_key_idle_node_is_activated_and_original_key_is_reported_lost, mc.module: mc_fog_ingest_server::worker, mc.src: fog/ingest/server/src/worker.rs:235
2024-09-30 20:40:32.298233322 UTC DEBG Checking up on peers..., mc.node_id: 0, mc.test_name: inactive_outstanding_key_idle_does_not_have_key::inactive_oustanding_key_idle_node_does_not_have_key_idle_node_is_activated_and_original_key_is_reported_lost, mc.module: mc_fog_ingest_server::worker, mc.src: fog/ingest/server/src/worker.rs:235
2024-09-30 20:40:32.298321977 UTC DEBG Checking on peer: insecure-igp://0.0.0.0:8561/, mc.node_id: 0, mc.test_name: inactive_outstanding_key_idle_does_not_have_key::inactive_oustanding_key_idle_node_does_not_have_key_idle_node_is_activated_and_original_key_is_reported_lost, mc.module: mc_fog_ingest_server::controller, mc.src: fog/ingest/server/src/controller.rs:1363
2024-09-30 20:40:32.298416784 UTC WARN Creating insecure gRPC connection to 0.0.0.0:8561, mc.peers.addr: 0.0.0.0:8561, mc.node_id: 0, mc.test_name: inactive_outstanding_key_idle_does_not_have_key::inactive_oustanding_key_idle_node_does_not_have_key_idle_node_is_activated_and_original_key_is_reported_lost, mc.module: mc_util_grpc::grpcio_extensions, mc.src: util/grpc/src/grpcio_extensions.rs:48
2024-09-30 20:40:32.327578931 UTC DEBG Peer backup insecure-igp://0.0.0.0:8561/ was confirmed, mc.node_id: 0, mc.test_name: inactive_outstanding_key_idle_does_not_have_key::inactive_oustanding_key_idle_node_does_not_have_key_idle_node_is_activated_and_original_key_is_reported_lost, mc.module: mc_fog_ingest_server::controller, mc.src: fog/ingest/server/src/controller.rs:1378
2024-09-30 20:40:32.328017409 UTC DEBG Checking on peer: insecure-igp://0.0.0.0:8566/, mc.node_id: 0, mc.test_name: inactive_outstanding_key_idle_does_not_have_key::inactive_oustanding_key_idle_node_does_not_have_key_idle_node_is_activated_and_original_key_is_reported_lost, mc.module: mc_fog_ingest_server::controller, mc.src: fog/ingest/server/src/controller.rs:1363
2024-09-30 20:40:32.328095385 UTC WARN Creating insecure gRPC connection to 0.0.0.0:8566, mc.peers.addr: 0.0.0.0:8566, mc.node_id: 0, mc.test_name: inactive_outstanding_key_idle_does_not_have_key::inactive_oustanding_key_idle_node_does_not_have_key_idle_node_is_activated_and_original_key_is_reported_lost, mc.module: mc_util_grpc::grpcio_extensions, mc.src: util/grpc/src/grpcio_extensions.rs:48
2024-09-30 20:40:32.356461376 UTC DEBG Peer backup insecure-igp://0.0.0.0:8566/ was confirmed, mc.node_id: 0, mc.test_name: inactive_outstanding_key_idle_does_not_have_key::inactive_oustanding_key_idle_node_does_not_have_key_idle_node_is_activated_and_original_key_is_reported_lost, mc.module: mc_fog_ingest_server::controller, mc.src: fog/ingest/server/src/controller.rs:1378
2024-09-30 20:40:33.523012413 UTC DEBG Checking up on peers..., mc.node_id: 2, mc.test_name: inactive_outstanding_key_idle_does_not_have_key::inactive_oustanding_key_idle_node_does_not_have_key_idle_node_is_activated_and_original_key_is_reported_lost, mc.module: mc_fog_ingest_server::worker, mc.src: fog/ingest/server/src/worker.rs:235
2024-09-30 20:40:36.335710713 UTC INFO Overseer worker thread stopping., mc.test_name: inactive_outstanding_key_idle_does_not_have_key::inactive_oustanding_key_idle_node_does_not_have_key_idle_node_is_activated_and_original_key_is_reported_lost, mc.module: mc_fog_overseer_server::worker, mc.src: fog/overseer/server/src/worker.rs:165
2024-09-30 20:40:37.035445732 UTC INFO Succeeded writing block 4 to the database, invocation id Some(IngestInvocationId(1)) ingress key CompressedRistrettoPublic(68cde24e7b404be994b960bb5598c528d8d919a2d8db2b217ae661aee822e41b), mc.node_id: 0, mc.test_name: inactive_outstanding_key_idle_does_not_have_key::inactive_oustanding_key_idle_node_does_not_have_key_idle_node_is_activated_and_original_key_is_reported_lost, mc.module: mc_fog_ingest_server::controller, mc.src: fog/ingest/server/src/controller.rs:636
2024-09-30 20:40:37.035565287 UTC DEBG Incremented next block index: 5, mc.node_id: 0, mc.test_name: inactive_outstanding_key_idle_does_not_have_key::inactive_oustanding_key_idle_node_does_not_have_key_idle_node_is_activated_and_original_key_is_reported_lost, mc.module: mc_fog_ingest_server::controller_state, mc.src: fog/ingest/server/src/controller_state.rs:155
2024-09-30 20:40:37.035657891 UTC DEBG Controller state: { mode: Active, next_block_index: 5, pubkey_expiry_window: 10, ingest_invocation_id: 1, peers: [insecure-igp://0.0.0.0:8556/, insecure-igp://0.0.0.0:8561/, insecure-igp://0.0.0.0:8566/] }, mc.node_id: 0, mc.test_name: inactive_outstanding_key_idle_does_not_have_key::inactive_oustanding_key_idle_node_does_not_have_key_idle_node_is_activated_and_original_key_is_reported_lost, mc.module: mc_fog_ingest_server::controller, mc.src: fog/ingest/server/src/controller.rs:647
2024-09-30 20:40:37.035777546 UTC INFO Finished ingesting block #4, mc.node_id: 0, mc.test_name: inactive_outstanding_key_idle_does_not_have_key::inactive_oustanding_key_idle_node_does_not_have_key_idle_node_is_activated_and_original_key_is_reported_lost, mc.module: mc_fog_ingest_server::controller, mc.src: fog/ingest/server/src/controller.rs:659
2024-09-30 20:40:37.052850309 UTC DEBG Writing state file to StateFile { file_path: "/tmp/.tmpsaYk3X/mc-fog-ingest-state-0" }, mc.node_id: 0, mc.test_name: inactive_outstanding_key_idle_does_not_have_key::inactive_oustanding_key_idle_node_does_not_have_key_idle_node_is_activated_and_original_key_is_reported_lost, mc.module: mc_fog_ingest_server::controller, mc.src: fog/ingest/server/src/controller.rs:1314
2024-09-30 20:40:37.063805155 UTC DEBG Checking up on peers..., mc.node_id: 1, mc.test_name: inactive_outstanding_key_idle_does_not_have_key::inactive_oustanding_key_idle_node_does_not_have_key_idle_node_is_activated_and_original_key_is_reported_lost, mc.module: mc_fog_ingest_server::worker, mc.src: fog/ingest/server/src/worker.rs:235
2024-09-30 20:40:37.357402177 UTC DEBG Checking up on peers..., mc.node_id: 0, mc.test_name: inactive_outstanding_key_idle_does_not_have_key::inactive_oustanding_key_idle_node_does_not_have_key_idle_node_is_activated_and_original_key_is_reported_lost, mc.module: mc_fog_ingest_server::worker, mc.src: fog/ingest/server/src/worker.rs:235
2024-09-30 20:40:38.056919846 UTC INFO Stop Requested: Polling loop stopped at block number 5, is_idle false, mc.node_id: 0, mc.test_name: inactive_outstanding_key_idle_does_not_have_key::inactive_oustanding_key_idle_node_does_not_have_key_idle_node_is_activated_and_original_key_is_reported_lost, mc.module: mc_fog_ingest_server::worker, mc.src: fog/ingest/server/src/worker.rs:75
2024-09-30 20:40:38.057003092 UTC DEBG Checking on peer: insecure-igp://0.0.0.0:8561/, mc.node_id: 0, mc.test_name: inactive_outstanding_key_idle_does_not_have_key::inactive_oustanding_key_idle_node_does_not_have_key_idle_node_is_activated_and_original_key_is_reported_lost, mc.module: mc_fog_ingest_server::controller, mc.src: fog/ingest/server/src/controller.rs:1363
2024-09-30 20:40:38.057061392 UTC WARN Creating insecure gRPC connection to 0.0.0.0:8561, mc.peers.addr: 0.0.0.0:8561, mc.node_id: 0, mc.test_name: inactive_outstanding_key_idle_does_not_have_key::inactive_oustanding_key_idle_node_does_not_have_key_idle_node_is_activated_and_original_key_is_reported_lost, mc.module: mc_util_grpc::grpcio_extensions, mc.src: util/grpc/src/grpcio_extensions.rs:48
2024-09-30 20:40:38.085920978 UTC DEBG Peer backup insecure-igp://0.0.0.0:8561/ was confirmed, mc.node_id: 0, mc.test_name: inactive_outstanding_key_idle_does_not_have_key::inactive_oustanding_key_idle_node_does_not_have_key_idle_node_is_activated_and_original_key_is_reported_lost, mc.module: mc_fog_ingest_server::controller, mc.src: fog/ingest/server/src/controller.rs:1378
2024-09-30 20:40:38.086356076 UTC DEBG Checking on peer: insecure-igp://0.0.0.0:8566/, mc.node_id: 0, mc.test_name: inactive_outstanding_key_idle_does_not_have_key::inactive_oustanding_key_idle_node_does_not_have_key_idle_node_is_activated_and_original_key_is_reported_lost, mc.module: mc_fog_ingest_server::controller, mc.src: fog/ingest/server/src/controller.rs:1363
2024-09-30 20:40:38.086446045 UTC WARN Creating insecure gRPC connection to 0.0.0.0:8566, mc.peers.addr: 0.0.0.0:8566, mc.node_id: 0, mc.test_name: inactive_outstanding_key_idle_does_not_have_key::inactive_oustanding_key_idle_node_does_not_have_key_idle_node_is_activated_and_original_key_is_reported_lost, mc.module: mc_util_grpc::grpcio_extensions, mc.src: util/grpc/src/grpcio_extensions.rs:48
2024-09-30 20:40:38.114958127 UTC DEBG Peer backup insecure-igp://0.0.0.0:8566/ was confirmed, mc.node_id: 0, mc.test_name: inactive_outstanding_key_idle_does_not_have_key::inactive_oustanding_key_idle_node_does_not_have_key_idle_node_is_activated_and_original_key_is_reported_lost, mc.module: mc_fog_ingest_server::controller, mc.src: fog/ingest/server/src/controller.rs:1378
2024-09-30 20:40:38.523570075 UTC DEBG Checking up on peers..., mc.node_id: 2, mc.test_name: inactive_outstanding_key_idle_does_not_have_key::inactive_oustanding_key_idle_node_does_not_have_key_idle_node_is_activated_and_original_key_is_reported_lost, mc.module: mc_fog_ingest_server::worker, mc.src: fog/ingest/server/src/worker.rs:235
2024-09-30 20:40:39.115534335 UTC DEBG Peer checkup thread stop requested., mc.node_id: 0, mc.test_name: inactive_outstanding_key_idle_does_not_have_key::inactive_oustanding_key_idle_node_does_not_have_key_idle_node_is_activated_and_original_key_is_reported_lost, mc.module: mc_fog_ingest_server::worker, mc.src: fog/ingest/server/src/worker.rs:229
2024-09-30 20:40:39.840328413 UTC DEBG Report cache thread stop requested., mc.node_id: 0, mc.test_name: inactive_outstanding_key_idle_does_not_have_key::inactive_oustanding_key_idle_node_does_not_have_key_idle_node_is_activated_and_original_key_is_reported_lost, mc.module: mc_fog_ingest_server::worker, mc.src: fog/ingest/server/src/worker.rs:289
2024-09-30 20:40:40.608292482 UTC INFO Stop Requested: Polling loop stopped at block number 0, is_idle true, mc.node_id: 1, mc.test_name: inactive_outstanding_key_idle_does_not_have_key::inactive_oustanding_key_idle_node_does_not_have_key_idle_node_is_activated_and_original_key_is_reported_lost, mc.module: mc_fog_ingest_server::worker, mc.src: fog/ingest/server/src/worker.rs:75
2024-09-30 20:40:41.064269081 UTC DEBG Peer checkup thread stop requested., mc.node_id: 1, mc.test_name: inactive_outstanding_key_idle_does_not_have_key::inactive_oustanding_key_idle_node_does_not_have_key_idle_node_is_activated_and_original_key_is_reported_lost, mc.module: mc_fog_ingest_server::worker, mc.src: fog/ingest/server/src/worker.rs:229
2024-09-30 20:40:41.474334110 UTC DEBG Report cache thread stop requested., mc.node_id: 1, mc.test_name: inactive_outstanding_key_idle_does_not_have_key::inactive_oustanding_key_idle_node_does_not_have_key_idle_node_is_activated_and_original_key_is_reported_lost, mc.module: mc_fog_ingest_server::worker, mc.src: fog/ingest/server/src/worker.rs:289
2024-09-30 20:40:42.237605490 UTC INFO Stop Requested: Polling loop stopped at block number 0, is_idle true, mc.node_id: 2, mc.test_name: inactive_outstanding_key_idle_does_not_have_key::inactive_oustanding_key_idle_node_does_not_have_key_idle_node_is_activated_and_original_key_is_reported_lost, mc.module: mc_fog_ingest_server::worker, mc.src: fog/ingest/server/src/worker.rs:75
2024-09-30 20:40:42.523932012 UTC DEBG Peer checkup thread stop requested., mc.node_id: 2, mc.test_name: inactive_outstanding_key_idle_does_not_have_key::inactive_oustanding_key_idle_node_does_not_have_key_idle_node_is_activated_and_original_key_is_reported_lost, mc.module: mc_fog_ingest_server::worker, mc.src: fog/ingest/server/src/worker.rs:229
2024-09-30 20:40:43.522678690 UTC DEBG Report cache thread stop requested., mc.node_id: 2, mc.test_name: inactive_outstanding_key_idle_does_not_have_key::inactive_oustanding_key_idle_node_does_not_have_key_idle_node_is_activated_and_original_key_is_reported_lost, mc.module: mc_fog_ingest_server::worker, mc.src: fog/ingest/server/src/worker.rs:289