Track pubsub topic validator receives - F-ssv-1044 - #2843
Open
julienharbulot wants to merge 4 commits into
Open
Conversation
Codecov Report✅ All modified and coverable lines are covered by tests. ☔ View full report in Codecov by Harness. 🚀 New features to boost your workflow:
|
Contributor
Greptile SummaryThis PR closes the observability gap identified in F-ssv-1044 by recording a new counter (
Confidence Score: 5/5Safe to merge — the change is an additive, read-path-only counter increment that cannot affect message routing or validation outcomes. The wrapping closure is minimal and correct, the attribute key follows the project namespacing convention, and the test verifies both the counter value and the attribute via the shared constant. No behavioral logic is altered. No files require special attention. Important Files Changed
Sequence DiagramsequenceDiagram
participant libp2p as libp2p PubSub
participant wrap as wrappedValidator (new)
participant otel as OTel Counter<br/>ssv.p2p.pubsub.messages.received
participant val as SSV msgValidator
libp2p->>wrap: ValidatorFunc(ctx, peerID, msg)
wrap->>otel: recordPubsubMessageReceived(ctx, topic)
otel-->>wrap: counter incremented
wrap->>val: validator(ctx, peerID, msg)
val-->>wrap: ValidationResult
wrap-->>libp2p: ValidationResult
Reviews (2): Last reviewed commit: "Merge branch 'stage' into F-ssv-1044" | Re-trigger Greptile |
![greptile-apps[bot]](https://avatars.githubusercontent.com/in/867647?s=60&v=4){kind=small}
Contributor
|
@greptile pls re-review |
Contributor
|
/test |
🟢 Test run for PR #2843Branch: F-ssv-1044 Status
Click to expand executor logs═══════════════════════════════════════════════════════════════════════════════════════════════════════
🧪 WELCOME TO Executor - SSV's Distributed Test Automation Execution Layer 🧪
___ __ __ ___ ___ _ _ _____ ___ ___
| __|\\ \\/ /| __|/ __|| | | ||_ _|/ _ \\ | _ \\
| _| > < | _|| (__ | |_| | | | | (_) || /
|___|/_/\\_\\|___|\\___| \\___/ |_| \\___/ |_|_\\
═══════════════════════════════════════════════════════════════════════════════════════════════════════
{"time":"2026-05-28T10:53:13.360274391Z","level":"INFO","msg":"🐳 Docker mode: Using environment variables for config generation"}
{"time":"2026-05-28T10:53:13.365262014Z","level":"INFO","msg":"🌐 Orchestrator API Client initialized","endpoint":"http://aetheria-orchestrator.aetheria.svc:8080"}
{"time":"2026-05-28T10:53:13.36528822Z","level":"INFO","msg":"📝 Requesting configuration generation from orchestrator API","network":"hoodi_stage","clusters":[300,301,302,303],"tests":"(sanity,e2m),(bulk,e2m,5)"}
{"time":"2026-05-28T10:53:13.394054222Z","level":"INFO","msg":"✅ Configuration generated successfully via API","resource_usage_id":"40f43b150002f6b599c46540a0d18680"}
{"time":"2026-05-28T10:53:13.394424152Z","level":"INFO","msg":"🚀 EXECUTOR Initialized Successfully"}
{"time":"2026-05-28T10:53:13.394438584Z","level":"INFO","msg":"⚙️ Test configuration loaded","network":"hoodi_stage","nodes":[300,301,302,303],"test_type":{"Sanity":{"ShouldRun":true,"E2M":true,"Threshold":false,"BulkAmount":0},"Bulk":{"ShouldRun":true,"E2M":true,"Threshold":false,"BulkAmount":5},"DbTest":{"ShouldRun":false,"MaxDurationSeconds":0},"Isolated":{"Tests":null}}}
{"time":"2026-05-28T10:53:16.25471467Z","level":"INFO","msg":"Generated operator pubkeys file","module":"scanner","path":"/app/shared/data/operators/operator-pubkeys-hoodi_stage.json"}
{"time":"2026-05-28T10:53:16.254873524Z","level":"INFO","msg":"Registered parser","module":"main","component":"parser-client","parser_type":"consensus"}
{"time":"2026-05-28T10:53:16.254897305Z","level":"INFO","msg":"Registered parser","module":"main","component":"parser-client","parser_type":"flow-emits"}
{"time":"2026-05-28T10:53:16.25492323Z","level":"INFO","msg":"Validation client initialized","module":"main","loki_enabled":true,"e2m_enabled":true}
{"time":"2026-05-28T10:53:16.254947666Z","level":"INFO","msg":"🔑 KEY STEP: Starting Isolated Tests Concurrently if exists...","module":"main"}
{"time":"2026-05-28T10:53:16.254974016Z","level":"INFO","msg":"🔑 KEY STEP: Starting Sanity Test Suite","module":"main"}
{"time":"2026-05-28T10:53:16.255019044Z","level":"INFO","msg":"Sanity: config values","test":"sanity","cluster_owner":"0x91E32eFb8139cd88caE0Df30d2Bf471294c6ed27","account_public_key":"0x91E32eFb8139cd88caE0Df30d2Bf471294c6ed27","operator_ids":[300,301,302,303]}
{"time":"2026-05-28T10:53:16.255120044Z","level":"INFO","msg":"No isolated tests configured, skipping","module":"main"}
{"time":"2026-05-28T10:53:16.319619924Z","level":"INFO","msg":"Available slots","test":"sanity","node":300,"slots":3000}
{"time":"2026-05-28T10:53:16.329617644Z","level":"INFO","msg":"Available slots","test":"sanity","node":301,"slots":1010}
{"time":"2026-05-28T10:53:16.341914329Z","level":"INFO","msg":"Available slots","test":"sanity","node":302,"slots":3000}
{"time":"2026-05-28T10:53:16.369947451Z","level":"INFO","msg":"Available slots","test":"sanity","node":303,"slots":1324}
{"time":"2026-05-28T10:53:52.649827081Z","level":"INFO","msg":"Extracted keyshares path","test":"sanity","module":"keys","path":"/app/shared/data/keyshares/0x83142d846a6b78759863175ff9ad7890bd47a1a534b63f3949080484082164adde97a829291e6dc0c5099d82657bf754.json"}
{"time":"2026-05-28T10:53:52.650496988Z","level":"INFO","msg":"Key shares file generated successfully","test":"sanity","keyshare_path":"/app/shared/data/keyshares/0x83142d846a6b78759863175ff9ad7890bd47a1a534b63f3949080484082164adde97a829291e6dc0c5099d82657bf754.json"}
{"time":"2026-05-28T10:53:57.088566502Z","level":"INFO","msg":"Cluster asset type before write","test":"sanity","asset_type":1,"asset_err":null,"asset_label":"ETH"}
{"time":"2026-05-28T10:54:01.886598256Z","level":"INFO","msg":"📝 tx gas limit set (estimate + buffer)","test":"sanity","module":"contract","contract":"0xc07B3E9671f884FDa67E1e7D43d952E0e1369fd8","method":"registerValidator","estimated_gas":244491,"gas_buffer_pct":1000,"gas_limit":2689401}
{"time":"2026-05-28T10:54:01.901592292Z","level":"INFO","msg":"1️⃣ Registering validator","test":"sanity","module":"contract","tx_hash":"0x7753d671556bbd71cdd09ef02c18e8d2dc13cf85a3163aa204ecc0ab9f26309a"}
{"time":"2026-05-28T10:54:01.916416444Z","level":"INFO","msg":"Waiting for transaction receipt, retrying...","test":"sanity","module":"contract","attempt":1,"sleep":10,"tx_hash":"0x7753d671556bbd71cdd09ef02c18e8d2dc13cf85a3163aa204ecc0ab9f26309a","tx_state":"pending"}
{"time":"2026-05-28T10:54:11.933743811Z","level":"INFO","msg":"Waiting for transaction receipt, retrying...","test":"sanity","module":"contract","attempt":2,"sleep":20,"tx_hash":"0x7753d671556bbd71cdd09ef02c18e8d2dc13cf85a3163aa204ecc0ab9f26309a","tx_state":"pending"}
{"time":"2026-05-28T10:54:31.939985723Z","level":"INFO","msg":"Transaction receipt received","test":"sanity","module":"contract","tx_hash":"0x7753d671556bbd71cdd09ef02c18e8d2dc13cf85a3163aa204ecc0ab9f26309a"}
{"time":"2026-05-28T10:54:31.940117553Z","level":"INFO","msg":"📜 CONTRACT: Contract Register Successful","test":"sanity","txHash":"0x7753d671556bbd71cdd09ef02c18e8d2dc13cf85a3163aa204ecc0ab9f26309a","block_hash":"0xe022f2f7d083072bc81cfa9cff823b4f5ebcd790f32852a1330b50ee1e3aa076"}
{"time":"2026-05-28T10:54:31.949034699Z","level":"INFO","msg":"Exporter: validator not indexed yet (or index=0), retrying until non-zero index appears or max attempts is reached","test":"sanity","module":"helpers","pubkey":"0x83142d846a6b78759863175ff9ad7890bd47a1a534b63f3949080484082164adde97a829291e6dc0c5099d82657bf754","delay_seconds":15,"max_attempts":20}
{"time":"2026-05-28T10:56:17.014340108Z","level":"INFO","msg":"Successfully retrieved validator index from exporter","test":"sanity","module":"helpers","pubkey":"0x83142d846a6b78759863175ff9ad7890bd47a1a534b63f3949080484082164adde97a829291e6dc0c5099d82657bf754"}
{"time":"2026-05-28T10:56:17.023379918Z","level":"INFO","msg":"E2M registration: polling until assigned/executed match validator count","module":"main","module":"e2m-validator","validation_type":"registration","registered_epoch":98313,"indices":"1102420","poll_interval_seconds":15,"fail_if_current_epoch_gt":98317}
{"time":"2026-05-28T10:56:17.132397314Z","level":"INFO","msg":"Validator event validation successful","module":"main","module":"loki-validator","validated_validators":1,"event":"ValidatorAdded"}
{"time":"2026-05-28T10:56:17.132504333Z","level":"INFO","msg":"Loki: SSV node log validation successful","test":"sanity","indices":["1102420"],"validators":1,"validate-type":"registration"}
{"time":"2026-05-28T10:58:17.263688921Z","level":"INFO","msg":"E2M registration check: still polling for assigned/executed to match validator count","module":"main","module":"e2m-validator","validation_type":"registration","indices":["1102420"],"registered_epoch":98313,"current_epoch":98312,"assigned":0,"executed":0,"missed":0}
{"time":"2026-05-28T11:00:17.464750664Z","level":"INFO","msg":"E2M registration check: still polling for assigned/executed to match validator count","module":"main","module":"e2m-validator","validation_type":"registration","indices":["1102420"],"registered_epoch":98313,"current_epoch":98312,"assigned":0,"executed":0,"missed":0}
{"time":"2026-05-28T11:02:17.715299062Z","level":"INFO","msg":"E2M registration check: still polling for assigned/executed to match validator count","module":"main","module":"e2m-validator","validation_type":"registration","indices":["1102420"],"registered_epoch":98313,"current_epoch":98313,"assigned":0,"executed":0,"missed":0}
{"time":"2026-05-28T11:04:17.902934123Z","level":"INFO","msg":"E2M registration check: still polling for assigned/executed to match validator count","module":"main","module":"e2m-validator","validation_type":"registration","indices":["1102420"],"registered_epoch":98313,"current_epoch":98313,"assigned":0,"executed":0,"missed":0}
{"time":"2026-05-28T11:06:18.16313905Z","level":"INFO","msg":"E2M registration check: still polling for assigned/executed to match validator count","module":"main","module":"e2m-validator","validation_type":"registration","indices":["1102420"],"registered_epoch":98313,"current_epoch":98313,"assigned":0,"executed":0,"missed":0}
{"time":"2026-05-28T11:06:33.202497039Z","level":"INFO","msg":"E2M registration validation successful - validators are attesting","module":"main","module":"e2m-validator","validation_type":"registration","indices":["1102420"],"registered_epoch":98313,"validated_epoch":98314,"epochs_waited":1}
{"time":"2026-05-28T11:06:33.202597524Z","level":"INFO","msg":"E2M validation successful","test":"sanity","indices":["1102420"],"validate-type":"registration"}
{"time":"2026-05-28T11:06:33.202648573Z","level":"INFO","msg":"Starting consensus validation with epoch iteration logic","module":"main","module":"loki-validator","validator_indices":["1102420"],"registered_epoch":98313,"max_epoch_offset":8}
{"time":"2026-05-28T11:06:33.212623053Z","level":"INFO","msg":"Consensus: Loki committee/aggregate lines restricted to logs at or after registration","module":"main","module":"loki-validator","registration_block_hash":"0xe022f2f7d083072bc81cfa9cff823b4f5ebcd790f32852a1330b50ee1e3aa076","not_before_utc":"2026-05-28T10:54:24Z"}
{"time":"2026-05-28T11:06:53.224379673Z","level":"INFO","msg":"Checking epoch for duties","module":"main","module":"loki-validator","epoch_offset":0,"current_epoch":"98313","validator_indices":["1102420"]}
{"time":"2026-05-28T11:06:53.229679107Z","level":"WARN","msg":"No attesters found in duties response for one or more validators","module":"main","module":"loki-validator","epoch_offset":0,"epoch":"98313"}
{"time":"2026-05-28T11:07:03.229885873Z","level":"INFO","msg":"Checking epoch for duties","module":"main","module":"loki-validator","epoch_offset":1,"current_epoch":"98314","validator_indices":["1102420"]}
{"time":"2026-05-28T11:07:03.235220656Z","level":"INFO","msg":"Successfully found duties, building duty ID for consensus validation","module":"main","module":"loki-validator","duty_id":"COMMITTEE-300_301_302_303-e98314-s3146066","final_epoch":"98314","slot":"3146066","validator_index":"1102420"}
{"time":"2026-05-28T11:07:03.35258193Z","level":"INFO","msg":"Consensus: QBFT start logs","module":"main","module":"loki-validator","duty_id":"COMMITTEE-300_301_302_303-e98314-s3146066","qbft_start_log_count":4,"canonical_round":1,"canonical_height":3146066,"canonical_leader":"302","container":"","canonical_log_time":"2026-05-28T11:03:12.884423Z"}
{"time":"2026-05-28T11:07:03.352623619Z","level":"INFO","msg":"Consensus: leader matches QBFT round-robin (ssv-spec v1.2.2 style - no eth epoch term)","module":"main","module":"loki-validator","duty_id":"COMMITTEE-300_301_302_303-e98314-s3146066","round":1,"height":3146066,"qbft_eth_epoch":98314,"leader":302}
{"time":"2026-05-28T11:07:03.352632288Z","level":"INFO","msg":"Consensus leader validation passed","module":"main","module":"loki-validator","round":1,"leader":302}
{"time":"2026-05-28T11:07:03.461403847Z","level":"WARN","msg":"Consensus: aggregate duty in Loki but no timing metrics yet - retrying with backoff...)","module":"main","module":"loki-validator","aggregate_duty_ids":["AGGREGATOR_COMMITTEE-300_301_302_303-e98314-s3146066","AGGREGATOR-e98314-s3146066-v1102420"],"max_attempts":12,"retry_interval_seconds":20}
{"time":"2026-05-28T11:10:44.14467669Z","level":"WARN","msg":"Consensus timing skipped: no aggregate submission log lines found for aggregate duty id after retries","module":"main","module":"loki-validator","aggregate_duty_ids":["AGGREGATOR_COMMITTEE-300_301_302_303-e98314-s3146066","AGGREGATOR-e98314-s3146066-v1102420"],"last_aggregate_duty_id":"AGGREGATOR-e98314-s3146066-v1102420","attempts":12,"loki_lines":32,"aggregate_submission_logs":0}
{"time":"2026-05-28T11:10:44.145352483Z","level":"WARN","msg":"Consensus timing skipped: aggregate metrics missing after retries","module":"main","module":"loki-validator","committee_duty_id":"COMMITTEE-300_301_302_303-e98314-s3146066","aggregate_duty_ids":["AGGREGATOR_COMMITTEE-300_301_302_303-e98314-s3146066","AGGREGATOR-e98314-s3146066-v1102420"]}
{"time":"2026-05-28T11:10:44.145371762Z","level":"INFO","msg":"Consensus validation completed successfully","module":"main","module":"loki-validator","duty_id":"COMMITTEE-300_301_302_303-e98314-s3146066","final_epoch":"98314"}
{"time":"2026-05-28T11:10:44.145385723Z","level":"INFO","msg":"Consensus timing validation successful","test":"sanity","indices":["1102420"],"epoch":98313}
{"time":"2026-05-28T11:10:44.145416217Z","level":"INFO","msg":"✅ SUCCESS: Registration Validation Success","test":"sanity","validate_type":"registration","e2m_enabled":true,"e2m_success":true,"loki_success":true}
{"time":"2026-05-28T11:10:48.179926682Z","level":"INFO","msg":"📝 tx gas limit set (estimate + buffer)","test":"sanity","module":"contract","contract":"0xc07B3E9671f884FDa67E1e7D43d952E0e1369fd8","method":"liquidate","estimated_gas":149318,"gas_buffer_pct":1000,"gas_limit":1642498}
{"time":"2026-05-28T11:10:48.191199401Z","level":"INFO","msg":"2️⃣ Liquidating cluster","test":"sanity","module":"contract","tx_hash":"0x1e5d70ec7399807d04307a5719021954784cf4356b1a5420b8089d4cf05df7b4"}
{"time":"2026-05-28T11:10:48.205725985Z","level":"INFO","msg":"Waiting for transaction receipt, retrying...","test":"sanity","module":"contract","attempt":1,"sleep":10,"tx_hash":"0x1e5d70ec7399807d04307a5719021954784cf4356b1a5420b8089d4cf05df7b4","tx_state":"pending"}
{"time":"2026-05-28T11:10:58.227705898Z","level":"INFO","msg":"Waiting for transaction receipt, retrying...","test":"sanity","module":"contract","attempt":2,"sleep":20,"tx_hash":"0x1e5d70ec7399807d04307a5719021954784cf4356b1a5420b8089d4cf05df7b4","tx_state":"pending"}
{"time":"2026-05-28T11:11:18.232120749Z","level":"INFO","msg":"Transaction receipt received","test":"sanity","module":"contract","tx_hash":"0x1e5d70ec7399807d04307a5719021954784cf4356b1a5420b8089d4cf05df7b4"}
{"time":"2026-05-28T11:11:18.232194421Z","level":"INFO","msg":"📜 CONTRACT: Cluster Liquidation Successful","test":"sanity","txHash":"0x1e5d70ec7399807d04307a5719021954784cf4356b1a5420b8089d4cf05df7b4","block_hash":"0x56565a5c8a5b68af00770fb6910c2ee7a3f2391494c87d05a29fc90ea8989c84"}
{"time":"2026-05-28T11:11:18.243615336Z","level":"INFO","msg":"waiting for block to be found","module":"main","module":"e2m-validator","module":"e2m"}
{"time":"2026-05-28T11:11:18.285563161Z","level":"INFO","msg":"Loki: no matching logs yet, retrying until data appears or max attempts is reached","module":"main","module":"loki-validator","attempts":1,"retry_delay":"20s","start_unix":1779955878,"end_unix":1779966678}
{"time":"2026-05-28T11:11:38.250078925Z","level":"INFO","msg":"waiting for block to be found","module":"main","module":"e2m-validator","module":"e2m"}
{"time":"2026-05-28T11:11:58.258120674Z","level":"INFO","msg":"waiting for block to be found","module":"main","module":"e2m-validator","module":"e2m"}
{"time":"2026-05-28T11:12:18.262458925Z","level":"INFO","msg":"Liquidation tx epoch: polling E2M until validators are all missed or have zero assigned duties","module":"main","module":"e2m-validator","validation_type":"liquidation","epoch":98315,"indices":"1102420","poll_interval_seconds":15,"fail_if_current_epoch_gte":98317,"fail_after_epochs_past_liquidation_tx":2}
{"time":"2026-05-28T11:12:33.295949662Z","level":"INFO","msg":"Validator still active after liquidation wait","module":"main","module":"e2m-validator","epoch":98315,"indices":["1102420"],"assigned":1,"executed":1,"missed":0}
{"time":"2026-05-28T11:12:58.387587971Z","level":"INFO","msg":"Event validation successful","module":"main","module":"loki-validator","valid_entries":4,"event":"ClusterLiquidated"}
{"time":"2026-05-28T11:12:58.387632471Z","level":"INFO","msg":"Loki: SSV node log validation successful","test":"sanity","indices":["1102420"],"validators":1,"validate-type":"liquidation"}
{"time":"2026-05-28T11:12:58.387641745Z","level":"INFO","msg":"E2M validation still in progress: waiting to confirm whether validators are no longer active on-chain duties (polling each 15s, next log may take several minutes)","test":"sanity","indices":["1102420"],"validators":1,"validate-type":"liquidation"}
{"time":"2026-05-28T11:14:33.505912333Z","level":"INFO","msg":"Waiting for liquidation criteria (all missed or zero assigned; same epoch, still polling E2M)","module":"main","module":"e2m-validator","epoch":98315,"indices":["1102420"],"liquidated_epoch":98315,"assigned":1,"executed":1,"missed":0}
{"time":"2026-05-28T11:16:33.699252375Z","level":"INFO","msg":"Waiting for liquidation criteria (all missed or zero assigned; same epoch, still polling E2M)","module":"main","module":"e2m-validator","epoch":98315,"indices":["1102420"],"liquidated_epoch":98315,"assigned":1,"executed":1,"missed":0}
{"time":"2026-05-28T11:18:33.892159669Z","level":"INFO","msg":"Waiting for liquidation criteria (all missed or zero assigned; same epoch, still polling E2M)","module":"main","module":"e2m-validator","epoch":98315,"indices":["1102420"],"liquidated_epoch":98315,"assigned":1,"executed":1,"missed":0}
{"time":"2026-05-28T11:19:49.023476441Z","level":"INFO","msg":"E2M liquidation validation successful - validators are liquidated","module":"main","module":"e2m-validator","validation_type":"liquidation","indices":["1102420"],"liquidated_epoch":98315,"validated_epoch":98316,"epochs_waited":1,"assigned":1,"missed":1}
{"time":"2026-05-28T11:19:49.023567671Z","level":"INFO","msg":"E2M validation successful","test":"sanity","indices":["1102420"],"validate-type":"liquidation"}
{"time":"2026-05-28T11:19:49.023594637Z","level":"INFO","msg":"✅ SUCCESS: Liquidation Validation Success","test":"sanity","validate_type":"liquidation","e2m_enabled":true,"e2m_success":true,"loki_success":true}
{"time":"2026-05-28T11:19:53.149513671Z","level":"INFO","msg":"📝 tx gas limit set (estimate + buffer)","test":"sanity","module":"contract","contract":"0xc07B3E9671f884FDa67E1e7D43d952E0e1369fd8","method":"reactivate","estimated_gas":141639,"gas_buffer_pct":1000,"gas_limit":1558029}
{"time":"2026-05-28T11:19:53.171576795Z","level":"INFO","msg":"3️⃣ Reactivating cluster","test":"sanity","module":"contract","tx_hash":"0xdf25f25fd822f7e1baa20c841dd2b129be040e3a874a162568221142e0a6d298"}
{"time":"2026-05-28T11:19:53.18588153Z","level":"INFO","msg":"Waiting for transaction receipt, retrying...","test":"sanity","module":"contract","attempt":1,"sleep":10,"tx_hash":"0xdf25f25fd822f7e1baa20c841dd2b129be040e3a874a162568221142e0a6d298","tx_state":"pending"}
{"time":"2026-05-28T11:20:03.196300364Z","level":"INFO","msg":"Waiting for transaction receipt, retrying...","test":"sanity","module":"contract","attempt":2,"sleep":20,"tx_hash":"0xdf25f25fd822f7e1baa20c841dd2b129be040e3a874a162568221142e0a6d298","tx_state":"pending"}
{"time":"2026-05-28T11:20:23.200059734Z","level":"INFO","msg":"Transaction receipt received","test":"sanity","module":"contract","tx_hash":"0xdf25f25fd822f7e1baa20c841dd2b129be040e3a874a162568221142e0a6d298"}
{"time":"2026-05-28T11:20:23.200098546Z","level":"INFO","msg":"📜 CONTRACT: Cluster Reactivation Successful","test":"sanity","txHash":"0xdf25f25fd822f7e1baa20c841dd2b129be040e3a874a162568221142e0a6d298","block_hash":"0xb8203a1901f1b9ebdd160c05e285e9d33313588d1989e3e21e859fd60adfe821"}
{"time":"2026-05-28T11:20:23.200129931Z","level":"INFO","msg":"Validating reactivation - checking that validators resume attesting","module":"main","module":"e2m-validator","indices":["1102420"],"block_hash":"0xb8203a1901f1b9ebdd160c05e285e9d33313588d1989e3e21e859fd60adfe821"}
{"time":"2026-05-28T11:20:23.204445895Z","level":"INFO","msg":"E2M registration: polling until assigned/executed match validator count","module":"main","module":"e2m-validator","validation_type":"registration","registered_epoch":98317,"indices":"1102420","poll_interval_seconds":15,"fail_if_current_epoch_gt":98321}
{"time":"2026-05-28T11:20:23.264112494Z","level":"INFO","msg":"Loki: no matching logs yet, retrying until data appears or max attempts is reached","module":"main","module":"loki-validator","attempts":1,"retry_delay":"20s","start_unix":1779956423,"end_unix":1779967223}
{"time":"2026-05-28T11:22:03.392972168Z","level":"INFO","msg":"Event validation successful","module":"main","module":"loki-validator","valid_entries":4,"event":"ClusterReactivated"}
{"time":"2026-05-28T11:22:03.393012001Z","level":"INFO","msg":"Loki: SSV node log validation successful","test":"sanity","indices":["1102420"],"validators":1,"validate-type":"reactivation"}
{"time":"2026-05-28T11:22:23.428554715Z","level":"INFO","msg":"E2M registration check: still polling for assigned/executed to match validator count","module":"main","module":"e2m-validator","validation_type":"registration","indices":["1102420"],"registered_epoch":98317,"current_epoch":98316,"assigned":1,"executed":0,"missed":1}
{"time":"2026-05-28T11:22:53.474682387Z","level":"WARN","msg":"HTTP request attempt failed","module":"HTTPRequester","error":"Get \\"http://e2m-hoodi.e2m.svc:8000/api/stats?indices=1102420&latest=1&minus=1\\": dial tcp 10.43.132.11:8000: connect: connection refused","attempt":"1/7","will_retry":true,"next_retry_in":"2s"}
{"time":"2026-05-28T11:22:55.479655626Z","level":"WARN","msg":"HTTP request attempt failed","module":"HTTPRequester","error":"Get \\"http://e2m-hoodi.e2m.svc:8000/api/stats?indices=1102420&latest=1&minus=1\\": dial tcp 10.43.132.11:8000: connect: connection refused","attempt":"2/7","will_retry":true,"next_retry_in":"3s"}
{"time":"2026-05-28T11:22:58.486135216Z","level":"WARN","msg":"HTTP request attempt failed","module":"HTTPRequester","error":"Get \\"http://e2m-hoodi.e2m.svc:8000/api/stats?indices=1102420&latest=1&minus=1\\": dial tcp 10.43.132.11:8000: connect: connection refused","attempt":"3/7","will_retry":true,"next_retry_in":"5s"}
{"time":"2026-05-28T11:23:03.492219989Z","level":"WARN","msg":"HTTP request attempt failed","module":"HTTPRequester","error":"Get \\"http://e2m-hoodi.e2m.svc:8000/api/stats?indices=1102420&latest=1&minus=1\\": dial tcp 10.43.132.11:8000: connect: connection refused","attempt":"4/7","will_retry":true,"next_retry_in":"5s"}
{"time":"2026-05-28T11:23:08.496537771Z","level":"WARN","msg":"HTTP request attempt failed","module":"HTTPRequester","error":"Get \\"http://e2m-hoodi.e2m.svc:8000/api/stats?indices=1102420&latest=1&minus=1\\": dial tcp 10.43.132.11:8000: connect: connection refused","attempt":"5/7","will_retry":true,"next_retry_in":"5s"}
{"time":"2026-05-28T11:23:13.504036621Z","level":"WARN","msg":"HTTP request attempt failed","module":"HTTPRequester","error":"Get \\"http://e2m-hoodi.e2m.svc:8000/api/stats?indices=1102420&latest=1&minus=1\\": dial tcp 10.43.132.11:8000: connect: connection refused","attempt":"6/7","will_retry":true,"next_retry_in":"5s"}
{"time":"2026-05-28T11:24:33.706402883Z","level":"INFO","msg":"E2M registration check: still polling for assigned/executed to match validator count","module":"main","module":"e2m-validator","validation_type":"registration","indices":["1102420"],"registered_epoch":98317,"current_epoch":98316,"assigned":1,"executed":0,"missed":1}
{"time":"2026-05-28T11:26:33.926943293Z","level":"INFO","msg":"E2M registration check: still polling for assigned/executed to match validator count","module":"main","module":"e2m-validator","validation_type":"registration","indices":["1102420"],"registered_epoch":98317,"current_epoch":98317,"assigned":0,"executed":0,"missed":0}
{"time":"2026-05-28T11:28:34.124300851Z","level":"INFO","msg":"E2M registration check: still polling for assigned/executed to match validator count","module":"main","module":"e2m-validator","validation_type":"registration","indices":["1102420"],"registered_epoch":98317,"current_epoch":98317,"assigned":0,"executed":0,"missed":0}
{"time":"2026-05-28T11:30:34.319200254Z","level":"INFO","msg":"E2M registration check: still polling for assigned/executed to match validator count","module":"main","module":"e2m-validator","validation_type":"registration","indices":["1102420"],"registered_epoch":98317,"current_epoch":98317,"assigned":0,"executed":0,"missed":0}
{"time":"2026-05-28T11:31:49.450354647Z","level":"INFO","msg":"E2M registration validation successful - validators are attesting","module":"main","module":"e2m-validator","validation_type":"registration","indices":["1102420"],"registered_epoch":98317,"validated_epoch":98318,"epochs_waited":1}
{"time":"2026-05-28T11:31:49.450404409Z","level":"INFO","msg":"Starting consensus validation with epoch iteration logic","module":"main","module":"loki-validator","validator_indices":["1102420"],"registered_epoch":98317,"max_epoch_offset":8}
{"time":"2026-05-28T11:31:49.450456339Z","level":"INFO","msg":"E2M validation successful","test":"sanity","indices":["1102420"],"validate-type":"reactivation"}
{"time":"2026-05-28T11:31:49.461059632Z","level":"INFO","msg":"Consensus: Loki committee/aggregate lines restricted to logs at or after registration","module":"main","module":"loki-validator","registration_block_hash":"0xb8203a1901f1b9ebdd160c05e285e9d33313588d1989e3e21e859fd60adfe821","not_before_utc":"2026-05-28T11:20:00Z"}
{"time":"2026-05-28T11:32:09.48034375Z","level":"INFO","msg":"Checking epoch for duties","module":"main","module":"loki-validator","epoch_offset":0,"current_epoch":"98317","validator_indices":["1102420"]}
{"time":"2026-05-28T11:32:09.486623287Z","level":"WARN","msg":"No attesters found in duties response for one or more validators","module":"main","module":"loki-validator","epoch_offset":0,"epoch":"98317"}
{"time":"2026-05-28T11:32:19.48695763Z","level":"INFO","msg":"Checking epoch for duties","module":"main","module":"loki-validator","epoch_offset":1,"current_epoch":"98318","validator_indices":["1102420"]}
{"time":"2026-05-28T11:32:19.49306413Z","level":"INFO","msg":"Successfully found duties, building duty ID for consensus validation","module":"main","module":"loki-validator","duty_id":"COMMITTEE-300_301_302_303-e98318-s3146198","final_epoch":"98318","slot":"3146198","validator_index":"1102420"}
{"time":"2026-05-28T11:32:20.430090668Z","level":"INFO","msg":"Consensus: QBFT start logs","module":"main","module":"loki-validator","duty_id":"COMMITTEE-300_301_302_303-e98318-s3146198","qbft_start_log_count":4,"canonical_round":1,"canonical_height":3146198,"canonical_leader":"302","container":"","canonical_log_time":"2026-05-28T11:29:37.753707Z"}
{"time":"2026-05-28T11:32:20.430141616Z","level":"INFO","msg":"Consensus: leader matches QBFT round-robin (ssv-spec v1.2.2 style - no eth epoch term)","module":"main","module":"loki-validator","duty_id":"COMMITTEE-300_301_302_303-e98318-s3146198","round":1,"height":3146198,"qbft_eth_epoch":98318,"leader":302}
{"time":"2026-05-28T11:32:20.430154161Z","level":"INFO","msg":"Consensus leader validation passed","module":"main","module":"loki-validator","round":1,"leader":302}
{"time":"2026-05-28T11:32:20.729514791Z","level":"WARN","msg":"Consensus: aggregate duty in Loki but no timing metrics yet - retrying with backoff...)","module":"main","module":"loki-validator","aggregate_duty_ids":["AGGREGATOR_COMMITTEE-300_301_302_303-e98318-s3146198","AGGREGATOR-e98318-s3146198-v1102420"],"max_attempts":12,"retry_interval_seconds":20}
{"time":"2026-05-28T11:36:01.288751959Z","level":"WARN","msg":"Consensus timing skipped: no aggregate submission log lines found for aggregate duty id after retries","module":"main","module":"loki-validator","aggregate_duty_ids":["AGGREGATOR_COMMITTEE-300_301_302_303-e98318-s3146198","AGGREGATOR-e98318-s3146198-v1102420"],"last_aggregate_duty_id":"AGGREGATOR-e98318-s3146198-v1102420","attempts":12,"loki_lines":32,"aggregate_submission_logs":0}
{"time":"2026-05-28T11:36:01.288810273Z","level":"WARN","msg":"Consensus timing skipped: aggregate metrics missing after retries","module":"main","module":"loki-validator","committee_duty_id":"COMMITTEE-300_301_302_303-e98318-s3146198","aggregate_duty_ids":["AGGREGATOR_COMMITTEE-300_301_302_303-e98318-s3146198","AGGREGATOR-e98318-s3146198-v1102420"]}
{"time":"2026-05-28T11:36:01.288822683Z","level":"INFO","msg":"Consensus validation completed successfully","module":"main","module":"loki-validator","duty_id":"COMMITTEE-300_301_302_303-e98318-s3146198","final_epoch":"98318"}
{"time":"2026-05-28T11:36:01.288832977Z","level":"INFO","msg":"Consensus timing validation successful","test":"sanity","indices":["1102420"],"epoch":98317}
{"time":"2026-05-28T11:36:01.288855349Z","level":"INFO","msg":"✅ SUCCESS: Reactivation Validation Success","test":"sanity","validate_type":"reactivation","e2m_enabled":true,"e2m_success":true,"loki_success":true}
{"time":"2026-05-28T11:36:05.68440901Z","level":"INFO","msg":"📝 tx gas limit set (estimate + buffer)","test":"sanity","module":"contract","contract":"0xc07B3E9671f884FDa67E1e7D43d952E0e1369fd8","method":"removeValidator","estimated_gas":144346,"gas_buffer_pct":1000,"gas_limit":1587806}
{"time":"2026-05-28T11:36:05.698487877Z","level":"INFO","msg":"4️⃣ Removing validator","test":"sanity","module":"contract","tx_hash":"0x253d6f95ddbb5d4eaeb01c446c578553edb292d021aabc75baa83630e5608bb6"}
{"time":"2026-05-28T11:36:05.707486242Z","level":"INFO","msg":"Waiting for transaction receipt, retrying...","test":"sanity","module":"contract","attempt":1,"sleep":10,"tx_hash":"0x253d6f95ddbb5d4eaeb01c446c578553edb292d021aabc75baa83630e5608bb6","tx_state":"pending"}
{"time":"2026-05-28T11:36:15.721673726Z","level":"INFO","msg":"Waiting for transaction receipt, retrying...","test":"sanity","module":"contract","attempt":2,"sleep":20,"tx_hash":"0x253d6f95ddbb5d4eaeb01c446c578553edb292d021aabc75baa83630e5608bb6","tx_state":"pending"}
{"time":"2026-05-28T11:36:35.724681954Z","level":"INFO","msg":"Transaction receipt received","test":"sanity","module":"contract","tx_hash":"0x253d6f95ddbb5d4eaeb01c446c578553edb292d021aabc75baa83630e5608bb6"}
{"time":"2026-05-28T11:36:35.724732492Z","level":"INFO","msg":"📜 CONTRACT: Contract Removal Successful","test":"sanity","txHash":"0x253d6f95ddbb5d4eaeb01c446c578553edb292d021aabc75baa83630e5608bb6","block_hash":"0x772fef579af4996ba51edaaf1e9b841b4a6d374a5dc45174ee072a9597f4c078"}
{"time":"2026-05-28T11:36:35.73677403Z","level":"INFO","msg":"waiting for block to be found","module":"main","module":"e2m-validator","module":"e2m"}
{"time":"2026-05-28T11:36:35.787524786Z","level":"INFO","msg":"Loki: no matching logs yet, retrying until data appears or max attempts is reached","module":"main","module":"loki-validator","attempts":1,"retry_delay":"20s","start_unix":1779957395,"end_unix":1779968195}
{"time":"2026-05-28T11:36:55.747493416Z","level":"INFO","msg":"waiting for block to be found","module":"main","module":"e2m-validator","module":"e2m"}
{"time":"2026-05-28T11:37:15.758493337Z","level":"INFO","msg":"waiting for block to be found","module":"main","module":"e2m-validator","module":"e2m"}
{"time":"2026-05-28T11:37:35.763976077Z","level":"INFO","msg":"Removal tx epoch: polling E2M until attestations.Assigned is 0 for these validators (on-chain removed, indexer may lag)","module":"main","module":"e2m-validator","validation_type":"removal","epoch":98319,"indices":"1102420","poll_interval_seconds":15,"fail_if_current_epoch_gte":98321,"fail_after_epochs_past_removal_tx":2}
{"time":"2026-05-28T11:37:50.80503557Z","level":"INFO","msg":"E2M removal check: waiting for epoch to reach removal tx before verifying duties cleared","module":"main","module":"e2m-validator","validation_type":"removal","epoch":98318,"indices":["1102420"],"removal_tx_epoch":98319}
{"time":"2026-05-28T11:38:15.927140731Z","level":"INFO","msg":"Validator event validation successful","module":"main","module":"loki-validator","validated_validators":1,"event":"ValidatorRemoved"}
{"time":"2026-05-28T11:38:15.927182738Z","level":"INFO","msg":"Loki: SSV node log validation successful","test":"sanity","indices":["1102420"],"validators":1,"validate-type":"removal"}
{"time":"2026-05-28T11:38:15.927190153Z","level":"INFO","msg":"E2M validation still in progress: waiting to confirm whether validators are no longer active on-chain duties (polling each 15s, next log may take several minutes)","test":"sanity","indices":["1102420"],"validators":1,"validate-type":"removal"}
{"time":"2026-05-28T11:39:05.929922278Z","level":"INFO","msg":"E2M removal check: validators still have duties in E2M, waiting for 'assigned' to drop to zero","module":"main","module":"e2m-validator","validation_type":"removal","epoch":98319,"indices":["1102420"],"assigned":1,"executed":1,"missed":0}
{"time":"2026-05-28T11:41:06.183127893Z","level":"INFO","msg":"E2M removal check: same epoch, still polling until 'assigned' is zero (validators should stop, not attest)","module":"main","module":"e2m-validator","validation_type":"removal","epoch":98319,"indices":["1102420"],"assigned":1,"executed":1,"missed":0}
{"time":"2026-05-28T11:43:06.38227672Z","level":"INFO","msg":"E2M removal check: same epoch, still polling until 'assigned' is zero (validators should stop, not attest)","module":"main","module":"e2m-validator","validation_type":"removal","epoch":98319,"indices":["1102420"],"assigned":1,"executed":1,"missed":0}
{"time":"2026-05-28T11:44:51.560688392Z","level":"INFO","msg":"E2M removal validation successful - validators stopped attesting","module":"main","module":"e2m-validator","validation_type":"removal","indices":["1102420"],"removed_epoch":98319,"validated_epoch":98320,"epochs_waited":1}
{"time":"2026-05-28T11:44:51.560778667Z","level":"INFO","msg":"E2M validation successful","test":"sanity","indices":["1102420"],"validate-type":"removal"}
{"time":"2026-05-28T11:44:51.560802153Z","level":"INFO","msg":"✅ SUCCESS: Removal Validation Success","test":"sanity","validate_type":"removal","e2m_enabled":true,"e2m_success":true,"loki_success":true}
{"time":"2026-05-28T11:44:51.568746238Z","level":"INFO","msg":"✅ SUCCESS: Sanity Test Suite Completed Successfully","module":"main","register":{"Contract":true,"E2M":true,"Loki":true},"liquidate":{"Contract":true,"E2M":true,"Loki":true},"reactivate":{"Contract":true,"E2M":true,"Loki":true},"remove":{"Contract":true,"E2M":true,"Loki":true}}
{"time":"2026-05-28T11:44:51.568770426Z","level":"INFO","msg":"🔑 KEY STEP: Starting Bulk Test Suite","module":"main"}
{"time":"2026-05-28T11:44:51.568782896Z","level":"INFO","msg":"Bulk: config values","test":"bulk","cluster_owner":"0x91E32eFb8139cd88caE0Df30d2Bf471294c6ed27","account_public_key":"0x91E32eFb8139cd88caE0Df30d2Bf471294c6ed27","operator_ids":[300,301,302,303]}
{"time":"2026-05-28T11:44:51.610012232Z","level":"INFO","msg":"Available slots","test":"bulk","node":300,"slots":3000}
{"time":"2026-05-28T11:44:51.620247462Z","level":"INFO","msg":"Available slots","test":"bulk","node":301,"slots":1010}
{"time":"2026-05-28T11:44:51.627053353Z","level":"INFO","msg":"Available slots","test":"bulk","node":302,"slots":3000}
{"time":"2026-05-28T11:44:51.636965795Z","level":"INFO","msg":"Available slots","test":"bulk","node":303,"slots":1324}
{"time":"2026-05-28T11:46:21.419036492Z","level":"INFO","msg":"Extracted keyshares path for bulk keyshare","test":"bulk","module":"keys","path":"/app/shared/data/keyshares/keyshares-1779968781.json"}
{"time":"2026-05-28T11:46:25.668786045Z","level":"INFO","msg":"Cluster asset type before write","test":"bulk","asset_type":1,"asset_err":null,"asset_label":"ETH"}
{"time":"2026-05-28T11:46:34.669157307Z","level":"INFO","msg":"📝 tx gas limit set (estimate + buffer)","test":"bulk","module":"contract","contract":"0xc07B3E9671f884FDa67E1e7D43d952E0e1369fd8","method":"bulkRegisterValidator","estimated_gas":524790,"gas_buffer_pct":1000,"gas_limit":5772690}
{"time":"2026-05-28T11:46:34.687111047Z","level":"INFO","msg":"1️⃣ Bulk Registering validators","test":"bulk","module":"contract","tx_hash":"0x021ddcc6fbac1d68cd2bde9d8aba06d0c897ec5bc54e5e79550ba3b82d350b14"}
{"time":"2026-05-28T11:46:34.691886806Z","level":"INFO","msg":"Bulk registration transaction sent","test":"bulk","txHash":"0x021ddcc6fbac1d68cd2bde9d8aba06d0c897ec5bc54e5e79550ba3b82d350b14"}
{"time":"2026-05-28T11:46:34.699865472Z","level":"INFO","msg":"Waiting for transaction receipt, retrying...","test":"bulk","module":"contract","attempt":1,"sleep":10,"tx_hash":"0x021ddcc6fbac1d68cd2bde9d8aba06d0c897ec5bc54e5e79550ba3b82d350b14","tx_state":"pending"}
{"time":"2026-05-28T11:46:44.716290261Z","level":"INFO","msg":"Waiting for transaction receipt, retrying...","test":"bulk","module":"contract","attempt":2,"sleep":20,"tx_hash":"0x021ddcc6fbac1d68cd2bde9d8aba06d0c897ec5bc54e5e79550ba3b82d350b14","tx_state":"pending"}
{"time":"2026-05-28T11:47:04.727415179Z","level":"INFO","msg":"Transaction receipt received","test":"bulk","module":"contract","tx_hash":"0x021ddcc6fbac1d68cd2bde9d8aba06d0c897ec5bc54e5e79550ba3b82d350b14"}
{"time":"2026-05-28T11:47:04.727520367Z","level":"INFO","msg":"📜 CONTRACT: Bulk Registration Successful","test":"bulk","blockHash":"0xe6f1e8b3633973253993c9176a8a7f6cf9988384fff0cb3539b8cc7fdb811d65","Validators Amount":5}
{"time":"2026-05-28T11:47:04.736052581Z","level":"INFO","msg":"Exporter: validator not indexed yet (or index=0), retrying until non-zero index appears or max attempts is reached","test":"bulk","module":"helpers","pubkey":"0x83142d846a6b78759863175ff9ad7890bd47a1a534b63f3949080484082164adde97a829291e6dc0c5099d82657bf754","delay_seconds":15,"max_attempts":20}
{"time":"2026-05-28T11:48:34.791148489Z","level":"INFO","msg":"Successfully retrieved validator index from exporter","test":"bulk","module":"helpers","pubkey":"0x83142d846a6b78759863175ff9ad7890bd47a1a534b63f3949080484082164adde97a829291e6dc0c5099d82657bf754"}
{"time":"2026-05-28T11:48:34.793904543Z","level":"INFO","msg":"Successfully retrieved validator index from exporter","test":"bulk","module":"helpers","pubkey":"0x836ba57493b4c26d495a39ddc1bf42dce1e234fab6a9a00b45ca00dfe6cd7190d37536220c4c12469f8fe557d8564d60"}
{"time":"2026-05-28T11:48:34.796561312Z","level":"INFO","msg":"Successfully retrieved validator index from exporter","test":"bulk","module":"helpers","pubkey":"0x86d6aa42d120173270727af286965c371f919f423558997f914b30b20bba45b041561650b531d386ed85f65828e0bde1"}
{"time":"2026-05-28T11:48:34.798790494Z","level":"INFO","msg":"Successfully retrieved validator index from exporter","test":"bulk","module":"helpers","pubkey":"0x874e9b0b577bb6c9dbd7bad54e19306422288cc9d9cced8522fbb3990a55c0c82586a9b0c8eca964aa38306179b42856"}
{"time":"2026-05-28T11:48:34.804071563Z","level":"INFO","msg":"Successfully retrieved validator index from exporter","test":"bulk","module":"helpers","pubkey":"0xa3a4b31b4ab322e432cec4719f3795d46e707f82f3e4a0930550edf09643712e61e947eea441ee037bb947868e9b0898"}
{"time":"2026-05-28T11:48:34.811539909Z","level":"INFO","msg":"E2M registration: polling until assigned/executed match validator count","module":"main","module":"e2m-validator","validation_type":"registration","registered_epoch":98321,"indices":"1102420,1104103,1092007,1092008,1104098","poll_interval_seconds":15,"fail_if_current_epoch_gt":98325}
{"time":"2026-05-28T11:48:35.003001423Z","level":"INFO","msg":"Validator event validation successful","module":"main","module":"loki-validator","validated_validators":5,"event":"ValidatorAdded"}
{"time":"2026-05-28T11:48:35.003069025Z","level":"INFO","msg":"Loki: SSV node log validation successful","test":"bulk","indices":["1102420","1104103","1092007","1092008","1104098"],"validators":5,"validate-type":"registration"}
{"time":"2026-05-28T11:50:35.047553959Z","level":"INFO","msg":"E2M registration check: still polling for assigned/executed to match validator count","module":"main","module":"e2m-validator","validation_type":"registration","indices":["1102420","1104103","1092007","1092008","1104098"],"registered_epoch":98321,"current_epoch":98320,"assigned":0,"executed":0,"missed":0}
{"time":"2026-05-28T11:52:35.275487089Z","level":"INFO","msg":"E2M registration check: still polling for assigned/executed to match validator count","module":"main","module":"e2m-validator","validation_type":"registration","indices":["1102420","1104103","1092007","1092008","1104098"],"registered_epoch":98321,"current_epoch":98321,"assigned":0,"executed":0,"missed":0}
{"time":"2026-05-28T11:54:35.504436193Z","level":"INFO","msg":"E2M registration check: still polling for assigned/executed to match validator count","module":"main","module":"e2m-validator","validation_type":"registration","indices":["1102420","1104103","1092007","1092008","1104098"],"registered_epoch":98321,"current_epoch":98321,"assigned":0,"executed":0,"missed":0}
{"time":"2026-05-28T11:56:35.705645012Z","level":"INFO","msg":"E2M registration check: still polling for assigned/executed to match validator count","module":"main","module":"e2m-validator","validation_type":"registration","indices":["1102420","1104103","1092007","1092008","1104098"],"registered_epoch":98321,"current_epoch":98321,"assigned":0,"executed":0,"missed":0}
{"time":"2026-05-28T11:57:20.772199928Z","level":"INFO","msg":"E2M registration validation successful - validators are attesting","module":"main","module":"e2m-validator","validation_type":"registration","indices":["1102420","1104103","1092007","1092008","1104098"],"registered_epoch":98321,"validated_epoch":98322,"epochs_waited":1}
{"time":"2026-05-28T11:57:20.772252682Z","level":"INFO","msg":"E2M validation successful","test":"bulk","indices":["1102420","1104103","1092007","1092008","1104098"],"validate-type":"registration"}
{"time":"2026-05-28T11:57:20.772305282Z","level":"INFO","msg":"Starting consensus validation with epoch iteration logic","module":"main","module":"loki-validator","validator_indices":["1102420","1104103","1092007","1092008","1104098"],"registered_epoch":98321,"max_epoch_offset":8}
{"time":"2026-05-28T11:57:20.781324574Z","level":"INFO","msg":"Consensus: Loki committee/aggregate lines restricted to logs at or after registration","module":"main","module":"loki-validator","registration_block_hash":"0xe6f1e8b3633973253993c9176a8a7f6cf9988384fff0cb3539b8cc7fdb811d65","not_before_utc":"2026-05-28T11:46:48Z"}
{"time":"2026-05-28T11:57:40.796216821Z","level":"INFO","msg":"Checking epoch for duties","module":"main","module":"loki-validator","epoch_offset":0,"current_epoch":"98321","validator_indices":["1102420","1104103","1092007","1092008","1104098"]}
{"time":"2026-05-28T11:57:40.813774988Z","level":"WARN","msg":"No attesters found in duties response for one or more validators","module":"main","module":"loki-validator","epoch_offset":0,"epoch":"98321"}
{"time":"2026-05-28T11:57:50.814856396Z","level":"INFO","msg":"Checking epoch for duties","module":"main","module":"loki-validator","epoch_offset":1,"current_epoch":"98322","validator_indices":["1102420","1104103","1092007","1092008","1104098"]}
{"time":"2026-05-28T11:57:50.819777468Z","level":"INFO","msg":"Successfully found duties, building duty ID for consensus validation","module":"main","module":"loki-validator","duty_id":"COMMITTEE-300_301_302_303-e98322-s3146311","final_epoch":"98322","slot":"3146311","validator_index":"1102420"}
{"time":"2026-05-28T11:57:50.940973686Z","level":"INFO","msg":"Consensus: QBFT start logs","module":"main","module":"loki-validator","duty_id":"COMMITTEE-300_301_302_303-e98322-s3146311","qbft_start_log_count":4,"canonical_round":1,"canonical_height":3146311,"canonical_leader":"303","container":"","canonical_log_time":"2026-05-28T11:52:16.100729Z"}
{"time":"2026-05-28T11:57:50.941048207Z","level":"INFO","msg":"Consensus: leader matches QBFT round-robin (ssv-spec v1.2.2 style - no eth epoch term)","module":"main","module":"loki-validator","duty_id":"COMMITTEE-300_301_302_303-e98322-s3146311","round":1,"height":3146311,"qbft_eth_epoch":98322,"leader":303}
{"time":"2026-05-28T11:57:50.941065328Z","level":"INFO","msg":"Consensus leader validation passed","module":"main","module":"loki-validator","round":1,"leader":303}
{"time":"2026-05-28T11:57:51.67892108Z","level":"WARN","msg":"Consensus: aggregate duty in Loki but no timing metrics yet - retrying with backoff...)","module":"main","module":"loki-validator","aggregate_duty_ids":["AGGREGATOR_COMMITTEE-300_301_302_303-e98322-s3146311","AGGREGATOR-e98322-s3146311-v1102420","AGGREGATOR-e98322-s3146311-v1104103","AGGREGATOR-e98322-s3146311-v1092007","AGGREGATOR-e98322-s3146311-v1092008","AGGREGATOR-e98322-s3146311-v1104098"],"max_attempts":12,"retry_interval_seconds":20}
{"time":"2026-05-28T12:01:33.264655892Z","level":"WARN","msg":"Consensus timing skipped: no aggregate submission log lines found for aggregate duty id after retries","module":"main","module":"loki-validator","aggregate_duty_ids":["AGGREGATOR_COMMITTEE-300_301_302_303-e98322-s3146311","AGGREGATOR-e98322-s3146311-v1102420","AGGREGATOR-e98322-s3146311-v1104103","AGGREGATOR-e98322-s3146311-v1092007","AGGREGATOR-e98322-s3146311-v1092008","AGGREGATOR-e98322-s3146311-v1104098"],"last_aggregate_duty_id":"AGGREGATOR-e98322-s3146311-v1104098","attempts":12,"loki_lines":0,"aggregate_submission_logs":0}
{"time":"2026-05-28T12:01:33.264756678Z","level":"WARN","msg":"Consensus timing skipped: aggregate metrics missing after retries","module":"main","module":"loki-validator","committee_duty_id":"COMMITTEE-300_301_302_303-e98322-s3146311","aggregate_duty_ids":["AGGREGATOR_COMMITTEE-300_301_302_303-e98322-s3146311","AGGREGATOR-e98322-s3146311-v1102420","AGGREGATOR-e98322-s3146311-v1104103","AGGREGATOR-e98322-s3146311-v1092007","AGGREGATOR-e98322-s3146311-v1092008","AGGREGATOR-e98322-s3146311-v1104098"]}
{"time":"2026-05-28T12:01:33.264775138Z","level":"INFO","msg":"Consensus validation completed successfully","module":"main","module":"loki-validator","duty_id":"COMMITTEE-300_301_302_303-e98322-s3146311","final_epoch":"98322"}
{"time":"2026-05-28T12:01:33.264811712Z","level":"INFO","msg":"Consensus timing validation successful","test":"bulk","indices":["1102420","1104103","1092007","1092008","1104098"],"epoch":98321}
{"time":"2026-05-28T12:01:33.264838763Z","level":"INFO","msg":"✅ SUCCESS: Registration Validation Success","test":"bulk","validate_type":"registration","e2m_enabled":true,"e2m_success":true,"loki_success":true}
{"time":"2026-05-28T12:01:33.26485116Z","level":"INFO","msg":"Bulk: registration validation summary","test":"bulk","bulk_amount":5,"registered_pubkeys":5,"indices_for_e2m":5,"e2m_success":true,"loki_success":true}
{"time":"2026-05-28T12:01:37.957567426Z","level":"WARN","msg":"failed to report run progress","test":"bulk","error":"progress update failed: no active usage tracking found with ID 40f43b150002f6b599c46540a0d18680"}
{"time":"2026-05-28T12:01:37.966548935Z","level":"INFO","msg":"📝 tx gas limit set (estimate + buffer)","test":"bulk","module":"contract","contract":"0xc07B3E9671f884FDa67E1e7D43d952E0e1369fd8","method":"liquidate","estimated_gas":148924,"gas_buffer_pct":1000,"gas_limit":1638164}
{"time":"2026-05-28T12:01:37.980284838Z","level":"INFO","msg":"2️⃣ Liquidating cluster","test":"bulk","module":"contract","tx_hash":"0xc53e84a881e59b30adaba8583bd3164b9b5f6eb5b92e8153022a4afe7bc625be"}
{"time":"2026-05-28T12:01:37.981339304Z","level":"WARN","msg":"failed to report run progress","test":"bulk","error":"progress update failed: no active usage tracking found with ID 40f43b150002f6b599c46540a0d18680"}
{"time":"2026-05-28T12:01:37.986780516Z","level":"INFO","msg":"Waiting for transaction receipt, retrying...","test":"bulk","module":"contract","attempt":1,"sleep":10,"tx_hash":"0xc53e84a881e59b30adaba8583bd3164b9b5f6eb5b92e8153022a4afe7bc625be","tx_state":"pending"}
{"time":"2026-05-28T12:01:47.996867325Z","level":"INFO","msg":"Waiting for transaction receipt, retrying...","test":"bulk","module":"contract","attempt":2,"sleep":20,"tx_hash":"0xc53e84a881e59b30adaba8583bd3164b9b5f6eb5b92e8153022a4afe7bc625be","tx_state":"pending"}
{"time":"2026-05-28T12:02:08.017194625Z","level":"INFO","msg":"Transaction receipt received","test":"bulk","module":"contract","tx_hash":"0xc53e84a881e59b30adaba8583bd3164b9b5f6eb5b92e8153022a4afe7bc625be"}
{"time":"2026-05-28T12:02:08.017241135Z","level":"INFO","msg":"📜 CONTRACT: Bulk Cluster Liquidation Successful","test":"bulk","txHash":"0xc53e84a881e59b30adaba8583bd3164b9b5f6eb5b92e8153022a4afe7bc625be","block_hash":"0xc77859f92ae8d1eedbb2effbdc39befd50628f5974d64c80eac318772319f7e0"}
{"time":"2026-05-28T12:02:08.024772601Z","level":"INFO","msg":"waiting for block to be found","module":"main","module":"e2m-validator","module":"e2m"}
{"time":"2026-05-28T12:02:08.084938153Z","level":"INFO","msg":"Loki: no matching logs yet, retrying until data appears or max attempts is reached","module":"main","module":"loki-validator","attempts":1,"retry_delay":"20s","start_unix":1779958928,"end_unix":1779969728}
{"time":"2026-05-28T12:02:28.038977722Z","level":"INFO","msg":"waiting for block to be found","module":"main","module":"e2m-validator","module":"e2m"}
{"time":"2026-05-28T12:02:48.093881514Z","level":"INFO","msg":"waiting for block to be found","module":"main","module":"e2m-validator","module":"e2m"}
{"time":"2026-05-28T12:03:08.107299771Z","level":"INFO","msg":"waiting for block to be found","module":"main","module":"e2m-validator","module":"e2m"}
{"time":"2026-05-28T12:03:28.131504638Z","level":"INFO","msg":"Liquidation tx epoch: polling E2M until validators are all missed or have zero assigned duties","module":"main","module":"e2m-validator","validation_type":"liquidation","epoch":98323,"indices":"1102420,1104103,1092007,1092008,1104098","poll_interval_seconds":15,"fail_if_current_epoch_gte":98328,"fail_after_epochs_past_liquidation_tx":5}
{"time":"2026-05-28T12:03:43.158389793Z","level":"INFO","msg":"Validator still active after liquidation wait","module":"main","module":"e2m-validator","epoch":98323,"indices":["1102420","1104103","1092007","1092008","1104098"],"assigned":5,"executed":5,"missed":0}
{"time":"2026-05-28T12:04:08.275785778Z","level":"INFO","msg":"Event validation successful","module":"main","module":"loki-validator","valid_entries":4,"event":"ClusterLiquidated"}
{"time":"2026-05-28T12:04:08.275834239Z","level":"INFO","msg":"Loki: SSV node log validation successful","test":"bulk","indices":["1102420","1104103","1092007","1092008","1104098"],"validators":5,"validate-type":"liquidation"}
{"time":"2026-05-28T12:04:08.275843903Z","level":"INFO","msg":"E2M validation still in progress: waiting to confirm whether validators are no longer active on-chain duties (polling each 15s, next log may take several minutes)","test":"bulk","indices":["1102420","1104103","1092007","1092008","1104098"],"validators":5,"validate-type":"liquidation"}
{"time":"2026-05-28T12:05:43.377945863Z","level":"INFO","msg":"Waiting for liquidation criteria (all missed or zero assigned; same epoch, still polling E2M)","module":"main","module":"e2m-validator","epoch":98323,"indices":["1102420","1104103","1092007","1092008","1104098"],"liquidated_epoch":98323,"assigned":5,"executed":5,"missed":0}
{"time":"2026-05-28T12:07:43.613834676Z","level":"INFO","msg":"Waiting for liquidation criteria (all missed or zero assigned; same epoch, still polling E2M)","module":"main","module":"e2m-validator","epoch":98323,"indices":["1102420","1104103","1092007","1092008","1104098"],"liquidated_epoch":98323,"assigned":5,"executed":5,"missed":0}
{"time":"2026-05-28T12:09:43.816262491Z","level":"INFO","msg":"Waiting for liquidation criteria (all missed or zero assigned; same epoch, still polling E2M)","module":"main","module":"e2m-validator","epoch":98323,"indices":["1102420","1104103","1092007","1092008","1104098"],"liquidated_epoch":98323,"assigned":5,"executed":5,"missed":0}
{"time":"2026-05-28T12:10:13.880046541Z","level":"INFO","msg":"E2M liquidation validation successful - validators are liquidated","module":"main","module":"e2m-validator","validation_type":"liquidation","indices":["1102420","1104103","1092007","1092008","1104098"],"liquidated_epoch":98323,"validated_epoch":98324,"epochs_waited":1,"assigned":0,"missed":0}
{"time":"2026-05-28T12:10:13.880107535Z","level":"INFO","msg":"E2M validation successful","test":"bulk","indices":["1102420","1104103","1092007","1092008","1104098"],"validate-type":"liquidation"}
{"time":"2026-05-28T12:10:13.880136147Z","level":"INFO","msg":"✅ SUCCESS: Liquidation Validation Success","test":"bulk","validate_type":"liquidation","e2m_enabled":true,"e2m_success":true,"loki_success":true}
{"time":"2026-05-28T12:10:18.487523267Z","level":"WARN","msg":"failed to report run progress","test":"bulk","error":"progress update failed: no active usage tracking found with ID 40f43b150002f6b599c46540a0d18680"}
{"time":"2026-05-28T12:10:18.49841648Z","level":"INFO","msg":"📝 tx gas limit set (estimate + buffer)","test":"bulk","module":"contract","contract":"0xc07B3E9671f884FDa67E1e7D43d952E0e1369fd8","method":"reactivate","estimated_gas":141639,"gas_buffer_pct":1000,"gas_limit":1558029}
{"time":"2026-05-28T12:10:18.511366393Z","level":"INFO","msg":"3️⃣ Reactivating cluster","test":"bulk","module":"contract","tx_hash":"0x4868328b4fe4f26d7ebf421af3cbbcc46fa14c002498a7e9f54fb75256b31826"}
{"time":"2026-05-28T12:10:18.513237431Z","level":"WARN","msg":"failed to report run progress","test":"bulk","error":"progress update failed: no active usage tracking found with ID 40f43b150002f6b599c46540a0d18680"}
{"time":"2026-05-28T12:10:18.518728392Z","level":"INFO","msg":"Waiting for transaction receipt, retrying...","test":"bulk","module":"contract","attempt":1,"sleep":10,"tx_hash":"0x4868328b4fe4f26d7ebf421af3cbbcc46fa14c002498a7e9f54fb75256b31826","tx_state":"pending"}
{"time":"2026-05-28T12:10:28.531557137Z","level":"INFO","msg":"Waiting for transaction receipt, retrying...","test":"bulk","module":"contract","attempt":2,"sleep":20,"tx_hash":"0x4868328b4fe4f26d7ebf421af3cbbcc46fa14c002498a7e9f54fb75256b31826","tx_state":"pending"}
{"time":"2026-05-28T12:10:48.536021055Z","level":"INFO","msg":"Transaction receipt received","test":"bulk","module":"contract","tx_hash":"0x4868328b4fe4f26d7ebf421af3cbbcc46fa14c002498a7e9f54fb75256b31826"}
{"time":"2026-05-28T12:10:48.536097533Z","level":"INFO","msg":"📜 CONTRACT: Bulk Cluster Reactivation Successful","test":"bulk","txHash":"0x4868328b4fe4f26d7ebf421af3cbbcc46fa14c002498a7e9f54fb75256b31826","block_hash":"0x74d6ce0fe74d2ad806915beaaf60a5b3d4cacbbadc3ea99bceaa8f04ba5086b6"}
{"time":"2026-05-28T12:10:48.536141168Z","level":"INFO","msg":"Validating reactivation - checking that validators resume attesting","module":"main","module":"e2m-validator","indices":["1102420","1104103","1092007","1092008","1104098"],"block_hash":"0x74d6ce0fe74d2ad806915beaaf60a5b3d4cacbbadc3ea99bceaa8f04ba5086b6"}
{"time":"2026-05-28T12:10:48.542242331Z","level":"INFO","msg":"waiting for block to be found","module":"main","module":"e2m-validator","module":"e2m"}
{"time":"2026-05-28T12:10:48.725812218Z","level":"INFO","msg":"Loki: no matching logs yet, retrying until data appears or max attempts is reached","module":"main","module":"loki-validator","attempts":1,"retry_delay":"20s","start_unix":1779959448,"end_unix":1779970248}
{"time":"2026-05-28T12:11:08.55571312Z","level":"INFO","msg":"E2M registration: polling until assigned/executed match validator count","module":"main","module":"e2m-validator","validation_type":"registration","registered_epoch":98325,"indices":"1102420,1104103,1092007,1092008,1104098","poll_interval_seconds":15,"fail_if_current_epoch_gt":98329}
{"time":"2026-05-28T12:12:28.847992468Z","level":"INFO","msg":"Event validation successful","module":"main","module":"loki-validator","valid_entries":4,"event":"ClusterReactivated"}
{"time":"2026-05-28T12:12:28.848048921Z","level":"INFO","msg":"Loki: SSV node log validation successful","test":"bulk","indices":["1102420","1104103","1092007","1092008","1104098"],"validators":5,"validate-type":"reactivation"}
{"time":"2026-05-28T12:13:08.778564934Z","level":"INFO","msg":"E2M registration check: still polling for assigned/executed to match validator count","module":"main","module":"e2m-validator","validation_type":"registration","indices":["1102420","1104103","1092007","1092008","1104098"],"registered_epoch":98325,"current_epoch":98324,"assigned":0,"executed":0,"missed":0}
{"time":"2026-05-28T12:15:08.976551991Z","level":"INFO","msg":"E2M registration check: still polling for assigned/executed to match validator count","module":"main","module":"e2m-validator","validation_type":"registration","indices":["1102420","1104103","1092007","1092008","1104098"],"registered_epoch":98325,"current_epoch":98324,"assigned":0,"executed":0,"missed":0}
{"time":"2026-05-28T12:17:09.219908167Z","level":"INFO","msg":"E2M registration check: still polling for assigned/executed to match validator count","module":"main","module":"e2m-validator","validation_type":"registration","indices":["1102420","1104103","1092007","1092008","1104098"],"registered_epoch":98325,"current_epoch":98324,"assigned":0,"executed":0,"missed":0}
{"time":"2026-05-28T12:19:09.448998502Z","level":"INFO","msg":"E2M registration check: still polling for assigned/executed to match validator count","module":"main","module":"e2m-validator","validation_type":"registration","indices":["1102420","1104103","1092007","1092008","1104098"],"registered_epoch":98325,"current_epoch":98325,"assigned":0,"executed":0,"missed":0}
{"time":"2026-05-28T12:21:09.651557542Z","level":"INFO","msg":"E2M registration check: still polling for assigned/executed to match validator count","module":"main","module":"e2m-validator","validation_type":"registration","indices":["1102420","1104103","1092007","1092008","1104098"],"registered_epoch":98325,"current_epoch":98325,"assigned":0,"executed":0,"missed":0}
{"time":"2026-05-28T12:23:09.876299991Z","level":"INFO","msg":"E2M registration check: still polling for assigned/executed to match validator count","module":"main","module":"e2m-validator","validation_type":"registration","indices":["1102420","1104103","1092007","1092008","1104098"],"registered_epoch":98325,"current_epoch":98326,"assigned":5,"executed":5,"missed":0}
{"time":"2026-05-28T12:23:09.876398942Z","level":"INFO","msg":"E2M registration validation successful - validators are attesting","module":"main","module":"e2m-validator","validation_type":"registration","indices":["1102420","1104103","1092007","1092008","1104098"],"registered_epoch":98325,"validated_epoch":98326,"epochs_waited":1}
{"time":"2026-05-28T12:23:09.876415987Z","level":"INFO","msg":"E2M validation successful","test":"bulk","indices":["1102420","1104103","1092007","1092008","1104098"],"validate-type":"reactivation"}
{"time":"2026-05-28T12:23:09.876475111Z","level":"INFO","msg":"Starting consensus validation with epoch iteration logic","module":"main","module":"loki-validator","validator_indices":["1102420","1104103","1092007","1092008","1104098"],"registered_epoch":98325,"max_epoch_offset":8}
{"time":"2026-05-28T12:23:09.885820472Z","level":"INFO","msg":"Consensus: Loki committee/aggregate lines restricted to logs at or after registration","module":"main","module":"loki-validator","registration_block_hash":"0x74d6ce0fe74d2ad806915beaaf60a5b3d4cacbbadc3ea99bceaa8f04ba5086b6","not_before_utc":"2026-05-28T12:10:36Z"}
{"time":"2026-05-28T12:23:29.900737674Z","level":"INFO","msg":"Checking epoch for duties","module":"main","module":"loki-validator","epoch_offset":0,"current_epoch":"98325","validator_indices":["1102420","1104103","1092007","1092008","1104098"]}
{"time":"2026-05-28T12:23:29.927484662Z","level":"WARN","msg":"No attesters found in duties response for one or more validators","module":"main","module":"loki-validator","epoch_offset":0,"epoch":"98325"}
{"time":"2026-05-28T12:23:39.936622712Z","level":"INFO","msg":"Checking epoch for duties","module":"main","module":"loki-validator","epoch_offset":1,"current_epoch":"98326","validator_indices":["1102420","1104103","1092007","1092008","1104098"]}
{"time":"2026-05-28T12:23:39.94851603Z","level":"INFO","msg":"Successfully found duties, building duty ID for consensus validation","module":"main","module":"loki-validator","duty_id":"COMMITTEE-300_301_302_303-e98326-s3146462","final_epoch":"98326","slot":"3146462","validator_index":"1102420"}
{"time":"2026-05-28T12:23:40.050935434Z","level":"INFO","msg":"Consensus: QBFT start logs","module":"main","module":"loki-validator","duty_id":"COMMITTEE-300_301_302_303-e98326-s3146462","qbft_start_log_count":4,"canonical_round":1,"canonical_height":3146462,"canonical_leader":"302","container":"","canonical_log_time":"2026-05-28T12:22:25.401569Z"}
{"time":"2026-05-28T12:23:40.050978857Z","level":"INFO","msg":"Consensus: leader matches QBFT round-robin (ssv-spec v1.2.2 style - no eth epoch term)","module":"main","module":"loki-validator","duty_id":"COMMITTEE-300_301_302_303-e98326-s3146462","round":1,"height":3146462,"qbft_eth_epoch":98326,"leader":302}
{"time":"2026-05-28T12:23:40.050990922Z","level":"INFO","msg":"Consensus leader validation passed","module":"main","module":"loki-validator","round":1,"leader":302}
{"time":"2026-05-28T12:23:40.629615314Z","level":"WARN","msg":"Consensus: aggregate duty in Loki but no timing metrics yet - retrying with backoff...)","module":"main","module":"loki-validator","aggregate_duty_ids":["AGGREGATOR_COMMITTEE-300_301_302_303-e98326-s3146462","AGGREGATOR-e98326-s3146462-v1102420","AGGREGATOR-e98326-s3146462-v1104103","AGGREGATOR-e98326-s3146462-v1092007","AGGREGATOR-e98326-s3146462-v1092008","AGGREGATOR-e98326-s3146462-v1104098"],"max_attempts":12,"retry_interval_seconds":20}
{"time":"2026-05-28T12:27:21.926470783Z","level":"WARN","msg":"Consensus timing skipped: no aggregate submission log lines found for aggregate duty id after retries","module":"main","module":"loki-validator","aggregate_duty_ids":["AGGREGATOR_COMMITTEE-300_301_302_303-e98326-s3146462","AGGREGATOR-e98326-s3146462-v1102420","AGGREGATOR-e98326-s3146462-v1104103","AGGREGATOR-e98326-s3146462-v1092007","AGGREGATOR-e98326-s3146462-v1092008","AGGREGATOR-e98326-s3146462-v1104098"],"last_aggregate_duty_id":"AGGREGATOR-e98326-s3146462-v1104098","attempts":12,"loki_lines":0,"aggregate_submission_logs":0}
{"time":"2026-05-28T12:27:21.92656138Z","level":"WARN","msg":"Consensus timing skipped: aggregate metrics missing after retries","module":"main","module":"loki-validator","committee_duty_id":"COMMITTEE-300_301_302_303-e98326-s3146462","aggregate_duty_ids":["AGGREGATOR_COMMITTEE-300_301_302_303-e98326-s3146462","AGGREGATOR-e98326-s3146462-v1102420","AGGREGATOR-e98326-s3146462-v1104103","AGGREGATOR-e98326-s3146462-v1092007","AGGREGATOR-e98326-s3146462-v1092008","AGGREGATOR-e98326-s3146462-v1104098"]}
{"time":"2026-05-28T12:27:21.9265765Z","level":"INFO","msg":"Consensus validation completed successfully","module":"main","module":"loki-validator","duty_id":"COMMITTEE-300_301_302_303-e98326-s3146462","final_epoch":"98326"}
{"time":"2026-05-28T12:27:21.926592825Z","level":"INFO","msg":"Consensus timing validation successful","test":"bulk","indices":["1102420","1104103","1092007","1092008","1104098"],"epoch":98325}
{"time":"2026-05-28T12:27:21.926620648Z","level":"INFO","msg":"✅ SUCCESS: Reactivation Validation Success","test":"bulk","validate_type":"reactivation","e2m_enabled":true,"e2m_success":true,"loki_success":true}
{"time":"2026-05-28T12:27:21.932330878Z","level":"WARN","msg":"failed to report run progress","test":"bulk","error":"progress update failed: no active usage tracking found with ID 40f43b150002f6b599c46540a0d18680"}
{"time":"2026-05-28T12:27:26.309601239Z","level":"INFO","msg":"📝 tx gas limit set (estimate + buffer)","test":"bulk","module":"contract","contract":"0xc07B3E9671f884FDa67E1e7D43d952E0e1369fd8","method":"bulkRemoveValidator","estimated_gas":200735,"gas_buffer_pct":1000,"gas_limit":2208085}
{"time":"2026-05-28T12:27:26.328994181Z","level":"INFO","msg":"4️⃣ Bulk Removing validators","test":"bulk","module":"contract","tx_hash":"0xfb9424abcca4c444d453a7f2da4dad63068b12f28f901514eeb7fedc66701d92"}
{"time":"2026-05-28T12:27:26.331635228Z","level":"WARN","msg":"failed to report run progress","test":"bulk","error":"progress update failed: no active usage tracking found with ID 40f43b150002f6b599c46540a0d18680"}
{"time":"2026-05-28T12:27:26.331696969Z","level":"INFO","msg":"Bulk removal transaction sent","test":"bulk","txHash":"0xfb9424abcca4c444d453a7f2da4dad63068b12f28f901514eeb7fedc66701d92"}
{"time":"2026-05-28T12:27:26.338280009Z","level":"INFO","msg":"Waiting for transaction receipt, retrying...","test":"bulk","module":"contract","attempt":1,"sleep":10,"tx_hash":"0xfb9424abcca4c444d453a7f2da4dad63068b12f28f901514eeb7fedc66701d92","tx_state":"pending"}
{"time":"2026-05-28T12:27:36.3533444Z","level":"INFO","msg":"Waiting for transaction receipt, retrying...","test":"bulk","module":"contract","attempt":2,"sleep":20,"tx_hash":"0xfb9424abcca4c444d453a7f2da4dad63068b12f28f901514eeb7fedc66701d92","tx_state":"pending"}
{"time":"2026-05-28T12:27:56.358439501Z","level":"INFO","msg":"Transaction receipt received","test":"bulk","module":"contract","tx_hash":"0xfb9424abcca4c444d453a7f2da4dad63068b12f28f901514eeb7fedc66701d92"}
{"time":"2026-05-28T12:27:56.358486271Z","level":"INFO","msg":"📜 CONTRACT: Bulk Removal Successful","test":"bulk","blockHash":"0x1d99292cb8845b3912e0554a1980ebe30864619741cc60c138a3d967ca1fe09f","Validators Amount":5}
{"time":"2026-05-28T12:27:56.369808517Z","level":"INFO","msg":"waiting for block to be found","module":"main","module":"e2m-validator","module":"e2m"}
{"time":"2026-05-28T12:27:56.454831183Z","level":"INFO","msg":"Loki: no matching logs yet, retrying until data appears or max attempts is reached","module":"main","module":"loki-validator","attempts":1,"retry_delay":"20s","start_unix":1779960476,"end_unix":1779971276}
{"time":"2026-05-28T12:28:16.384611051Z","level":"INFO","msg":"waiting for block to be found","module":"main","module":"e2m-validator","module":"e2m"}
{"time":"2026-05-28T12:28:36.393523887Z","level":"INFO","msg":"waiting for block to be found","module":"main","module":"e2m-validator","module":"e2m"}
{"time":"2026-05-28T12:28:56.402628768Z","level":"INFO","msg":"Removal tx epoch: polling E2M until attestations.Assigned is 0 for these validators (on-chain removed, indexer may lag)","module":"main","module":"e2m-validator","validation_type":"removal","epoch":98327,"indices":"1102420,1104103,1092007,1092008,1104098","poll_interval_seconds":15,"fail_if_current_epoch_gte":98332,"fail_after_epochs_past_removal_tx":5}
{"time":"2026-05-28T12:29:11.444981938Z","level":"INFO","msg":"E2M removal check: waiting for epoch to reach removal tx before verifying duties cleared","module":"main","module":"e2m-validator","validation_type":"removal","epoch":98326,"indices":["1102420","1104103","1092007","1092008","1104098"],"removal_tx_epoch":98327}
{"time":"2026-05-28T12:29:16.560255143Z","level":"INFO","msg":"Validator event validation successful","module":"main","module":"loki-validator","validated_validators":5,"event":"ValidatorRemoved"}
{"time":"2026-05-28T12:29:16.560302263Z","level":"INFO","msg":"Loki: SSV node log validation successful","test":"bulk","indices":["1102420","1104103","1092007","1092008","1104098"],"validators":5,"validate-type":"removal"}
{"time":"2026-05-28T12:29:16.560322525Z","level":"INFO","msg":"E2M validation still in progress: waiting to confirm whether validators are no longer active on-chain duties (polling each 15s, next log may take several minutes)","test":"bulk","indices":["1102420","1104103","1092007","1092008","1104098"],"validators":5,"validate-type":"removal"}
{"time":"2026-05-28T12:29:56.539564473Z","level":"INFO","msg":"E2M removal check: validators still have duties in E2M, waiting for 'assigned' to drop to zero","module":"main","module":"e2m-validator","validation_type":"removal","epoch":98327,"indices":["1102420","1104103","1092007","1092008","1104098"],"assigned":5,"executed":5,"missed":0}
{"time":"2026-05-28T12:31:56.772351211Z","level":"INFO","msg":"E2M removal check: same epoch, still polling until 'assigned' is zero (validators should stop, not attest)","module":"main","module":"e2m-validator","validation_type":"removal","epoch":98327,"indices":["1102420","1104103","1092007","1092008","1104098"],"assigned":5,"executed":5,"missed":0}
{"time":"2026-05-28T12:33:56.970468383Z","level":"INFO","msg":"E2M removal check: same epoch, still polling until 'assigned' is zero (validators should stop, not attest)","module":"main","module":"e2m-validator","validation_type":"removal","epoch":98327,"indices":["1102420","1104103","1092007","1092008","1104098"],"assigned":5,"executed":5,"missed":0}
{"time":"2026-05-28T12:35:42.1954392Z","level":"INFO","msg":"E2M removal validation successful - validators stopped attesting","module":"main","module":"e2m-validator","validation_type":"removal","indices":["1102420","1104103","1092007","1092008","1104098"],"removed_epoch":98327,"validated_epoch":98328,"epochs_waited":1}
{"time":"2026-05-28T12:35:42.195501273Z","level":"INFO","msg":"E2M validation successful","test":"bulk","indices":["1102420","1104103","1092007","1092008","1104098"],"validate-type":"removal"}
{"time":"2026-05-28T12:35:42.19553812Z","level":"INFO","msg":"✅ SUCCESS: Removal Validation Success","test":"bulk","validate_type":"removal","e2m_enabled":true,"e2m_success":true,"loki_success":true}
{"time":"2026-05-28T12:35:42.195551828Z","level":"INFO","msg":"Bulk: removal validation summary","test":"bulk","bulk_amount":5,"removed_pubkeys":5,"indices_for_e2m":5,"e2m_success":true,"loki_success":true}
{"time":"2026-05-28T12:35:42.203855133Z","level":"WARN","msg":"failed to report run progress","test":"bulk","error":"progress update failed: no active usage tracking found with ID 40f43b150002f6b599c46540a0d18680"}
{"time":"2026-05-28T12:35:42.203929693Z","level":"INFO","msg":"✅ SUCCESS: Bulk Test Suite Completed Successfully","module":"main","register":{"Contract":true,"E2M":true,"Loki":true},"liquidate":{"Contract":true,"E2M":true,"Loki":true},"reactivate":{"Contract":true,"E2M":true,"Loki":true},"remove":{"Contract":true,"E2M":true,"Loki":true}}
{"time":"2026-05-28T12:35:42.203939491Z","level":"INFO","msg":"⏳ PROGRESS: Waiting for all tests to finish","module":"main"}
{"time":"2026-05-28T12:35:42.203977598Z","level":"INFO","msg":"✅ SUCCESS: All Test Suites Completed Successfully","module":"main","passed_suites":["sanity","bulk"],"skipped_suites":["isolated"]}
{"time":"2026-05-28T12:35:42.204004394Z","level":"INFO","msg":"🔑 KEY STEP: Starting resource teardown...","module":"main","usage_id":"40f43b150002f6b599c46540a0d18680"}
{"time":"2026-05-28T12:35:42.205539656Z","level":"INFO","msg":"Resource usage already cleared, skipping teardown attempts","module":"main","usage_id":"40f43b150002f6b599c46540a0d18680"}
Result - 🟢 Success
|
2 tasks
iurii-ssv
reviewed
May 28, 2026
iurii-ssv
left a comment
iurii-ssv
left a comment
Contributor
There was a problem hiding this comment.
Leaving a few inline notes. Most are minor; the only judgement call is the attribute-key fragmentation across P2P metrics — flagged as informational since it touches design rather than mechanics.
If helpful, I've put the mechanical fixes (description, helper comment, test shadowing rename) into a draft PR you can merge into this branch as-is: #2862. Cherry-pick or close as you prefer.
| observabilityNamespace = "ssv.p2p.messages" | ||
|
|
||
| pubsubObservabilityNamespace = "ssv.p2p.pubsub.messages" | ||
| pubsubTopicAttributeKey = "ssv.p2p.pubsub.topic" |
Contributor
There was a problem hiding this comment.
Attribute-key fragmentation for "topic name" (informational — not blocking)
This new key labels exactly the same logical thing (a libp2p topic name) as two existing keys in the codebase:
ssv.p2p.message.topic— used byinboundMessageCounter/outboundMessageCounterin this very file (messageTopicAttribute, line 55).ssv.p2p.topic.name— used bypeersPerTopicGaugeinnetwork/p2p/observability.go:91.
With this PR there are now three keys for the same value across the P2P metrics surface. The most natural correlation an operator wants — "received → inbound → peers per topic" — cannot be done with a single group by topic in PromQL; they'll need to remember which key applies to which counter.
I understand the rationale (the new ssv.p2p.pubsub.* namespace deserves its own attribute prefix), so I'm not suggesting a concrete change here — it's a design call. But it would be worth either reusing one of the existing keys, or opening a follow-up to consolidate all three under a single canonical key (e.g. ssv.p2p.topic.name).
| meter.Int64Counter( | ||
| observability.InstrumentName(pubsubObservabilityNamespace, "received"), | ||
| metric.WithUnit("{message}"), | ||
| metric.WithDescription("total number of messages received by the pubsub topic validator"))) |
Contributor
There was a problem hiding this comment.
Description is ambiguous next to inboundMessageCounter
The description here ("total number of messages received by the pubsub topic validator") and inboundMessageCounter's description ("total number of inbound messages", line 29) sound nearly identical to anyone reading the metric registry — yet the entire point of this PR is that the two counters measure different things (pre- vs. post-validation). Tightening the wording so the distinction is visible at a glance:
Suggested change
| metric.WithDescription("total number of messages received by the pubsub topic validator"))) | |
| metric.WithDescription("total number of messages delivered to the pubsub topic validator, before SSV validation runs (compare with ssv_p2p_messages_in_total for the post-validation rate)"))) |
| } | ||
| } | ||
|
|
||
| func recordPubsubMessageReceived(ctx context.Context, topic string) { |
Contributor
There was a problem hiding this comment.
Minor: worth a 1-line comment to flag pre-validation timing
A future reader touching the wrapper in controller.go might assume this counts only successful deliveries. Calling out the timing explicitly here means they don't have to chase the call site to find out:
Suggested change
| func recordPubsubMessageReceived(ctx context.Context, topic string) { | |
| // recordPubsubMessageReceived is called from the topic validator wrapper before the inner SSV | |
| // validator runs, so the counter increments for every message libp2p hands to the validator | |
| // regardless of validation outcome (accept/ignore/reject/timeout). | |
| func recordPubsubMessageReceived(ctx context.Context, topic string) { |
Comment on lines
+30
to
+35
| for _, metric := range scopeMetrics.Metrics { | ||
| if metric.Name != "ssv.p2p.pubsub.messages.received" { | ||
| continue | ||
| } | ||
|
|
||
| sum, ok := metric.Data.(metricdata.Sum[int64]) |
Contributor
There was a problem hiding this comment.
Nit: loop variable metric shadows the imported metric package
From go.opentelemetry.io/otel/sdk/metric (line 8). Compiles only because the package isn't referenced inside the loop body, but it's an avoidable foot-gun if anyone later edits this block. Renaming to m:
Suggested change
| for _, metric := range scopeMetrics.Metrics { | |
| if metric.Name != "ssv.p2p.pubsub.messages.received" { | |
| continue | |
| } | |
| sum, ok := metric.Data.(metricdata.Sum[int64]) | |
| for _, m := range scopeMetrics.Metrics { | |
| if m.Name != "ssv.p2p.pubsub.messages.received" { | |
| continue | |
| } | |
| sum, ok := m.Data.(metricdata.Sum[int64]) |
momosh-ssv
reviewed
Jun 12, 2026
| reader := metric.NewManualReader() | ||
| provider := metric.NewMeterProvider(metric.WithReader(reader)) | ||
| previousProvider := otel.GetMeterProvider() | ||
| otel.SetMeterProvider(provider) |
Contributor
There was a problem hiding this comment.
Should we consider moving the provider swap into a TestMain, like protocol/v2/ssv/queue/main_test.go does?
Seems that setting the global provider mid-test leaves the package-level counters re-pointed for whatever runs after, and restoring the previous (delegating) provider in cleanup may not actually rebind them.
Setting a ManualReader-backed provider once before m.Run() would match the existing pattern and avoid the order dependence.
|
|
||
| err = ctrl.ps.RegisterTopicValidator(name, ctrl.msgValidator.ValidatorForTopic(name), opts...) | ||
| validator := ctrl.msgValidator.ValidatorForTopic(name) | ||
| wrappedValidator := func(ctx context.Context, p peer.ID, pmsg *pubsub.Message) pubsub.ValidationResult { |
Contributor
There was a problem hiding this comment.
Might be worth a test that goes through the wrapper itself — the new test calls recordPubsubMessageReceived directly, so the wiring here stays unverified.
Registering the validator and pushing one message through it, then asserting the counter, would close that gap.
…owed test var (#2862) - Tighten the counter description to spell out that it counts deliveries to the topic validator *before* SSV validation runs, and reference inboundMessageCounter so operators can see the post-validation counterpart at a glance. - Add a brief comment on recordPubsubMessageReceived noting it is invoked from the validator wrapper before the inner validator, so all outcomes (including reject/timeout) are counted. - Rename the test loop variable that shadowed the imported metric package.
This file contains hidden or bidirectional Unicode text that may be interpreted or compiled differently than what appears below. To review, open the file in an editor that reveals hidden Unicode characters.
Learn more about bidirectional Unicode characters
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
3 participants
Add this suggestion to a batch that can be applied as a single commit.This suggestion is invalid because no changes were made to the code.Suggestions cannot be applied while the pull request is closed.Suggestions cannot be applied while viewing a subset of changes.Only one suggestion per line can be applied in a batch.Add this suggestion to a batch that can be applied as a single commit.Applying suggestions on deleted lines is not supported.You must change the existing code in this line in order to create a valid suggestion.Outdated suggestions cannot be applied.This suggestion has been applied or marked resolved.Suggestions cannot be applied from pending reviews.Suggestions cannot be applied on multi-line comments.Suggestions cannot be applied while the pull request is queued to merge.Suggestion cannot be applied right now. Please check back later.
Ticket
F-ssv-1044
The ticket reports an observability gap: existing SSV validation counters show what happened after SSV validation runs, but they do not show whether a pubsub message reached the node's topic validator at all. That leaves delivery/topic/mesh issues ambiguous from validation/decoding issues.
Changes
ssv_p2p_pubsub_messages_received_totalvia OTel instrumentssv.p2p.pubsub.messages.received.topic.Validation
go test ./network/topics -run TestRecordPubsubMessageReceived -count=1 -timeout=30sgo test ./network/topics -run '^$' -count=1 -timeout=30sGOWORK=off go tool -modfile=tool.mod github.com/golangci/golangci-lint/v2/cmd/golangci-lint run ./network/topicsFixes - Fixes ssvlabs/ssv-node-board#1044