Bug: Accounts die silently and streams don't resume on restart

[fabriguespe]

Describe the bug

• After the latest Node SDK bindings release, logs were added for the Node SDK bots.
• Upon restarting, the message stream does not resume, preventing the bot from receiving or responding to messages.
• The stream only resumes correctly after removing and re-adding the bot.
• Another workaround is wiping the DB and restarting the bot.

log (1).txt

Area.1.mp4

2024-10-17T17:06:26.184081Z  INFO xmtp_mls::groups::sync: Processing envelope with hash "9d9a4b28377e782279e59b964a2ea21e2dd48e85cb1351483150c2276b4d8ed9"

2024-10-17T17:06:26.184086Z  INFO xmtp_mls::groups::sync: client [b92c13db581e91ff4b5c1d5af598a4f4a815f3d9b960d5fc79febb1ae3c71a05] is about to process external envelope [39658]

2024-10-17T17:06:26.184088Z ERROR openmls::group::public_group::validation: Wrong Epoch: message.epoch() 68 > 65 self.group_context().epoch()    

2024-10-17T17:06:26.184090Z DEBUG xmtp_mls::storage::encrypted_store: Transaction async being rolled back

2024-10-17T17:06:26.184095Z  INFO xmtp_mls::groups::sync: error is not retryable. OpenMlsProcessMessage(ValidationError(WrongEpoch))

2024-10-17T17:06:26.184097Z DEBUG xmtp_mls::storage::encrypted_store: Transaction async beginning

2024-10-17T17:06:26.184099Z DEBUG xmtp_mls::storage::encrypted_store: Pulling connection from pool, idle_connections=23, total_connections=25

2024-10-17T17:06:26.184120Z  INFO xmtp_mls::groups::sync: Processing envelope with hash "71b9d064d93754f61f49097fe996b953857ace3ee242f2090f493eeda3b48313"

2024-10-17T17:06:26.184125Z  INFO xmtp_mls::groups::sync: client [b92c13db581e91ff4b5c1d5af598a4f4a815f3d9b960d5fc79febb1ae3c71a05] is about to process external envelope [39659]

2024-10-17T17:06:26.184127Z ERROR openmls::group::public_group::validation: Wrong Epoch: message.epoch() 68 > 65 self.group_context().epoch()    

2024-10-17T17:06:26.184129Z DEBUG xmtp_mls::storage::encrypted_store: Transaction async being rolled back

2024-10-17T17:06:26.184135Z  INFO xmtp_mls::groups::sync: error is not retryable. OpenMlsProcessMessage(ValidationError(WrongEpoch))

2024-10-17T17:06:26.184137Z DEBUG xmtp_mls::storage::encrypted_store: Transaction async beginning

2024-10-17T17:06:26.184139Z DEBUG xmtp_mls::storage::encrypted_store: Pulling connection from pool, idle_connections=23, total_connections=25

2024-10-17T17:06:26.184161Z  INFO xmtp_mls::groups::sync: Processing envelope with hash "7e5afbbebbc591870b242be60a87b683a8bb1cb75de150df1ae53ea05900a255"

2024-10-17T17:06:26.184163Z  INFO xmtp_mls::groups::sync: client [b92c13db581e91ff4b5c1d5af598a4f4a815f3d9b960d5fc79febb1ae3c71a05] is about to process external envelope [39666]

2024-10-17T17:06:26.184165Z ERROR openmls::group::public_group::validation: Wrong Epoch: message.epoch() 68 > 65 self.group_context().epoch()    

2024-10-17T17:06:26.184167Z DEBUG xmtp_mls::storage::encrypted_store: Transaction async being rolled back

2024-10-17T17:06:26.184172Z  INFO xmtp_mls::groups::sync: error is not retryable. OpenMlsProcessMessage(ValidationError(WrongEpoch))

2024-10-17T17:06:26.184174Z DEBUG xmtp_mls::storage::encrypted_store: Transaction async beginning

2024-10-17T17:06:26.184175Z DEBUG xmtp_mls::storage::encrypted_store: Pulling connection from pool, idle_connections=23, total_connections=25

2024-10-17T17:06:26.184197Z  INFO xmtp_mls::groups::sync: Processing envelope with hash "ba2c85053bff24c5808f39a2885a16b54632417e7b7de2177e6fb6e5a6fe09a0"

2024-10-17T17:06:26.184201Z  INFO xmtp_mls::groups::sync: client [b92c13db581e91ff4b5c1d5af598a4f4a815f3d9b960d5fc79febb1ae3c71a05] is about to process external envelope [39667]

