search

xmtp / xmtp-react-native

A package you can use to build with XMTP in a React Native or Expo app.
MIT License
35 stars 14 forks source link

Bug: Complex Setup with Streams and Group metadata causes forked groups #416

Closed alexrisch closed 2 weeks ago

alexrisch commented 3 weeks ago

Describe the bug

When setting streamAllMessages and updating group metadata fairly quickly after group creation Group syncing stops working

 const [alix, bo] = await createClients(2)
  console.log('created clients')

  //#region Stream All Messages
  await bo.conversations.streamAllMessages(async () => {
    console.log('message received')
  }, true)
  //#endregion
  // #region create group
  const alixGroup = await alix.conversations.newGroup([bo.address])
  await alixGroup.updateGroupName('hello')
  await alixGroup.send('hello1')
  console.log('sent group message')
  // #endregion
  // #region sync groups
  await bo.conversations.syncGroups()
  // #endregion
  const boGroups = await bo.conversations.listGroups()
  assert(boGroups.length === 1, 'bo should have 1 group')
  const boGroup = boGroups[0]
  await boGroup.sync()

  const boMessages1 = await boGroup.messages()
  assert(
    boMessages1.length === 2,
    `should have 2 messages on first load received ${boMessages1.length}`
  )
  await boGroup.send('hello2')
  await boGroup.send('hello3')
  await alixGroup.sync()
  const alixMessages = await alixGroup.messages()
  for (const message of alixMessages) {
    console.log(
      'message',
      message.contentTypeId,
      message.contentTypeId === 'xmtp.org/text:1.0'
        ? message.content()
        : 'Group Updated'
    )
  }
  // alix sees 3 messages
  assert(
    alixMessages.length === 5,
    `should have 5 messages on first load received ${alixMessages.length}`
  )
  await alixGroup.send('hello4')
  await boGroup.sync()
  const boMessages2 = await boGroup.messages()
  for (const message of boMessages2) {
    console.log(
      'message',
      message.contentTypeId,
      message.contentTypeId === 'xmtp.org/text:1.0'
        ? message.content()
        : 'Group Updated'
    )
  }
  // bo sees 4 messages
  assert(
    boMessages2.length === 5,
    `should have 5 messages on second load received ${boMessages2.length}`
  )

Expected behavior

No response

Steps to reproduce the bug

No response

cameronvoell commented 3 weeks ago

Logs with extra logging from Nick's libxmtp branch:

What seems notable to me is that it looks like the commit for updating the group name is being processed by both clients, however we start seeing Wrong Epoch: message.epoch() 2 > 1 self.group_context().epoch() for the non group creator. This seems to me like the second member processed the external message for the group name update, and successfully merged the commit, however their Group Context epoch did not increase from 1 to 2.

