Bug: missed events when indexing monitored homeserver due to PubkyClientError

[catch-21]

Nexus in staging has been configured to monitor other homeservers, including the one we host for production. The majority of posts, tags etc. made in production have been indexed but some were noticed as missing:

Post 1
https://pubky.app/post/xfruyap91ekm4my5xi3s5g4uixk5s4t3rsj6enp5e3zyj86z37ro/00347QP1762MG
https://staging.pubky.app/post/xfruyap91ekm4my5xi3s5g4uixk5s4t3rsj6enp5e3zyj86z37ro/00347QP1762MG
Post 2
https://pubky.app/post/xfruyap91ekm4my5xi3s5g4uixk5s4t3rsj6enp5e3zyj86z37ro/00347QNS6GYAG
https://staging.pubky.app/post/xfruyap91ekm4my5xi3s5g4uixk5s4t3rsj6enp5e3zyj86z37ro/00347QNS6GYAG
Reply
https://pubky.app/post/xfruyap91ekm4my5xi3s5g4uixk5s4t3rsj6enp5e3zyj86z37ro/00347QP85ADE0
https://staging.pubky.app/post/xfruyap91ekm4my5xi3s5g4uixk5s4t3rsj6enp5e3zyj86z37ro/00347QP85ADE0

Each of these were made by the same user in an approximately 5 minute period. As you can see, only nexus in production has indexed them, and nexus in staging did not.

Looking at nexus logs around this time shows each of these events was attempted to be indexed once but there was a PubkyClientError:

Post 1