2024-10-17T17:06:26.184203Z ERROR openmls::group::public_group::validation: Wrong Epoch: message.epoch() 68 > 65 self.group_context().epoch()    

2024-10-17T17:06:26.184206Z DEBUG xmtp_mls::storage::encrypted_store: Transaction async being rolled back

2024-10-17T17:06:26.184211Z  INFO xmtp_mls::groups::sync: error is not retryable. OpenMlsProcessMessage(ValidationError(WrongEpoch))

2024-10-17T17:06:26.184213Z DEBUG xmtp_mls::storage::encrypted_store: Transaction async beginning

2024-10-17T17:06:26.184215Z DEBUG xmtp_mls::storage::encrypted_store: Pulling connection from pool, idle_connections=23, total_connections=25

2024-10-17T17:06:26.184236Z  INFO xmtp_mls::groups::sync: Processing envelope with hash "b4ae2538ffa26b788c1a99713d0975dea61e81325b053baeb29e9a3a5c62b641"

2024-10-17T17:06:26.184241Z  INFO xmtp_mls::groups::sync: client [b92c13db581e91ff4b5c1d5af598a4f4a815f3d9b960d5fc79febb1ae3c71a05] is about to process external envelope [39668]

2024-10-17T17:06:26.184243Z ERROR openmls::group::public_group::validation: Wrong Epoch: message.epoch() 68 > 65 self.group_context().epoch()    

2024-10-17T17:06:26.184245Z DEBUG xmtp_mls::storage::encrypted_store: Transaction async being rolled back

2024-10-17T17:06:26.184254Z  INFO xmtp_mls::groups::sync: error is not retryable. OpenMlsProcessMessage(ValidationError(WrongEpoch))

2024-10-17T17:06:26.184257Z DEBUG xmtp_mls::storage::encrypted_store: Transaction async beginning

2024-10-17T17:06:26.184259Z DEBUG xmtp_mls::storage::encrypted_store: Pulling connection from pool, idle_connections=23, total_connections=25

2024-10-17T17:06:26.184281Z  INFO xmtp_mls::groups::sync: Processing envelope with hash "01996fd91a4a15884a47b770d5db0d95c531e5bd85fcff20172e222062e0a923"

2024-10-17T17:06:26.184286Z  INFO xmtp_mls::groups::sync: client [b92c13db581e91ff4b5c1d5af598a4f4a815f3d9b960d5fc79febb1ae3c71a05] is about to process external envelope [39669]

2024-10-17T17:06:26.184288Z ERROR openmls::group::public_group::validation: Wrong Epoch: message.epoch() 68 > 65 self.group_context().epoch()    

2024-10-17T17:06:26.184290Z DEBUG xmtp_mls::storage::encrypted_store: Transaction async being rolled back

2024-10-17T17:06:26.184295Z  INFO xmtp_mls::groups::sync: error is not retryable. OpenMlsProcessMessage(ValidationError(WrongEpoch))

2024-10-17T17:06:26.184298Z DEBUG xmtp_mls::storage::encrypted_store: Transaction async beginning

2024-10-17T17:06:26.184299Z DEBUG xmtp_mls::storage::encrypted_store: Pulling connection from pool, idle_connections=23, total_connections=25

2024-10-17T17:06:26.184321Z  INFO xmtp_mls::groups::sync: Processing envelope with hash "029d16222223662c4741bb884fa229f0923d87665eabf92435b0e9ac89d21ee0"

2024-10-17T17:06:26.184325Z  INFO xmtp_mls::groups::sync: client [b92c13db581e91ff4b5c1d5af598a4f4a815f3d9b960d5fc79febb1ae3c71a05] is about to process external envelope [39670]

2024-10-17T17:06:26.184327Z ERROR openmls::group::public_group::validation: Wrong Epoch: message.epoch() 68 > 65 self.group_context().epoch()    

2024-10-17T17:06:26.184329Z DEBUG xmtp_mls::storage::encrypted_store: Transaction async being rolled back

2024-10-17T17:06:26.184335Z  INFO xmtp_mls::groups::sync: error is not retryable. OpenMlsProcessMessage(ValidationError(WrongEpoch))

2024-10-17T17:06:26.184337Z DEBUG xmtp_mls::storage::encrypted_store: Transaction async beginning

2024-10-17T17:06:26.184338Z DEBUG xmtp_mls::storage::encrypted_store: Pulling connection from pool, idle_connections=23, total_connections=25

2024-10-17T17:06:26.184360Z  INFO xmtp_mls::groups::sync: Processing envelope with hash "b9f2a4dce303114cf677de71709910b6381c55f6da551f856cff6a0c26a3b933"