logs
``` 2024-06-13 07:07:39.597 19829-19888 INFO e I [libxmtp] Getting inbox_ids for account addresses: ["0xa7c16f129aa9dec5a9fd0321381ad8568bfe5e3d"] 2024-06-13 07:07:39.601 391-478 AudioFlinger pid-391 D mixer(0xb400007afe601930) throttle end: throttle time(33) 2024-06-13 07:07:39.605 19829-19888 INFO e I [libxmtp] Creating API client for host: http://10.0.2.2:5556, isSecure: false 2024-06-13 07:07:39.608 19829-19888 INFO e I [libxmtp] Creating message store with path: Some("/data/user/0/expo.modules.xmtpreactnativesdk.example/files/xmtp_db/xmtp-LOCAL-0e922b3d7ac597d11df41ccb34dbbdf82d2c6e454738d52cbe48e0ef05c604e8.db3") and encryption key: true 2024-06-13 07:07:39.608 19829-19888 INFO e I [libxmtp] Setting up DB connection pool 2024-06-13 07:07:39.612 19829-19888 INFO e I [libxmtp] Running DB migrations 2024-06-13 07:07:39.617 19829-19888 INFO e I [libxmtp] Migrations successful 2024-06-13 07:07:39.617 19829-19888 INFO e I [libxmtp] Creating XMTP client 2024-06-13 07:07:39.618 19829-19888 INFO e I [libxmtp] Initializing identity 2024-06-13 07:07:39.618 19829-19888 INFO e I [libxmtp] Getting inbox_ids for account addresses: ["0xa7c16f129aa9dec5a9fd0321381ad8568bfe5e3d"] 2024-06-13 07:07:39.623 19829-19888 INFO e I [libxmtp] Provided Signer: fc8206bdaf48928ea76219c077c81b14bb581005a8f7db2f2940cb478541a855 2024-06-13 07:07:39.624 19829-19888 INFO e I [libxmtp] Missing Signatures: [Address("0xa7c16f129aa9dec5a9fd0321381ad8568bfe5e3d"), Installation([252, 130, 6, 189, 175, 72, 146, 142, 167, 98, 25, 192, 119, 200, 27, 20, 187, 88, 16, 5, 168, 247, 219, 47, 41, 64, 203, 71, 133, 65, 168, 85])] 2024-06-13 07:07:39.625 19829-19888 INFO e I [libxmtp] Provided Signer: 0xa7c16f129aa9dec5a9fd0321381ad8568bfe5e3d 2024-06-13 07:07:39.626 19829-19888 INFO e I [libxmtp] Missing Signatures: [Address("0xa7c16f129aa9dec5a9fd0321381ad8568bfe5e3d")] 2024-06-13 07:07:39.657 19829-19888 INFO e I [libxmtp] Created XMTP client for inbox_id: 0e922b3d7ac597d11df41ccb34dbbdf82d2c6e454738d52cbe48e0ef05c604e8 2024-06-13 07:07:39.657 19829-19888 Client e I LibXMTP Version: 6797fd55 Branch: nm/forked-group-state Date: 2024-06-12 16:37:37 +0000 2024-06-13 07:07:39.676 19829-19888 XMTPModule e V createRandom 2024-06-13 07:07:39.680 19829-22291 TrafficStats e D tagSocket(458) with statsTag=0xffffffff, statsUid=-1 2024-06-13 07:07:39.714 391-478 audioserver pid-391 D FGS Logger Transaction failed 2024-06-13 07:07:39.714 391-478 audioserver pid-391 D -129 2024-06-13 07:07:39.720 19829-19888 INFO e I [libxmtp] Getting inbox_ids for account addresses: ["0x53a9321d28a209df2a1260bd2fb0ae86691aa874"] 2024-06-13 07:07:39.725 19829-19888 INFO e I [libxmtp] Creating API client for host: http://10.0.2.2:5556, isSecure: false 2024-06-13 07:07:39.728 19829-19888 INFO e I [libxmtp] Creating message store with path: Some("/data/user/0/expo.modules.xmtpreactnativesdk.example/files/xmtp_db/xmtp-LOCAL-cff60102f491735783d93cae79d11891b93a8f389e0de3a54f7868cc9d38e0b6.db3") and encryption key: true 2024-06-13 07:07:39.728 19829-19888 INFO e I [libxmtp] Setting up DB connection pool 2024-06-13 07:07:39.731 19829-19888 INFO e I [libxmtp] Running DB migrations 2024-06-13 07:07:39.736 19829-19888 INFO e I [libxmtp] Migrations successful 2024-06-13 07:07:39.737 19829-19888 INFO e I [libxmtp] Creating XMTP client 2024-06-13 07:07:39.738 19829-19888 INFO e I [libxmtp] Initializing identity 2024-06-13 07:07:39.739 19829-19888 INFO e I [libxmtp] Getting inbox_ids for account addresses: ["0x53a9321d28a209df2a1260bd2fb0ae86691aa874"] 2024-06-13 07:07:39.742 19829-19888 INFO e I [libxmtp] Provided Signer: 853f1cf116e7f43c9a7392503bca92399891394c37a6b94be8ee90c9dfa6efce 2024-06-13 07:07:39.742 19829-19888 INFO e I [libxmtp] Missing Signatures: [Address("0x53a9321d28a209df2a1260bd2fb0ae86691aa874"), Installation([133, 63, 28, 241, 22, 231, 244, 60, 154, 115, 146, 80, 59, 202, 146, 57, 152, 145, 57, 76, 55, 166, 185, 75, 232, 238, 144, 201, 223, 166, 239, 206])] 2024-06-13 07:07:39.743 19829-19888 INFO e I [libxmtp] Provided Signer: 0x53a9321d28a209df2a1260bd2fb0ae86691aa874 2024-06-13 07:07:39.744 19829-19888 INFO e I [libxmtp] Missing Signatures: [Address("0x53a9321d28a209df2a1260bd2fb0ae86691aa874")] 2024-06-13 07:07:39.773 19829-19888 INFO e I [libxmtp] Created XMTP client for inbox_id: cff60102f491735783d93cae79d11891b93a8f389e0de3a54f7868cc9d38e0b6 2024-06-13 07:07:39.773 19829-19888 Client e I LibXMTP Version: 6797fd55 Branch: nm/forked-group-state Date: 2024-06-12 16:37:37 +0000 2024-06-13 07:07:39.791 19829-19892 ReactNativeJS e I created clients 2024-06-13 07:07:39.791 19829-19892 XMTPModule e V subscribeToAllMessages 2024-06-13 07:07:39.793 19829-20204 XMTPModule e V createGroup 2024-06-13 07:07:39.796 19829-20204 INFO e I [libxmtp] Getting inbox_ids for account addresses: ["0x53a9321d28a209df2a1260bd2fb0ae86691aa874"] 2024-06-13 07:07:39.799 19829-22305 TrafficStats e D tagSocket(437) with statsTag=0xffffffff, statsUid=-1 2024-06-13 07:07:39.803 19829-19999 INFO e I [libxmtp] creating group with account addresses: 0x53A9321d28A209Df2A1260bD2FB0AE86691aA874 2024-06-13 07:07:39.806 19829-19999 INFO e I [libxmtp] creating group 2024-06-13 07:07:39.826 19829-19999 INFO e I [libxmtp] Getting inbox_ids for account addresses: ["0x53a9321d28a209df2a1260bd2fb0ae86691aa874"] 2024-06-13 07:07:39.837 19829-19999 INFO e I [libxmtp] old group membership: {"0e922b3d7ac597d11df41ccb34dbbdf82d2c6e454738d52cbe48e0ef05c604e8": 0} 2024-06-13 07:07:39.839 19829-19999 INFO e I [libxmtp] updated group membership: {"0e922b3d7ac597d11df41ccb34dbbdf82d2c6e454738d52cbe48e0ef05c604e8": 2963, "cff60102f491735783d93cae79d11891b93a8f389e0de3a54f7868cc9d38e0b6": 2964} 2024-06-13 07:07:39.857 19829-19999 INFO e I [libxmtp] [0e922b3d7ac597d11df41ccb34dbbdf82d2c6e454738d52cbe48e0ef05c604e8] Validating commit for intent 1. Message timestamp: 1718287661464649000 2024-06-13 07:07:39.858 19829-19999 INFO e I [libxmtp] Group context extensions proposal found: GroupMembership { members: {"0e922b3d7ac597d11df41ccb34dbbdf82d2c6e454738d52cbe48e0ef05c604e8": 2963, "cff60102f491735783d93cae79d11891b93a8f389e0de3a54f7868cc9d38e0b6": 2964} } 2024-06-13 07:07:39.858 19829-19999 INFO e I [libxmtp] [0e922b3d7ac597d11df41ccb34dbbdf82d2c6e454738d52cbe48e0ef05c604e8] merging pending commit for intent 1 2024-06-13 07:07:39.859 19829-19999 INFO e I [libxmtp] 0e922b3d7ac597d11df41ccb34dbbdf82d2c6e454738d52cbe48e0ef05c604e8: Storing a transcript message with 1 members added and 0 members removed and 0 metadata changes 2024-06-13 07:07:39.864 19829-19987 INFO e I [libxmtp] Received conversation streaming payload 2024-06-13 07:07:39.883 19829-19999 XMTPModule e V updateGroupName 2024-06-13 07:07:39.891 19829-19987 INFO e I [libxmtp] closing stream 2024-06-13 07:07:39.894 19829-19987 INFO e I [libxmtp] Received message streaming payload 2024-06-13 07:07:39.896 19829-19987 INFO e I [libxmtp] [cff60102f491735783d93cae79d11891b93a8f389e0de3a54f7868cc9d38e0b6] processing external message 2024-06-13 07:07:39.896 19829-19987 ERROR e E [libxmtp] Wrong Epoch: message.epoch() 0 != 1 self.group_context().epoch() 2024-06-13 07:07:39.900 19829-20204 INFO e I [libxmtp] [0e922b3d7ac597d11df41ccb34dbbdf82d2c6e454738d52cbe48e0ef05c604e8] Validating commit for intent 2. Message timestamp: 1718287661508577000 2024-06-13 07:07:39.901 19829-20204 INFO e I [libxmtp] Group context extensions proposal found: GroupMembership { members: {"cff60102f491735783d93cae79d11891b93a8f389e0de3a54f7868cc9d38e0b6": 2964, "0e922b3d7ac597d11df41ccb34dbbdf82d2c6e454738d52cbe48e0ef05c604e8": 2963} } 2024-06-13 07:07:39.902 19829-20204 INFO e I [libxmtp] [0e922b3d7ac597d11df41ccb34dbbdf82d2c6e454738d52cbe48e0ef05c604e8] merging pending commit for intent 2 2024-06-13 07:07:39.903 19829-20204 INFO e I [libxmtp] 0e922b3d7ac597d11df41ccb34dbbdf82d2c6e454738d52cbe48e0ef05c604e8: Storing a transcript message with 0 members added and 0 members removed and 1 metadata changes 2024-06-13 07:07:39.904 19829-19987 INFO e I [libxmtp] [cff60102f491735783d93cae79d11891b93a8f389e0de3a54f7868cc9d38e0b6] processing external message 2024-06-13 07:07:39.905 19829-19987 ERROR e E [libxmtp] Wrong Epoch: message.epoch() 0 != 1 self.group_context().epoch() 2024-06-13 07:07:39.906 19829-19987 INFO e I [libxmtp] [cff60102f491735783d93cae79d11891b93a8f389e0de3a54f7868cc9d38e0b6] processing external message 2024-06-13 07:07:39.907 19829-19987 INFO e I [libxmtp] [cff60102f491735783d93cae79d11891b93a8f389e0de3a54f7868cc9d38e0b6] extracted sender inbox id: 0e922b3d7ac597d11df41ccb34dbbdf82d2c6e454738d52cbe48e0ef05c604e8 2024-06-13 07:07:39.908 19829-20204 XMTPModule e V sendMessageToGroup 2024-06-13 07:07:39.914 19829-19987 INFO e I [libxmtp] [cff60102f491735783d93cae79d11891b93a8f389e0de3a54f7868cc9d38e0b6] received staged commit. Merging and clearing any pending commits 2024-06-13 07:07:39.914 19829-19987 INFO e I [libxmtp] Group context extensions proposal found: GroupMembership { members: {"cff60102f491735783d93cae79d11891b93a8f389e0de3a54f7868cc9d38e0b6": 2964, "0e922b3d7ac597d11df41ccb34dbbdf82d2c6e454738d52cbe48e0ef05c604e8": 2963} } 2024-06-13 07:07:39.915 19829-19987 INFO e I [libxmtp] [cff60102f491735783d93cae79d11891b93a8f389e0de3a54f7868cc9d38e0b6] staged commit is valid 2024-06-13 07:07:39.916 19829-19987 INFO e I [libxmtp] [cff60102f491735783d93cae79d11891b93a8f389e0de3a54f7868cc9d38e0b6] staged commit merged successfully 2024-06-13 07:07:39.917 19829-19987 INFO e I [libxmtp] cff60102f491735783d93cae79d11891b93a8f389e0de3a54f7868cc9d38e0b6: Storing a transcript message with 0 members added and 0 members removed and 1 metadata changes 2024-06-13 07:07:39.918 19829-19987 ERROR e E [libxmtp] Message processing errors: [OpenMlsProcessMessage(ValidationError(WrongEpoch))] 2024-06-13 07:07:39.919 19829-19987 ERROR e E [libxmtp] receive error ReceiveErrors([OpenMlsProcessMessage(ValidationError(WrongEpoch))]) 2024-06-13 07:07:39.920 19829-19987 INFO e I [libxmtp] Skipped message streaming payload 2024-06-13 07:07:39.921 19829-19987 INFO e I [libxmtp] Received message streaming payload 2024-06-13 07:07:39.922 19829-19987 INFO e I [libxmtp] [cff60102f491735783d93cae79d11891b93a8f389e0de3a54f7868cc9d38e0b6] processing external message 2024-06-13 07:07:39.922 19829-19987 ERROR e E [libxmtp] Wrong Epoch: message.epoch() 1 != 2 self.group_context().epoch() 2024-06-13 07:07:39.928 19829-19892 ReactNativeJS e I message received 2024-06-13 07:07:39.937 19829-19987 INFO e I [libxmtp] Received message streaming payload 2024-06-13 07:07:39.939 19829-19987 INFO e I [libxmtp] [cff60102f491735783d93cae79d11891b93a8f389e0de3a54f7868cc9d38e0b6] processing external message 2024-06-13 07:07:39.940 19829-19987 INFO e I [libxmtp] [cff60102f491735783d93cae79d11891b93a8f389e0de3a54f7868cc9d38e0b6] extracted sender inbox id: 0e922b3d7ac597d11df41ccb34dbbdf82d2c6e454738d52cbe48e0ef05c604e8 2024-06-13 07:07:39.940 19829-19987 INFO e I [libxmtp] [cff60102f491735783d93cae79d11891b93a8f389e0de3a54f7868cc9d38e0b6] decoding application message 2024-06-13 07:07:39.941 19829-19892 ReactNativeJS e I sent group message 2024-06-13 07:07:39.941 19829-22304 XMTPModule e V syncGroups 2024-06-13 07:07:39.948 19829-19892 ReactNativeJS e I message received 2024-06-13 07:07:39.951 19829-22302 XMTPModule e V listGroups 2024-06-13 07:07:39.960 19829-22302 XMTPModule e V syncGroup 2024-06-13 07:07:39.966 19829-22302 INFO e I [libxmtp] [cff60102f491735783d93cae79d11891b93a8f389e0de3a54f7868cc9d38e0b6] processing external message 2024-06-13 07:07:39.966 19829-22302 ERROR e E [libxmtp] Wrong Epoch: message.epoch() 2 > 1 self.group_context().epoch() 2024-06-13 07:07:39.967 19829-22302 ERROR e E [libxmtp] Message processing errors: [OpenMlsProcessMessage(ValidationError(WrongEpoch))] 2024-06-13 07:07:39.968 19829-22302 ERROR e E [libxmtp] receive error ReceiveErrors([OpenMlsProcessMessage(ValidationError(WrongEpoch))]) 2024-06-13 07:07:39.969 19829-22302 XMTPModule e V groupMessages 2024-06-13 07:07:39.979 19829-22302 XMTPModule e V sendMessageToGroup 2024-06-13 07:07:40.002 19829-19987 INFO e I [libxmtp] Received message streaming payload 2024-06-13 07:07:40.005 19829-22302 XMTPModule e V sendMessageToGroup 2024-06-13 07:07:40.007 19829-19892 ReactNativeJS e I message received 2024-06-13 07:07:40.022 19829-19987 INFO e I [libxmtp] Received message streaming payload 2024-06-13 07:07:40.023 19829-19987 INFO e I [libxmtp] [cff60102f491735783d93cae79d11891b93a8f389e0de3a54f7868cc9d38e0b6] processing external message 2024-06-13 07:07:40.024 19829-19987 ERROR e E [libxmtp] This is the wrong ratchet type. 2024-06-13 07:07:40.024 19829-22302 XMTPModule e V syncGroup 2024-06-13 07:07:40.025 19829-19987 ERROR e E [libxmtp] Ciphertext generation out of bounds 1 RatchetTypeError 2024-06-13 07:07:40.028 19829-19987 INFO e I [libxmtp] [cff60102f491735783d93cae79d11891b93a8f389e0de3a54f7868cc9d38e0b6] processing external message 2024-06-13 07:07:40.028 19829-19987 ERROR e E [libxmtp] Wrong Epoch: message.epoch() 2 > 1 self.group_context().epoch() 2024-06-13 07:07:40.030 19829-19987 ERROR e E [libxmtp] Message processing errors: [OpenMlsProcessMessage(ValidationError(WrongEpoch))] 2024-06-13 07:07:40.030 19829-19987 ERROR e E [libxmtp] receive error ReceiveErrors([OpenMlsProcessMessage(ValidationError(WrongEpoch))]) 2024-06-13 07:07:40.036 19829-19892 ReactNativeJS e I message received 2024-06-13 07:07:40.040 19829-22302 INFO e I [libxmtp] [0e922b3d7ac597d11df41ccb34dbbdf82d2c6e454738d52cbe48e0ef05c604e8] processing external message 2024-06-13 07:07:40.040 19829-22302 INFO e I [libxmtp] [0e922b3d7ac597d11df41ccb34dbbdf82d2c6e454738d52cbe48e0ef05c604e8] processing external message 2024-06-13 07:07:40.041 19829-22302 ERROR e E [libxmtp] Message processing errors: [OpenMlsProcessMessage(ValidationError(UnableToDecrypt(AeadError))), OpenMlsProcessMessage(ValidationError(UnableToDecrypt(AeadError)))] 2024-06-13 07:07:40.042 19829-22302 ERROR e E [libxmtp] receive error ReceiveErrors([OpenMlsProcessMessage(ValidationError(UnableToDecrypt(AeadError))), OpenMlsProcessMessage(ValidationError(UnableToDecrypt(AeadError)))]) 2024-06-13 07:07:40.044 19829-22302 XMTPModule e V groupMessages ```
neekolas commented 3 weeks ago