Nov 18 13:52:07 nexus-service.europe-west6-b.c.pubky-stag.internal nexusd[204291]: 2025-11-18T13:52:07.979228Z DEBUG nexus_watcher::events:43: New event: PUT pubky://xfruyap91ekm4my5xi3s5g4uixk5s4t3rsj6enp5e3zyj86z37ro/pub/pubky.app/posts/00347QP1762MG
Nov 18 13:52:07 nexus-service.europe-west6-b.c.pubky-stag.internal nexusd[204291]: 2025-11-18T13:52:07.979261Z DEBUG nexus_watcher::service::processor:137: Processing event: Event { uri: "pubky://xfruyap91ekm4my5xi3s5g4uixk5s4t3rsj6enp5e3zyj86z37ro/pub/pubky.app/posts/0
0347QP1762MG", event_type: Put, parsed_uri: ParsedUri { user_id: PubkyId("xfruyap91ekm4my5xi3s5g4uixk5s4t3rsj6enp5e3zyj86z37ro"), resource: Post("00347QP1762MG") }, files_path: "/home/pubky-stag/static/files" }
Nov 18 13:52:07 nexus-service.europe-west6-b.c.pubky-stag.internal nexusd[204291]: 2025-11-18T13:52:07.979278Z DEBUG nexus_watcher::events:104: Handling PUT event for URI: pubky://xfruyap91ekm4my5xi3s5g4uixk5s4t3rsj6enp5e3zyj86z37ro/pub/pubky.app/posts/00347QP1762MG
Nov 18 13:52:07 nexus-service.europe-west6-b.c.pubky-stag.internal nexusd[204291]: 2025-11-18T13:52:07.979362Z DEBUG reqwest::connect:882: starting new connection: https://_pubky.xfruyap91ekm4my5xi3s5g4uixk5s4t3rsj6enp5e3zyj86z37ro/
Nov 18 13:52:07 nexus-service.europe-west6-b.c.pubky-stag.internal nexusd[204291]: 2025-11-18T13:52:07.979435Z DEBUG pkarr::client:399: responding with cached packet even if expired. public_key: xfruyap91ekm4my5xi3s5g4uixk5s4t3rsj6enp5e3zyj86z37ro
Nov 18 13:52:07 nexus-service.europe-west6-b.c.pubky-stag.internal nexusd[204291]: 2025-11-18T13:52:07.980762Z DEBUG hyper_util::client::legacy::connect::http:768: connecting to 34.65.156.171:443
Nov 18 13:52:07 nexus-service.europe-west6-b.c.pubky-stag.internal nexusd[204291]: 2025-11-18T13:52:07.985800Z DEBUG hyper_util::client::legacy::connect::http:771: connected to 34.65.156.171:443
Nov 18 13:52:07 nexus-service.europe-west6-b.c.pubky-stag.internal nexusd[204291]: 2025-11-18T13:52:07.990363Z ERROR nexus_watcher::service::processor:152: PubkyClientError: error sending request for url (https://_pubky.xfruyap91ekm4my5xi3s5g4uixk5s4t3rsj6enp5e3zyj86z37
ro/pub/pubky.app/posts/00347QP1762MG), PUT:xfruyap91ekm4my5xi3s5g4uixk5s4t3rsj6enp5e3zyj86z37ro:posts:00347QP1762MG
Nov 18 13:52:07 nexus-service.europe-west6-b.c.pubky-stag.internal nexusd[204291]: 2025-11-18T13:52:07.992871Z DEBUG nexus_common::db::kv::index::json:62: Set key: RetryManager:state:PUT:xfruyap91ekm4my5xi3s5g4uixk5s4t3rsj6enp5e3zyj86z37ro:posts:00347QP1762MG with optional expiration: None

Post 2

Nov 18 13:53:39 nexus-service.europe-west6-b.c.pubky-stag.internal nexusd[204291]: 2025-11-18T13:53:39.295579Z DEBUG nexus_watcher::events:43: New event: PUT pubky://xfruyap91ekm4my5xi3s5g4uixk5s4t3rsj6enp5e3zyj86z37ro/pub/pubky.app/posts/00347QP85ADE0
Nov 18 13:53:39 nexus-service.europe-west6-b.c.pubky-stag.internal nexusd[204291]: 2025-11-18T13:53:39.295619Z DEBUG nexus_watcher::service::processor:137: Processing event: Event { uri: "pubky://xfruyap91ekm4my5xi3s5g4uixk5s4t3rsj6enp5e3zyj86z37ro/pub/pubky.app/posts/00347QP85ADE0", event_type: Put, parsed_uri: ParsedUri { user_id: PubkyId("xfruyap91ekm4my5xi3s5g4uixk5s4t3rsj6enp5e3zyj86z37ro"), resource: Post("00347QP85ADE0") }, files_path: "/home/pubky-stag/static/files" }
Nov 18 13:53:39 nexus-service.europe-west6-b.c.pubky-stag.internal nexusd[204291]: 2025-11-18T13:53:39.295635Z DEBUG nexus_watcher::events:104: Handling PUT event for URI: pubky://xfruyap91ekm4my5xi3s5g4uixk5s4t3rsj6enp5e3zyj86z37ro/pub/pubky.app/posts/00347QP85ADE0
Nov 18 13:53:39 nexus-service.europe-west6-b.c.pubky-stag.internal nexusd[204291]: 2025-11-18T13:53:39.295722Z DEBUG reqwest::connect:882: starting new connection: https://_pubky.xfruyap91ekm4my5xi3s5g4uixk5s4t3rsj6enp5e3zyj86z37ro/
Nov 18 13:53:39 nexus-service.europe-west6-b.c.pubky-stag.internal nexusd[204291]: 2025-11-18T13:53:39.295820Z DEBUG pkarr::client:399: responding with cached packet even if expired. public_key: xfruyap91ekm4my5xi3s5g4uixk5s4t3rsj6enp5e3zyj86z37ro
Nov 18 13:53:39 nexus-service.europe-west6-b.c.pubky-stag.internal nexusd[204291]: 2025-11-18T13:53:39.296910Z DEBUG hyper_util::client::legacy::connect::http:768: connecting to 34.65.156.171:443
Nov 18 13:53:39 nexus-service.europe-west6-b.c.pubky-stag.internal nexusd[204291]: 2025-11-18T13:53:39.302083Z DEBUG hyper_util::client::legacy::connect::http:771: connected to 34.65.156.171:443
Nov 18 13:53:39 nexus-service.europe-west6-b.c.pubky-stag.internal nexusd[204291]: 2025-11-18T13:53:39.306836Z ERROR nexus_watcher::service::processor:152: PubkyClientError: error sending request for url (https://_pubky.xfruyap91ekm4my5xi3s5g4uixk5s4t3rsj6enp5e3zyj86z37ro/pub/pubky.app/posts/00347QP85ADE0), PUT:xfruyap91ekm4my5xi3s5g4uixk5s4t3rsj6enp5e3zyj86z37ro:posts:00347QP85ADE0
Nov 18 13:53:39 nexus-service.europe-west6-b.c.pubky-stag.internal nexusd[204291]: 2025-11-18T13:53:39.309548Z DEBUG nexus_common::db::kv::index::json:62: Set key: RetryManager:state:PUT:xfruyap91ekm4my5xi3s5g4uixk5s4t3rsj6enp5e3zyj86z37ro:posts:00347QP85ADE0 with optional expiration: None

Reply

Nov 18 13:53:39 nexus-service.europe-west6-b.c.pubky-stag.internal nexusd[204291]: 2025-11-18T13:53:39.295579Z DEBUG nexus_watcher::events:43: New event: PUT pubky://xfruyap91ekm4my5xi3s5g4uixk5s4t3rsj6enp5e3zyj86z37ro/pub/pubky.app/posts/00347QP85ADE0
Nov 18 13:53:39 nexus-service.europe-west6-b.c.pubky-stag.internal nexusd[204291]: 2025-11-18T13:53:39.295619Z DEBUG nexus_watcher::service::processor:137: Processing event: Event { uri: "pubky://xfruyap91ekm4my5xi3s5g4uixk5s4t3rsj6enp5e3zyj86z37ro/pub/pubky.app/posts/00347QP85ADE0", event_type: Put, parsed_uri: ParsedUri { user_id: PubkyId("xfruyap91ekm4my5xi3s5g4uixk5s4t3rsj6enp5e3zyj86z37ro"), resource: Post("00347QP85ADE0") }, files_path: "/home/pubky-stag/static/files" }
Nov 18 13:53:39 nexus-service.europe-west6-b.c.pubky-stag.internal nexusd[204291]: 2025-11-18T13:53:39.295635Z DEBUG nexus_watcher::events:104: Handling PUT event for URI: pubky://xfruyap91ekm4my5xi3s5g4uixk5s4t3rsj6enp5e3zyj86z37ro/pub/pubky.app/posts/00347QP85ADE0
Nov 18 13:53:39 nexus-service.europe-west6-b.c.pubky-stag.internal nexusd[204291]: 2025-11-18T13:53:39.295722Z DEBUG reqwest::connect:882: starting new connection: https://_pubky.xfruyap91ekm4my5xi3s5g4uixk5s4t3rsj6enp5e3zyj86z37ro/
Nov 18 13:53:39 nexus-service.europe-west6-b.c.pubky-stag.internal nexusd[204291]: 2025-11-18T13:53:39.295820Z DEBUG pkarr::client:399: responding with cached packet even if expired. public_key: xfruyap91ekm4my5xi3s5g4uixk5s4t3rsj6enp5e3zyj86z37ro
Nov 18 13:53:39 nexus-service.europe-west6-b.c.pubky-stag.internal nexusd[204291]: 2025-11-18T13:53:39.296910Z DEBUG hyper_util::client::legacy::connect::http:768: connecting to 34.65.156.171:443
Nov 18 13:53:39 nexus-service.europe-west6-b.c.pubky-stag.internal nexusd[204291]: 2025-11-18T13:53:39.302083Z DEBUG hyper_util::client::legacy::connect::http:771: connected to 34.65.156.171:443
Nov 18 13:53:39 nexus-service.europe-west6-b.c.pubky-stag.internal nexusd[204291]: 2025-11-18T13:53:39.306836Z ERROR nexus_watcher::service::processor:152: PubkyClientError: error sending request for url (https://_pubky.xfruyap91ekm4my5xi3s5g4uixk5s4t3rsj6enp5e3zyj86z37ro/pub/pubky.app/posts/00347QP85ADE0), PUT:xfruyap91ekm4my5xi3s5g4uixk5s4t3rsj6enp5e3zyj86z37ro:posts:00347QP85ADE0
Nov 18 13:53:39 nexus-service.europe-west6-b.c.pubky-stag.internal nexusd[204291]: 2025-11-18T13:53:39.309548Z DEBUG nexus_common::db::kv::index::json:62: Set key: RetryManager:state:PUT:xfruyap91ekm4my5xi3s5g4uixk5s4t3rsj6enp5e3zyj86z37ro:posts:00347QP85ADE0 with optional expiration: None

The result is the event is not indexed and is not retried. I suggest that nexus must handle client errors so not to forget about unindexed events - keep a record and retry later. Also consider telling pubky-app about failed/delays post events that have not (yet) been successfully indexed.

[tipogi]

We are monitoring the failed events in redis under RetryManager:events, but are not retried. You can find there all the failed events for example PUT:xfruyap91ekm4my5xi3s5g4uixk5s4t3rsj6enp5e3zyj86z37ro:posts:00347QP1762MG and under that key the failed reason: RetryManager:state:PUT:xfruyap91ekm4my5xi3s5g4uixk5s4t3rsj6enp5e3zyj86z37ro:posts:00347QP1762MG

We started doing the retry manager (we only achieve the first step, caching) but other things got preference and we stopped. 2026 would be the year of that. To have more context, check src/events/retry