2024-10-17T17:06:26.184365Z  INFO xmtp_mls::groups::sync: client [b92c13db581e91ff4b5c1d5af598a4f4a815f3d9b960d5fc79febb1ae3c71a05] is about to process external envelope [39671]

2024-10-17T17:06:26.184367Z ERROR openmls::group::public_group::validation: Wrong Epoch: message.epoch() 68 > 65 self.group_context().epoch()    

2024-10-17T17:06:26.184369Z DEBUG xmtp_mls::storage::encrypted_store: Transaction async being rolled back

2024-10-17T17:06:26.184374Z  INFO xmtp_mls::groups::sync: error is not retryable. OpenMlsProcessMessage(ValidationError(WrongEpoch))

2024-10-17T17:06:26.184377Z DEBUG xmtp_mls::storage::encrypted_store: Transaction async beginning

2024-10-17T17:06:26.184378Z DEBUG xmtp_mls::storage::encrypted_store: Pulling connection from pool, idle_connections=23, total_connections=25

2024-10-17T17:06:26.184400Z  INFO xmtp_mls::groups::sync: Processing envelope with hash "15a2195322ded85595e607d86bd9190bd0cc05dc713da733f2e8a1f02888b15a"

2024-10-17T17:06:26.184405Z  INFO xmtp_mls::groups::sync: client [b92c13db581e91ff4b5c1d5af598a4f4a815f3d9b960d5fc79febb1ae3c71a05] is about to process external envelope [39672]

2024-10-17T17:06:26.184407Z ERROR openmls::group::public_group::validation: Wrong Epoch: message.epoch() 68 > 65 self.group_context().epoch()    

2024-10-17T17:06:26.184409Z DEBUG xmtp_mls::storage::encrypted_store: Transaction async being rolled back

2024-10-17T17:06:26.184414Z  INFO xmtp_mls::groups::sync: error is not retryable. OpenMlsProcessMessage(ValidationError(WrongEpoch))

2024-10-17T17:06:26.184417Z ERROR xmtp_mls::groups::sync: Message processing errors: [OpenMlsProcessMessage(ValidationError(WrongEpoch)), OpenMlsProcessMessage(ValidationError(WrongEpoch)), OpenMlsProcessMessage(ValidationError(WrongEpoch)), OpenMlsProcessMessage(ValidationError(WrongEpoch)), OpenMlsProcessMessage(ValidationError(WrongEpoch)), OpenMlsProcessMessage(ValidationError(WrongEpoch)), OpenMlsProcessMessage(ValidationError(WrongEpoch)), OpenMlsProcessMessage(ValidationError(WrongEpoch)), OpenMlsProcessMessage(ValidationError(WrongEpoch)), OpenMlsProcessMessage(ValidationError(WrongEpoch)), OpenMlsProcessMessage(ValidationError(WrongEpoch)), OpenMlsProcessMessage(ValidationError(WrongEpoch)), OpenMlsProcessMessage(ValidationError(WrongEpoch)), OpenMlsProcessMessage(ValidationError(WrongEpoch)), OpenMlsProcessMessage(ValidationError(WrongEpoch)), OpenMlsProcessMessage(ValidationError(WrongEpoch)), OpenMlsProcessMessage(ValidationError(WrongEpoch)), OpenMlsProcessMessage(ValidationError(WrongEpoch)), OpenMlsProcessMessage(ValidationError(WrongEpoch)), OpenMlsProcessMessage(ValidationError(WrongEpoch)), OpenMlsProcessMessage(ValidationError(WrongEpoch)), OpenMlsProcessMessage(ValidationError(WrongEpoch)), OpenMlsProcessMessage(ValidationError(WrongEpoch)), OpenMlsProcessMessage(ValidationError(WrongEpoch)), OpenMlsProcessMessage(ValidationError(WrongEpoch)), OpenMlsProcessMessage(ValidationError(WrongEpoch)), OpenMlsProcessMessage(ValidationError(WrongEpoch)), OpenMlsProcessMessage(ValidationError(WrongEpoch)), OpenMlsProcessMessage(ValidationError(WrongEpoch)), OpenMlsProcessMessage(ValidationError(WrongEpoch)), OpenMlsProcessMessage(ValidationError(WrongEpoch)), OpenMlsProcessMessage(ValidationError(WrongEpoch)), OpenMlsProcessMessage(ValidationError(WrongEpoch)), OpenMlsProcessMessage(ValidationError(WrongEpoch)), OpenMlsProcessMessage(ValidationError(WrongEpoch)), OpenMlsProcessMessage(ValidationError(WrongEpoch)), OpenMlsProcessMessage(ValidationError(WrongEpoch)), OpenMlsProcessMessage(ValidationError(WrongEpoch)), OpenMlsProcessMessage(ValidationError(WrongEpoch)), OpenMlsProcessMessage(ValidationError(WrongEpoch)), OpenMlsProcessMessage(ValidationError(WrongEpoch)), OpenMlsProcessMessage(ValidationError(WrongEpoch)), OpenMlsProcessMessage(ValidationError(WrongEpoch))]