It feels like we are getting somewhere.

Maybe it would be helpful to compare the logs with a run through the same actions that doesn't fork the group state. Then we can see what's different. Some Wrong epoch errors are harmless and expected, since new members will read all messages in a group starting at the beginning (before they joined).

It would also be helpful to start logging hashes of the envelope payloads all over the place so we can see exactly which messages are failing to process. That way when a message fails to decrypt we can tie it back to when it was sent and figure out what intent it was related to (adding the member, changing the name) and whether or not it was a retry.

neekolas commented 3 weeks ago

One other thing I could see being helpful to log is any transaction rollbacks. Want to make super sure that messages which appear to have been processed successfully aren't rolling back at the last minute silently somewhere.

Maybe we just throw a line somewhere in the Storage transaction and transaction_async functions

cameronvoell commented 3 weeks ago

New error log, with envelope hashes and messages on transaction commits and rollbacks, replaced inboxIDs with CREATOR and USER2 for readability:

logs
``` 2024-06-13 08:41:12.921 29161-29335 INFO I [libxmtp] Getting inbox_ids for account addresses: ["0x923c22e0b8f53942dd7f79e676aa0d756f67c12b"] 2024-06-13 08:41:12.927 29161-29281 TrafficStats D tagSocket(222) with statsTag=0xffffffff, statsUid=-1 2024-06-13 08:41:12.929 29161-29333 INFO I [libxmtp] creating group with account addresses: 0x923C22e0b8f53942dd7f79e676aA0D756f67C12b 2024-06-13 08:41:12.930 29161-29333 INFO I [libxmtp] creating group 2024-06-13 08:41:12.947 29161-29333 INFO I [libxmtp] Getting inbox_ids for account addresses: ["0x923c22e0b8f53942dd7f79e676aa0d756f67c12b"] 2024-06-13 08:41:12.957 29161-29335 INFO I [libxmtp] old group membership: {"CREATOR": 0} 2024-06-13 08:41:12.957 29161-29335 INFO I [libxmtp] updated group membership: {"CREATOR": 2995, "USER2": 2996} 2024-06-13 08:41:12.976 29161-29335 INFO I [libxmtp] Transaction Async beginning 2024-06-13 08:41:12.977 29161-29335 INFO I [libxmtp] client [CREATOR] is about to process own envelope [3111] 2024-06-13 08:41:12.977 29161-29335 INFO I [libxmtp] envelope [3111] is equal to intent [1] 2024-06-13 08:41:12.978 29161-29335 INFO I [libxmtp] [CREATOR] Validating commit for intent 1. Message timestamp: 1718293274607845000 2024-06-13 08:41:12.978 29161-29335 INFO I [libxmtp] Group context extensions proposal found: GroupMembership { members: {"USER2": 2996, "CREATOR": 2995} } 2024-06-13 08:41:12.979 29161-29335 INFO I [libxmtp] [CREATOR] merging pending commit for intent 1 2024-06-13 08:41:12.979 29161-29335 INFO I [libxmtp] CREATOR: Storing a transcript message with 1 members added and 0 members removed and 0 metadata changes 2024-06-13 08:41:12.980 29161-29335 INFO I [libxmtp] Transaction Async being committed 2024-06-13 08:41:12.986 29161-29321 INFO I [libxmtp] Received conversation streaming payload 2024-06-13 08:41:13.007 29161-29333 XMTPModule V updateGroupName 2024-06-13 08:41:13.013 29161-29321 INFO I [libxmtp] closing stream 2024-06-13 08:41:13.016 29161-29321 INFO I [libxmtp] Received message streaming payload 2024-06-13 08:41:13.017 29161-29321 INFO I [libxmtp] client [USER2] is about to process streamed envelope: [3111] 2024-06-13 08:41:13.017 29161-29321 INFO I [libxmtp] Transaction Async beginning 2024-06-13 08:41:13.018 29161-29321 INFO I [libxmtp] client [USER2] is about to process external envelope [3111] 2024-06-13 08:41:13.018 29161-29321 ERROR E [libxmtp] Wrong Epoch: message.epoch() 0 != 1 self.group_context().epoch() 2024-06-13 08:41:13.019 29161-29321 INFO I [libxmtp] Transaction Async being rolled back 2024-06-13 08:41:13.029 29161-29333 INFO I [libxmtp] Transaction Async beginning 2024-06-13 08:41:13.030 29161-29333 INFO I [libxmtp] client [CREATOR] is about to process own envelope [3112] 2024-06-13 08:41:13.030 29161-29333 INFO I [libxmtp] envelope [3112] is equal to intent [2] 2024-06-13 08:41:13.031 29161-29333 INFO I [libxmtp] [CREATOR] Validating commit for intent 2. Message timestamp: 1718293274657447000 2024-06-13 08:41:13.031 29161-29321 INFO I [libxmtp] Transaction Async beginning 2024-06-13 08:41:13.032 29161-29333 INFO I [libxmtp] Group context extensions proposal found: GroupMembership { members: {"CREATOR": 2995, "USER2": 2996} } 2024-06-13 08:41:13.033 29161-29321 INFO I [libxmtp] client [USER2] is about to process external envelope [3111] 2024-06-13 08:41:13.033 29161-29321 ERROR E [libxmtp] Wrong Epoch: message.epoch() 0 != 1 self.group_context().epoch() 2024-06-13 08:41:13.034 29161-29321 INFO I [libxmtp] Transaction Async being rolled back 2024-06-13 08:41:13.035 29161-29321 INFO I [libxmtp] Transaction Async beginning 2024-06-13 08:41:13.035 29161-29333 INFO I [libxmtp] [CREATOR] merging pending commit for intent 2 2024-06-13 08:41:13.036 29161-29321 INFO I [libxmtp] client [USER2] is about to process external envelope [3112] 2024-06-13 08:41:13.037 29161-29333 INFO I [libxmtp] CREATOR: Storing a transcript message with 0 members added and 0 members removed and 1 metadata changes 2024-06-13 08:41:13.037 29161-29333 INFO I [libxmtp] Transaction Async being committed 2024-06-13 08:41:13.038 29161-29321 INFO I [libxmtp] [USER2] extracted sender inbox id: CREATOR 2024-06-13 08:41:13.039 29161-29321 INFO I [libxmtp] [USER2] received staged commit. Merging and clearing any pending commits 2024-06-13 08:41:13.040 29161-29321 INFO I [libxmtp] Group context extensions proposal found: GroupMembership { members: {"CREATOR": 2995, "USER2": 2996} } 2024-06-13 08:41:13.041 29161-29321 INFO I [libxmtp] [USER2] staged commit is valid 2024-06-13 08:41:13.042 29161-29321 INFO I [libxmtp] [USER2] staged commit merged successfully 2024-06-13 08:41:13.042 29161-29333 XMTPModule V sendMessageToGroup 2024-06-13 08:41:13.043 29161-29321 INFO I [libxmtp] USER2: Storing a transcript message with 0 members added and 0 members removed and 1 metadata changes 2024-06-13 08:41:13.044 29161-29321 INFO I [libxmtp] Transaction Async being committed 2024-06-13 08:41:13.046 29161-29321 ERROR E [libxmtp] Message processing errors: [OpenMlsProcessMessage(ValidationError(WrongEpoch))] 2024-06-13 08:41:13.046 29161-29321 ERROR E [libxmtp] receive error ReceiveErrors([OpenMlsProcessMessage(ValidationError(WrongEpoch))]) 2024-06-13 08:41:13.048 29161-29321 INFO I [libxmtp] Skipped message streaming payload 2024-06-13 08:41:13.048 29161-29321 INFO I [libxmtp] Received message streaming payload 2024-06-13 08:41:13.049 29161-29321 INFO I [libxmtp] client [USER2] is about to process streamed envelope: [3112] 2024-06-13 08:41:13.049 29161-29321 INFO I [libxmtp] Transaction Async beginning 2024-06-13 08:41:13.050 29161-29321 INFO I [libxmtp] client [USER2] is about to process external envelope [3112] 2024-06-13 08:41:13.051 29161-29321 ERROR E [libxmtp] Wrong Epoch: message.epoch() 1 != 2 self.group_context().epoch() 2024-06-13 08:41:13.052 29161-29321 INFO I [libxmtp] Transaction Async being rolled back 2024-06-13 08:41:13.060 29161-29224 ReactNativeJS I message received 2024-06-13 08:41:13.069 29161-29321 INFO I [libxmtp] Received message streaming payload 2024-06-13 08:41:13.070 29161-29321 INFO I [libxmtp] client [USER2] is about to process streamed envelope: [3113] 2024-06-13 08:41:13.070 29161-29321 INFO I [libxmtp] Transaction Async beginning 2024-06-13 08:41:13.072 29161-29224 ReactNativeJS I sent group message 2024-06-13 08:41:13.072 29161-29335 XMTPModule V syncGroups 2024-06-13 08:41:13.074 29161-29321 INFO I [libxmtp] client [USER2] is about to process external envelope [3113] 2024-06-13 08:41:13.075 29161-29321 INFO I [libxmtp] [USER2] extracted sender inbox id: CREATOR 2024-06-13 08:41:13.076 29161-29321 INFO I [libxmtp] [USER2] decoding application message 2024-06-13 08:41:13.077 29161-29321 INFO I [libxmtp] Transaction Async being committed 2024-06-13 08:41:13.081 29161-29224 ReactNativeJS I message received 2024-06-13 08:41:13.085 29161-29335 INFO I [libxmtp] Transaction Async beginning 2024-06-13 08:41:13.089 29161-29335 INFO I [libxmtp] Transaction Async being committed 2024-06-13 08:41:13.091 29161-29335 XMTPModule V listGroups 2024-06-13 08:41:13.101 29161-29335 XMTPModule V syncGroup 2024-06-13 08:41:13.108 29161-29335 INFO I [libxmtp] Transaction Async beginning 2024-06-13 08:41:13.109 29161-29335 INFO I [libxmtp] client [USER2] is about to process external envelope [3113] 2024-06-13 08:41:13.109 29161-29335 ERROR E [libxmtp] Wrong Epoch: message.epoch() 2 > 1 self.group_context().epoch() 2024-06-13 08:41:13.110 29161-29335 INFO I [libxmtp] Transaction Async being rolled back 2024-06-13 08:41:13.111 29161-29335 ERROR E [libxmtp] Message processing errors: [OpenMlsProcessMessage(ValidationError(WrongEpoch))] 2024-06-13 08:41:13.111 29161-29335 ERROR E [libxmtp] receive error ReceiveErrors([OpenMlsProcessMessage(ValidationError(WrongEpoch))]) 2024-06-13 08:41:13.113 29161-29335 XMTPModule V groupMessages 2024-06-13 08:41:13.123 29161-29335 XMTPModule V sendMessageToGroup 2024-06-13 08:41:13.150 29161-29321 INFO I [libxmtp] Received message streaming payload 2024-06-13 08:41:13.151 29161-29321 INFO I [libxmtp] client [USER2] is about to process streamed envelope: [3114] 2024-06-13 08:41:13.152 29161-29321 INFO I [libxmtp] Transaction Async beginning 2024-06-13 08:41:13.153 29161-29321 INFO I [libxmtp] client [USER2] is about to process own envelope [3114] 2024-06-13 08:41:13.153 29161-29333 XMTPModule V sendMessageToGroup 2024-06-13 08:41:13.154 29161-29321 INFO I [libxmtp] envelope [3114] is equal to intent [1] 2024-06-13 08:41:13.154 29161-29321 INFO I [libxmtp] Transaction Async being committed 2024-06-13 08:41:13.160 29161-29224 ReactNativeJS I message received 2024-06-13 08:41:13.172 29161-29321 INFO I [libxmtp] Received message streaming payload 2024-06-13 08:41:13.173 29161-29321 INFO I [libxmtp] client [USER2] is about to process streamed envelope: [3115] 2024-06-13 08:41:13.174 29161-29321 INFO I [libxmtp] Transaction Async beginning 2024-06-13 08:41:13.175 29161-29321 INFO I [libxmtp] client [USER2] is about to process own envelope [3115] 2024-06-13 08:41:13.176 29161-29321 INFO I [libxmtp] envelope [3115] is equal to intent [2] 2024-06-13 08:41:13.176 29161-29333 XMTPModule V syncGroup 2024-06-13 08:41:13.176 29161-29321 INFO I [libxmtp] Transaction Async being committed 2024-06-13 08:41:13.182 29161-29224 ReactNativeJS I message received 2024-06-13 08:41:13.185 29161-29333 INFO I [libxmtp] Transaction Async beginning 2024-06-13 08:41:13.185 29161-29333 INFO I [libxmtp] client [CREATOR] is about to process own envelope [3113] 2024-06-13 08:41:13.186 29161-29333 INFO I [libxmtp] envelope [3113] is equal to intent [3] 2024-06-13 08:41:13.189 29161-29333 INFO I [libxmtp] Transaction Async being committed 2024-06-13 08:41:13.191 29161-29333 INFO I [libxmtp] Transaction Async beginning 2024-06-13 08:41:13.191 29161-29333 INFO I [libxmtp] client [CREATOR] is about to process external envelope [3114] 2024-06-13 08:41:13.192 29161-29333 INFO I [libxmtp] Transaction Async being rolled back 2024-06-13 08:41:13.193 29161-29333 INFO I [libxmtp] Transaction Async beginning 2024-06-13 08:41:13.193 29161-29333 INFO I [libxmtp] client [CREATOR] is about to process external envelope [3115] 2024-06-13 08:41:13.194 29161-29333 INFO I [libxmtp] Transaction Async being rolled back 2024-06-13 08:41:13.194 29161-29333 ERROR E [libxmtp] Message processing errors: [OpenMlsProcessMessage(ValidationError(UnableToDecrypt(AeadError))), OpenMlsProcessMessage(ValidationError(UnableToDecrypt(AeadError)))] 2024-06-13 08:41:13.195 29161-29333 ERROR E [libxmtp] receive error ReceiveErrors([OpenMlsProcessMessage(ValidationError(UnableToDecrypt(AeadError))), OpenMlsProcessMessage(ValidationError(UnableToDecrypt(AeadError)))]) 2024-06-13 08:41:13.198 29161-29333 XMTPModule V groupMessages 2024-06-13 08:41:13.212 29161-29224 ReactNativeJS I 'message', 'xmtp.org/text:1.0', 'hello1' 2024-06-13 08:41:13.212 29161-29224 ReactNativeJS I 'message', 'xmtp.org/group_updated:1.0', 'Group Updated' 2024-06-13 08:41:13.213 29161-29224 ReactNativeJS I 'message', 'xmtp.org/group_updated:1.0', 'Group Updated ```