2024-10-17T17:06:26.184561Z ERROR xmtp_mls::groups::sync: receive error ReceiveErrors([OpenMlsProcessMessage(ValidationError(WrongEpoch)), OpenMlsProcessMessage(ValidationError(WrongEpoch)), OpenMlsProcessMessage(ValidationError(WrongEpoch)), OpenMlsProcessMessage(ValidationError(WrongEpoch)), OpenMlsProcessMessage(ValidationError(WrongEpoch)), OpenMlsProcessMessage(ValidationError(WrongEpoch)), OpenMlsProcessMessage(ValidationError(WrongEpoch)), OpenMlsProcessMessage(ValidationError(WrongEpoch)), OpenMlsProcessMessage(ValidationError(WrongEpoch)), OpenMlsProcessMessage(ValidationError(WrongEpoch)), OpenMlsProcessMessage(ValidationError(WrongEpoch)), OpenMlsProcessMessage(ValidationError(WrongEpoch)), OpenMlsProcessMessage(ValidationError(WrongEpoch)), OpenMlsProcessMessage(ValidationError(WrongEpoch)), OpenMlsProcessMessage(ValidationError(WrongEpoch)), OpenMlsProcessMessage(ValidationError(WrongEpoch)), OpenMlsProcessMessage(ValidationError(WrongEpoch)), OpenMlsProcessMessage(ValidationError(WrongEpoch)), OpenMlsProcessMessage(ValidationError(WrongEpoch)), OpenMlsProcessMessage(ValidationError(WrongEpoch)), OpenMlsProcessMessage(ValidationError(WrongEpoch)), OpenMlsProcessMessage(ValidationError(WrongEpoch)), OpenMlsProcessMessage(ValidationError(WrongEpoch)), OpenMlsProcessMessage(ValidationError(WrongEpoch)), OpenMlsProcessMessage(ValidationError(WrongEpoch)), OpenMlsProcessMessage(ValidationError(WrongEpoch)), OpenMlsProcessMessage(ValidationError(WrongEpoch)), OpenMlsProcessMessage(ValidationError(WrongEpoch)), OpenMlsProcessMessage(ValidationError(WrongEpoch)), OpenMlsProcessMessage(ValidationError(WrongEpoch)), OpenMlsProcessMessage(ValidationError(WrongEpoch)), OpenMlsProcessMessage(ValidationError(WrongEpoch)), OpenMlsProcessMessage(ValidationError(WrongEpoch)), OpenMlsProcessMessage(ValidationError(WrongEpoch)), OpenMlsProcessMessage(ValidationError(WrongEpoch)), OpenMlsProcessMessage(ValidationError(WrongEpoch)), OpenMlsProcessMessage(ValidationError(WrongEpoch)), OpenMlsProcessMessage(ValidationError(WrongEpoch)), OpenMlsProcessMessage(ValidationError(WrongEpoch)), OpenMlsProcessMessage(ValidationError(WrongEpoch)), OpenMlsProcessMessage(ValidationError(WrongEpoch)), OpenMlsProcessMessage(ValidationError(WrongEpoch)), OpenMlsProcessMessage(ValidationError(WrongEpoch))])

2024-10-17T17:06:26.184636Z DEBUG xmtp_mls::groups::subscriptions: Sync triggered by streamed message successful

2024-10-17T17:06:26.184643Z DEBUG xmtp_mls::storage::encrypted_store: Pulling connection from pool, idle_connections=24, total_connections=25

2024-10-17T17:06:26.184703Z  INFO xmtp_mls::subscriptions: Skipped message streaming payload

2024-10-17T17:09:56.228729Z DEBUG Connection{peer=Client}: h2::codec::framed_read: received frame=Ping { ack: false, payload: [0, 0, 0, 0, 0, 0, 0, 0] }

2024-10-17T17:09:56.228775Z DEBUG Connection{peer=Client}: h2::codec::framed_write: send frame=Ping { ack: true, payload: [0, 0, 0, 0, 0, 0, 0, 0] }

[fabriguespe]

When I installed Converse on a new phone, I stopped being part of the group chat. After wiping my local data and re-adding my account, I was able to join the group again. This could be tied to the way client instances are managed across devices, similar to the bot issue where the stream doesn’t resume.