Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Send msg db locked fix #1484

Draft
wants to merge 12 commits into
base: main
Choose a base branch
from
Draft

Send msg db locked fix #1484

wants to merge 12 commits into from

Conversation

cameronvoell
Copy link
Contributor

No description provided.

@cameronvoell cameronvoell changed the title Pass in provider to update_consent_state Send msg db lock fix Jan 10, 2025
@cameronvoell cameronvoell changed the title Send msg db lock fix Send msg db locked fix Jan 10, 2025
@cameronvoell
Copy link
Contributor Author

test-logcat-2025-01-10_06-22-07.log

DB Locked still showing on most recent commit see log below

test code:

test('can message in a group', async () => {
  const [alixClient, boClient] = await createClients(2)

  // alix creates a group
  const alixGroup = await alixClient.conversations.newGroup([
    boClient.address,
  ])

  // alix can send messages
  await alixGroup.send('hello, world')

  // Database is locked error intermittently on the second send
  await alixGroup.send('gm')

  return true
})
logs 
01-10 06:23:10.086  7459  7659 V XMTPModule: sendMessage
01-10 06:23:10.086  7459  7659 D xmtpv3  : ThreadId(17) xmtp_mls::storage::encrypted_store::native: Pulling connection from pool, idle_connections=25, total_connections=25
01-10 06:23:10.086  7459  7659 D xmtpv3  : ThreadId(17) xmtp_mls::storage::encrypted_store::native: Pulling connection from pool, idle_connections=25, total_connections=25
01-10 06:23:10.086  7459  7659 D xmtpv3  : ThreadId(17) xmtp_mls::storage::sql_key_store: read Tree
01-10 06:23:10.086  7459  7659 D xmtpv3  : ThreadId(17) xmtp_mls::storage::sql_key_store: read_list ProposalQueueRefs
01-10 06:23:10.086  7459  7659 D xmtpv3  : ThreadId(17) xmtp_mls::storage::sql_key_store: read GroupContext
01-10 06:23:10.087  7459  7659 D xmtpv3  : ThreadId(17) xmtp_mls::storage::sql_key_store: read InterimTranscriptHash
01-10 06:23:10.087  7459  7659 D xmtpv3  : ThreadId(17) xmtp_mls::storage::sql_key_store: read ConfirmationTag
01-10 06:23:10.087  7459  7659 D xmtpv3  : ThreadId(17) xmtp_mls::storage::sql_key_store: read EpochSecrets
01-10 06:23:10.087  7459  7659 D xmtpv3  : ThreadId(17) xmtp_mls::storage::sql_key_store: read OwnLeafNodeIndex
01-10 06:23:10.087  7459  7659 D xmtpv3  : ThreadId(17) xmtp_mls::storage::sql_key_store: read MessageSecrets
01-10 06:23:10.087  7459  7659 D xmtpv3  : ThreadId(17) xmtp_mls::storage::sql_key_store: read ResumptionPskStore
01-10 06:23:10.087  7459  7659 D xmtpv3  : ThreadId(17) xmtp_mls::storage::sql_key_store: read MlsGroupJoinConfig
01-10 06:23:10.087  7459  7659 D xmtpv3  : ThreadId(17) xmtp_mls::storage::sql_key_store: own_leaf_nodes
01-10 06:23:10.087  7459  7659 D xmtpv3  : ThreadId(17) xmtp_mls::storage::sql_key_store: read_list OwnLeafNodes
01-10 06:23:10.087  7459  7659 D xmtpv3  : ThreadId(17) xmtp_mls::storage::sql_key_store: read GroupState
01-10 06:23:10.087  7459  7659 D xmtpv3  : ThreadId(17) xmtp_mls::storage::encrypted_store::native: Pulling connection from pool, idle_connections=25, total_connections=25
01-10 06:23:10.088  7459  7659 D xmtpv3  : ThreadId(17) xmtp_mls::groups: sending message inbox_id="5ba963badd8739fa3cf8bb0c3f7da5432fc1947df7faade72cfe3a8c1afafdc2"
01-10 06:23:10.088  7459  7659 D xmtpv3  : ThreadId(17) xmtp_mls::storage::encrypted_store::native: Pulling connection from pool, idle_connections=25, total_connections=25
01-10 06:23:10.088  7459  7659 D xmtpv3  : ThreadId(17) xmtp_mls::storage::encrypted_store::private: Transaction async beginning
01-10 06:23:10.088  7459  7659 D xmtpv3  : ThreadId(17) xmtp_mls::storage::sql_key_store: read Tree
01-10 06:23:10.088  7459  7659 D xmtpv3  : ThreadId(17) xmtp_mls::storage::sql_key_store: read_list ProposalQueueRefs
01-10 06:23:10.088  7459  7659 D xmtpv3  : ThreadId(17) xmtp_mls::storage::sql_key_store: read GroupContext
01-10 06:23:10.088  7459  7659 D xmtpv3  : ThreadId(17) xmtp_mls::storage::sql_key_store: read InterimTranscriptHash
01-10 06:23:10.088  7459  7659 D xmtpv3  : ThreadId(17) xmtp_mls::storage::sql_key_store: read ConfirmationTag
01-10 06:23:10.088  7459  7659 D xmtpv3  : ThreadId(17) xmtp_mls::storage::sql_key_store: read EpochSecrets
01-10 06:23:10.088  7459  7659 D xmtpv3  : ThreadId(17) xmtp_mls::storage::sql_key_store: read OwnLeafNodeIndex
01-10 06:23:10.088  7459  7659 D xmtpv3  : ThreadId(17) xmtp_mls::storage::sql_key_store: read MessageSecrets
01-10 06:23:10.088  7459  7659 D xmtpv3  : ThreadId(17) xmtp_mls::storage::sql_key_store: read ResumptionPskStore
01-10 06:23:10.088  7459  7659 D xmtpv3  : ThreadId(17) xmtp_mls::storage::sql_key_store: read MlsGroupJoinConfig
01-10 06:23:10.088  7459  7659 D xmtpv3  : ThreadId(17) xmtp_mls::storage::sql_key_store: own_leaf_nodes
01-10 06:23:10.088  7459  7659 D xmtpv3  : ThreadId(17) xmtp_mls::storage::sql_key_store: read_list OwnLeafNodes
01-10 06:23:10.088  7459  7659 D xmtpv3  : ThreadId(17) xmtp_mls::storage::sql_key_store: read GroupState
01-10 06:23:10.088  7459  7659 D xmtpv3  : ThreadId(17) xmtp_mls::identity_updates: Fetching identity updates for: ["e0a0f091145e8fba676f7c46c3a9e3ccb665d60d3259af1fdc124e034a5aa40e", "5ba963badd8739fa3cf8bb0c3f7da5432fc1947df7faade72cfe3a8c1afafdc2"]
01-10 06:23:10.088  7459  7642 D xmtpv3  : async-compat/tokio-1 tower::buffer::worker: service.ready=true processing request
01-10 06:23:10.088  7459  7642 D xmtpv3  : async-compat/tokio-1 Connection{peer=Client}: h2::codec::framed_write: send frame=Headers { stream_id: StreamId(6503), flags: (0x4: END_HEADERS) }
01-10 06:23:10.088  7459  7642 D xmtpv3  : async-compat/tokio-1 Connection{peer=Client}: h2::codec::framed_write: send frame=Data { stream_id: StreamId(6503) }
01-10 06:23:10.088  7459  7642 D xmtpv3  : async-compat/tokio-1 Connection{peer=Client}: h2::codec::framed_write: send frame=Data { stream_id: StreamId(6503), flags: (0x1: END_STREAM) }
01-10 06:23:10.096  7459  7642 D xmtpv3  : async-compat/tokio-1 Connection{peer=Client}: h2::codec::framed_read: received frame=WindowUpdate { stream_id: StreamId(0), size_increment: 147 }
01-10 06:23:10.096  7459  7642 D xmtpv3  : async-compat/tokio-1 Connection{peer=Client}: h2::codec::framed_read: received frame=Ping { ack: false, payload: [2, 4, 16, 16, 9, 14, 7, 7] }
01-10 06:23:10.096  7459  7642 D xmtpv3  : async-compat/tokio-1 Connection{peer=Client}: h2::codec::framed_write: send frame=Ping { ack: true, payload: [2, 4, 16, 16, 9, 14, 7, 7] }
01-10 06:23:10.096  7459  7642 D xmtpv3  : async-compat/tokio-1 Connection{peer=Client}: h2::codec::framed_read: received frame=Headers { stream_id: StreamId(6503), flags: (0x4: END_HEADERS) }
01-10 06:23:10.096  7459  7642 D xmtpv3  : async-compat/tokio-1 Connection{peer=Client}: h2::codec::framed_read: received frame=Data { stream_id: StreamId(6503) }
01-10 06:23:10.096  7459  7642 D xmtpv3  : async-compat/tokio-1 Connection{peer=Client}: h2::codec::framed_read: received frame=Headers { stream_id: StreamId(6503), flags: (0x5: END_HEADERS | END_STREAM) }
01-10 06:23:10.097  7459  7555 D xmtpv3  : ThreadId(06) xmtp_mls::storage::encrypted_store::private: Transaction beginning
01-10 06:23:10.097  7459  7555 D xmtpv3  : ThreadId(06) xmtp_mls::groups::intents: queued intent inbox_id="5ba963badd8739fa3cf8bb0c3f7da5432fc1947df7faade72cfe3a8c1afafdc2" intent_kind=SendMessage
01-10 06:23:10.097  7459  7555 D xmtpv3  : ThreadId(06) xmtp_mls::storage::encrypted_store::private: Transaction being committed
01-10 06:23:10.098  7459  7555 D xmtpv3  : ThreadId(06) sync_until_last_intent_resolved:sync_until_intent_resolved:sync_with_conn: xmtp_mls::storage::sql_key_store: read Tree
01-10 06:23:10.098  7459  7555 D xmtpv3  : ThreadId(06) sync_until_last_intent_resolved:sync_until_intent_resolved:sync_with_conn: xmtp_mls::storage::sql_key_store: read_list ProposalQueueRefs
01-10 06:23:10.098  7459  7555 D xmtpv3  : ThreadId(06) sync_until_last_intent_resolved:sync_until_intent_resolved:sync_with_conn: xmtp_mls::storage::sql_key_store: read GroupContext
01-10 06:23:10.098  7459  7555 D xmtpv3  : ThreadId(06) sync_until_last_intent_resolved:sync_until_intent_resolved:sync_with_conn: xmtp_mls::storage::sql_key_store: read InterimTranscriptHash
01-10 06:23:10.098  7459  7555 D xmtpv3  : ThreadId(06) sync_until_last_intent_resolved:sync_until_intent_resolved:sync_with_conn: xmtp_mls::storage::sql_key_store: read ConfirmationTag
01-10 06:23:10.098  7459  7555 D xmtpv3  : ThreadId(06) sync_until_last_intent_resolved:sync_until_intent_resolved:sync_with_conn: xmtp_mls::storage::sql_key_store: read EpochSecrets
01-10 06:23:10.098  7459  7555 D xmtpv3  : ThreadId(06) sync_until_last_intent_resolved:sync_until_intent_resolved:sync_with_conn: xmtp_mls::storage::sql_key_store: read OwnLeafNodeIndex
01-10 06:23:10.098  7459  7555 D xmtpv3  : ThreadId(06) sync_until_last_intent_resolved:sync_until_intent_resolved:sync_with_conn: xmtp_mls::storage::sql_key_store: read MessageSecrets
01-10 06:23:10.098  7459  7555 D xmtpv3  : ThreadId(06) sync_until_last_intent_resolved:sync_until_intent_resolved:sync_with_conn: xmtp_mls::storage::sql_key_store: read ResumptionPskStore
01-10 06:23:10.098  7459  7555 D xmtpv3  : ThreadId(06) sync_until_last_intent_resolved:sync_until_intent_resolved:sync_with_conn: xmtp_mls::storage::sql_key_store: read MlsGroupJoinConfig
01-10 06:23:10.098  7459  7555 D xmtpv3  : ThreadId(06) sync_until_last_intent_resolved:sync_until_intent_resolved:sync_with_conn: xmtp_mls::storage::sql_key_store: own_leaf_nodes
01-10 06:23:10.098  7459  7555 D xmtpv3  : ThreadId(06) sync_until_last_intent_resolved:sync_until_intent_resolved:sync_with_conn: xmtp_mls::storage::sql_key_store: read_list OwnLeafNodes
01-10 06:23:10.098  7459  7555 D xmtpv3  : ThreadId(06) sync_until_last_intent_resolved:sync_until_intent_resolved:sync_with_conn: xmtp_mls::storage::sql_key_store: read GroupState
01-10 06:23:10.098  7459  7555 D xmtpv3  : ThreadId(06) sync_until_last_intent_resolved:sync_until_intent_resolved:sync_with_conn: xmtp_mls::storage::sql_key_store: write MessageSecrets
01-10 06:23:10.098  7459  7555 D xmtpv3  : ThreadId(06) sync_until_last_intent_resolved:sync_until_intent_resolved:sync_with_conn: xmtp_mls::groups::mls_sync: client [5ba963badd8739fa3cf8bb0c3f7da5432fc1947df7faade72cfe3a8c1afafdc2] set stored intent [7] to state `published` inbox_id="5ba963badd8739fa3cf8bb0c3f7da5432fc1947df7faade72cfe3a8c1afafdc2" installation_id=65fe34f132880bf6fb6f3db79d6c074c3a94b0a315ca068cd761c937db0c36cd intent.id=7 intent.kind=SendMessage group_id="f5e1a4bd666888496d280fef2005c225"
01-10 06:23:10.098  7459  7555 D xmtpv3  : ThreadId(06) sync_until_last_intent_resolved:sync_until_intent_resolved:sync_with_conn: xmtp_mls::storage::encrypted_store::native: Pulling connection from pool, idle_connections=24, total_connections=25
01-10 06:23:10.098  7459  7555 D xmtpv3  : ThreadId(06) sync_until_last_intent_resolved:sync_until_intent_resolved:sync_with_conn: xmtp_mls::api::mls: sending [1] group messages inbox_id="5ba963badd8739fa3cf8bb0c3f7da5432fc1947df7faade72cfe3a8c1afafdc2"
01-10 06:23:10.098  7459  7642 D xmtpv3  : async-compat/tokio-1 sync_until_last_intent_resolved:sync_until_intent_resolved:sync_with_conn: tower::buffer::worker: service.ready=true processing request
01-10 06:23:10.099  7459  7642 D xmtpv3  : async-compat/tokio-1 Connection{peer=Client}: h2::codec::framed_write: send frame=Headers { stream_id: StreamId(6505), flags: (0x4: END_HEADERS) }
01-10 06:23:10.099  7459  7642 D xmtpv3  : async-compat/tokio-1 Connection{peer=Client}: h2::codec::framed_write: send frame=Data { stream_id: StreamId(6505) }
01-10 06:23:10.099  7459  7642 D xmtpv3  : async-compat/tokio-1 Connection{peer=Client}: h2::codec::framed_write: send frame=Data { stream_id: StreamId(6505), flags: (0x1: END_STREAM) }
01-10 06:23:10.100  7459  7642 D xmtpv3  : async-compat/tokio-1 Connection{peer=Client}: h2::codec::framed_read: received frame=WindowUpdate { stream_id: StreamId(0), size_increment: 272 }
01-10 06:23:10.101  7459  7642 D xmtpv3  : async-compat/tokio-1 Connection{peer=Client}: h2::codec::framed_read: received frame=Ping { ack: false, payload: [2, 4, 16, 16, 9, 14, 7, 7] }
01-10 06:23:10.101  7459  7642 D xmtpv3  : async-compat/tokio-1 Connection{peer=Client}: h2::codec::framed_write: send frame=Ping { ack: true, payload: [2, 4, 16, 16, 9, 14, 7, 7] }
01-10 06:23:10.103  7459  7642 D xmtpv3  : async-compat/tokio-1 Connection{peer=Client}: h2::codec::framed_read: received frame=Headers { stream_id: StreamId(6505), flags: (0x4: END_HEADERS) }
01-10 06:23:10.103  7459  7642 D xmtpv3  : async-compat/tokio-1 Connection{peer=Client}: h2::codec::framed_read: received frame=Data { stream_id: StreamId(6505) }
01-10 06:23:10.103  7459  7642 D xmtpv3  : async-compat/tokio-1 Connection{peer=Client}: h2::codec::framed_read: received frame=Headers { stream_id: StreamId(6505), flags: (0x5: END_HEADERS | END_STREAM) }
01-10 06:23:10.104  7459  7659 I xmtpv3  : ThreadId(17) sync_until_last_intent_resolved:sync_until_intent_resolved:sync_with_conn: xmtp_mls::groups::mls_sync: [5ba963badd8739fa3cf8bb0c3f7da5432fc1947df7faade72cfe3a8c1afafdc2] published intent [7] of type [SendMessage] intent.id=7 intent.kind=SendMessage inbox_id="5ba963badd8739fa3cf8bb0c3f7da5432fc1947df7faade72cfe3a8c1afafdc2" installation_id=65fe34f132880bf6fb6f3db79d6c074c3a94b0a315ca068cd761c937db0c36cd group_id="f5e1a4bd666888496d280fef2005c225"
01-10 06:23:10.104  7459  7659 D xmtpv3  : ThreadId(17) sync_until_last_intent_resolved:sync_until_intent_resolved:sync_with_conn:receive: xmtp_mls::api::mls: query group messages group_id="f5e1a4bd666888496d280fef2005c225" id_cursor=36383 inbox_id="5ba963badd8739fa3cf8bb0c3f7da5432fc1947df7faade72cfe3a8c1afafdc2"
01-10 06:23:10.104  7459  7642 D xmtpv3  : async-compat/tokio-1 sync_until_last_intent_resolved:sync_until_intent_resolved:sync_with_conn:receive: tower::buffer::worker: service.ready=true processing request
01-10 06:23:10.104  7459  7642 D xmtpv3  : async-compat/tokio-1 Connection{peer=Client}: h2::codec::framed_write: send frame=Headers { stream_id: StreamId(6507), flags: (0x4: END_HEADERS) }
01-10 06:23:10.104  7459  7642 D xmtpv3  : async-compat/tokio-1 Connection{peer=Client}: h2::codec::framed_write: send frame=Data { stream_id: StreamId(6507) }
01-10 06:23:10.104  7459  7642 D xmtpv3  : async-compat/tokio-1 Connection{peer=Client}: h2::codec::framed_write: send frame=Data { stream_id: StreamId(6507), flags: (0x1: END_STREAM) }
01-10 06:23:10.105  7459  7642 D xmtpv3  : async-compat/tokio-1 Connection{peer=Client}: h2::codec::framed_read: received frame=WindowUpdate { stream_id: StreamId(0), size_increment: 33 }
01-10 06:23:10.105  7459  7642 D xmtpv3  : async-compat/tokio-1 Connection{peer=Client}: h2::codec::framed_read: received frame=Ping { ack: false, payload: [2, 4, 16, 16, 9, 14, 7, 7] }
01-10 06:23:10.105  7459  7642 D xmtpv3  : async-compat/tokio-1 Connection{peer=Client}: h2::codec::framed_write: send frame=Ping { ack: true, payload: [2, 4, 16, 16, 9, 14, 7, 7] }
01-10 06:23:10.105  7459  7642 D xmtpv3  : async-compat/tokio-1 Connection{peer=Client}: h2::codec::framed_read: received frame=Headers { stream_id: StreamId(6507), flags: (0x4: END_HEADERS) }
01-10 06:23:10.106  7459  7642 D xmtpv3  : async-compat/tokio-1 Connection{peer=Client}: h2::codec::framed_read: received frame=Data { stream_id: StreamId(6507) }
01-10 06:23:10.106  7459  7642 D xmtpv3  : async-compat/tokio-1 Connection{peer=Client}: h2::codec::framed_read: received frame=Headers { stream_id: StreamId(6507), flags: (0x5: END_HEADERS | END_STREAM) }
01-10 06:23:10.106  7459  7659 D xmtpv3  : ThreadId(17) sync_until_last_intent_resolved:sync_until_intent_resolved:sync_with_conn:receive: xmtp_mls::storage::encrypted_store::private: Transaction async beginning
01-10 06:23:10.106  7459  7659 I xmtpv3  : ThreadId(17) sync_until_last_intent_resolved:sync_until_intent_resolved:sync_with_conn:receive: xmtp_mls::groups::mls_sync: Processing envelope with hash "152accf0ed5f0d4f27d73725a1cc3b50c6fd6b64cbf9ccbf716688f2b46c3aa5" inbox_id="5ba963badd8739fa3cf8bb0c3f7da5432fc1947df7faade72cfe3a8c1afafdc2" installation_id=65fe34f132880bf6fb6f3db79d6c074c3a94b0a315ca068cd761c937db0c36cd group_id="f5e1a4bd666888496d280fef2005c225" msg_id=36386
01-10 06:23:10.106  7459  7659 I xmtpv3  : ThreadId(17) sync_until_last_intent_resolved:sync_until_intent_resolved:sync_with_conn:receive: xmtp_mls::groups::mls_sync: client [5ba963badd8739fa3cf8bb0c3f7da5432fc1947df7faade72cfe3a8c1afafdc2] is about to process own envelope [36386] for intent [7] inbox_id="5ba963badd8739fa3cf8bb0c3f7da5432fc1947df7faade72cfe3a8c1afafdc2" installation_id=65fe34f132880bf6fb6f3db79d6c074c3a94b0a315ca068cd761c937db0c36cd group_id="f5e1a4bd666888496d280fef2005c225" msg_id=36386 intent_id=7 intent.kind=SendMessage
01-10 06:23:10.106  7459  7659 D xmtpv3  : ThreadId(17) sync_until_last_intent_resolved:sync_until_intent_resolved:sync_with_conn:receive: xmtp_mls::storage::sql_key_store: read Tree
01-10 06:23:10.106  7459  7659 D xmtpv3  : ThreadId(17) sync_until_last_intent_resolved:sync_until_intent_resolved:sync_with_conn:receive: xmtp_mls::storage::sql_key_store: read_list ProposalQueueRefs
01-10 06:23:10.106  7459  7659 D xmtpv3  : ThreadId(17) sync_until_last_intent_resolved:sync_until_intent_resolved:sync_with_conn:receive: xmtp_mls::storage::sql_key_store: read GroupContext
01-10 06:23:10.106  7459  7659 D xmtpv3  : ThreadId(17) sync_until_last_intent_resolved:sync_until_intent_resolved:sync_with_conn:receive: xmtp_mls::storage::sql_key_store: read InterimTranscriptHash
01-10 06:23:10.107  7459  7659 D xmtpv3  : ThreadId(17) sync_until_last_intent_resolved:sync_until_intent_resolved:sync_with_conn:receive: xmtp_mls::storage::sql_key_store: read ConfirmationTag
01-10 06:23:10.107  7459  7659 D xmtpv3  : ThreadId(17) sync_until_last_intent_resolved:sync_until_intent_resolved:sync_with_conn:receive: xmtp_mls::storage::sql_key_store: read EpochSecrets
01-10 06:23:10.107  7459  7659 D xmtpv3  : ThreadId(17) sync_until_last_intent_resolved:sync_until_intent_resolved:sync_with_conn:receive: xmtp_mls::storage::sql_key_store: read OwnLeafNodeIndex
01-10 06:23:10.107  7459  7659 D xmtpv3  : ThreadId(17) sync_until_last_intent_resolved:sync_until_intent_resolved:sync_with_conn:receive: xmtp_mls::storage::sql_key_store: read MessageSecrets
01-10 06:23:10.107  7459  7659 D xmtpv3  : ThreadId(17) sync_until_last_intent_resolved:sync_until_intent_resolved:sync_with_conn:receive: xmtp_mls::storage::sql_key_store: read ResumptionPskStore
01-10 06:23:10.107  7459  7659 D xmtpv3  : ThreadId(17) sync_until_last_intent_resolved:sync_until_intent_resolved:sync_with_conn:receive: xmtp_mls::storage::sql_key_store: read MlsGroupJoinConfig
01-10 06:23:10.107  7459  7659 D xmtpv3  : ThreadId(17) sync_until_last_intent_resolved:sync_until_intent_resolved:sync_with_conn:receive: xmtp_mls::storage::sql_key_store: own_leaf_nodes
01-10 06:23:10.107  7459  7659 D xmtpv3  : ThreadId(17) sync_until_last_intent_resolved:sync_until_intent_resolved:sync_with_conn:receive: xmtp_mls::storage::sql_key_store: read_list OwnLeafNodes
01-10 06:23:10.107  7459  7659 D xmtpv3  : ThreadId(17) sync_until_last_intent_resolved:sync_until_intent_resolved:sync_with_conn:receive: xmtp_mls::storage::sql_key_store: read GroupState
01-10 06:23:10.107  7459  7659 D xmtpv3  : ThreadId(17) sync_until_last_intent_resolved:sync_until_intent_resolved:sync_with_conn:receive: xmtp_mls::groups::mls_sync: [5ba963badd8739fa3cf8bb0c3f7da5432fc1947df7faade72cfe3a8c1afafdc2]-[f5e1a4bd666888496d280fef2005c225] processing own message for intent 7 / SendMessage, message_epoch: 1 inbox_id="5ba963badd8739fa3cf8bb0c3f7da5432fc1947df7faade72cfe3a8c1afafdc2" installation_id=65fe34f132880bf6fb6f3db79d6c074c3a94b0a315ca068cd761c937db0c36cd group_id="f5e1a4bd666888496d280fef2005c225" msg_id=36386 intent.id=7 intent.kind=SendMessage
01-10 06:23:10.108  7459  7659 W xmtpv3  : ThreadId(17) sync_until_last_intent_resolved:sync_until_intent_resolved:sync_with_conn:receive: xmtp_mls::storage::encrypted_store::private: More than 1 strong connection references still exist during async transaction
01-10 06:23:10.108  7459  7659 D xmtpv3  : ThreadId(17) sync_until_last_intent_resolved:sync_until_intent_resolved:sync_with_conn:receive: xmtp_mls::storage::encrypted_store::private: Transaction async being committed
01-10 06:23:10.108  7459  7659 I xmtpv3  : ThreadId(17) sync_until_last_intent_resolved:sync_until_intent_resolved:sync_with_conn:receive: xmtp_mls::groups::mls_sync: Transaction completed successfully: process for group [f5e1a4bd666888496d280fef2005c225] envelope cursor[36386]
01-10 06:23:10.108  7459  7659 W xmtpv3  : ThreadId(17) xmtp_mls::storage::encrypted_store::private: More than 1 strong connection references still exist during async transaction
01-10 06:23:10.108  7459  7642 E xmtpv3  : async-compat/tokio-1 xmtp_mls::groups::device_sync: Outgoing preference update [ConsentUpdate(StoredConsentRecord { entity_type: ConversationId, state: Allowed, entity: "f5e1a4bd666888496d280fef2005c225" })]
01-10 06:23:10.108  7459  7642 D xmtpv3  : async-compat/tokio-1 xmtp_mls::storage::encrypted_store::native: Pulling connection from pool, idle_connections=24, total_connections=25
01-10 06:23:10.108  7459  7642 D xmtpv3  : async-compat/tokio-1 sync_with_conn: xmtp_mls::storage::sql_key_store: read Tree
01-10 06:23:10.108  7459  7642 D xmtpv3  : async-compat/tokio-1 sync_with_conn: xmtp_mls::storage::sql_key_store: read_list ProposalQueueRefs
01-10 06:23:10.108  7459  7642 D xmtpv3  : async-compat/tokio-1 sync_with_conn: xmtp_mls::storage::sql_key_store: read GroupContext
01-10 06:23:10.108  7459  7642 D xmtpv3  : async-compat/tokio-1 sync_with_conn: xmtp_mls::storage::sql_key_store: read InterimTranscriptHash
01-10 06:23:10.108  7459  7642 D xmtpv3  : async-compat/tokio-1 sync_with_conn: xmtp_mls::storage::sql_key_store: read ConfirmationTag
01-10 06:23:10.108  7459  7642 D xmtpv3  : async-compat/tokio-1 sync_with_conn: xmtp_mls::storage::sql_key_store: read EpochSecrets
01-10 06:23:10.108  7459  7642 D xmtpv3  : async-compat/tokio-1 sync_with_conn: xmtp_mls::storage::sql_key_store: read OwnLeafNodeIndex
01-10 06:23:10.108  7459  7642 D xmtpv3  : async-compat/tokio-1 sync_with_conn: xmtp_mls::storage::sql_key_store: read MessageSecrets
01-10 06:23:10.109  7459  7642 D xmtpv3  : async-compat/tokio-1 sync_with_conn: xmtp_mls::storage::sql_key_store: read ResumptionPskStore
01-10 06:23:10.109  7459  7642 D xmtpv3  : async-compat/tokio-1 sync_with_conn: xmtp_mls::storage::sql_key_store: read MlsGroupJoinConfig
01-10 06:23:10.109  7459  7642 D xmtpv3  : async-compat/tokio-1 sync_with_conn: xmtp_mls::storage::sql_key_store: own_leaf_nodes
01-10 06:23:10.109  7459  7642 D xmtpv3  : async-compat/tokio-1 sync_with_conn: xmtp_mls::storage::sql_key_store: read_list OwnLeafNodes
01-10 06:23:10.109  7459  7642 D xmtpv3  : async-compat/tokio-1 sync_with_conn: xmtp_mls::storage::sql_key_store: read GroupState
01-10 06:23:10.109  7459  7642 D xmtpv3  : async-compat/tokio-1 sync_with_conn:receive: xmtp_mls::api::mls: query group messages group_id="32f52b31b2eb4e40cc592e4a594fac50" id_cursor=36379 inbox_id="5ba963badd8739fa3cf8bb0c3f7da5432fc1947df7faade72cfe3a8c1afafdc2"
01-10 06:23:10.109  7459  7642 D xmtpv3  : async-compat/tokio-1 sync_with_conn:receive: tower::buffer::worker: service.ready=true processing request
01-10 06:23:10.109  7459  7642 D xmtpv3  : async-compat/tokio-1 Connection{peer=Client}: h2::codec::framed_write: send frame=Headers { stream_id: StreamId(6509), flags: (0x4: END_HEADERS) }
01-10 06:23:10.109  7459  7642 D xmtpv3  : async-compat/tokio-1 Connection{peer=Client}: h2::codec::framed_write: send frame=Data { stream_id: StreamId(6509) }
01-10 06:23:10.109  7459  7642 D xmtpv3  : async-compat/tokio-1 Connection{peer=Client}: h2::codec::framed_write: send frame=Data { stream_id: StreamId(6509), flags: (0x1: END_STREAM) }
01-10 06:23:10.110  7459  7642 D xmtpv3  : async-compat/tokio-1 Connection{peer=Client}: h2::codec::framed_read: received frame=WindowUpdate { stream_id: StreamId(0), size_increment: 33 }
01-10 06:23:10.110  7459  7642 D xmtpv3  : async-compat/tokio-1 Connection{peer=Client}: h2::codec::framed_read: received frame=Ping { ack: false, payload: [2, 4, 16, 16, 9, 14, 7, 7] }
01-10 06:23:10.110  7459  7642 D xmtpv3  : async-compat/tokio-1 Connection{peer=Client}: h2::codec::framed_write: send frame=Ping { ack: true, payload: [2, 4, 16, 16, 9, 14, 7, 7] }
01-10 06:23:10.110  7459  7642 D xmtpv3  : async-compat/tokio-1 Connection{peer=Client}: h2::codec::framed_read: received frame=Headers { stream_id: StreamId(6509), flags: (0x4: END_HEADERS) }
01-10 06:23:10.110  7459  7659 D xmtpv3  : ThreadId(17) xmtp_mls::storage::encrypted_store::private: Transaction async being committed
01-10 06:23:10.111  7459  7642 D xmtpv3  : async-compat/tokio-1 Connection{peer=Client}: h2::codec::framed_read: received frame=Data { stream_id: StreamId(6509) }
01-10 06:23:10.112  7459  7642 D xmtpv3  : async-compat/tokio-1 Connection{peer=Client}: h2::codec::framed_read: received frame=Headers { stream_id: StreamId(6509), flags: (0x5: END_HEADERS | END_STREAM) }
01-10 06:23:10.112  7459  7642 D xmtpv3  : async-compat/tokio-1 sync_with_conn:receive: xmtp_mls::storage::encrypted_store::private: Transaction async beginning
01-10 06:23:10.112  7459  7642 I xmtpv3  : async-compat/tokio-1 sync_with_conn:receive: xmtp_mls::groups::mls_sync: Processing envelope with hash "5793b3a1d52e0ff8edbece76265b0bc000a41c55c5a74563c0464219c10e3a2c" inbox_id="5ba963badd8739fa3cf8bb0c3f7da5432fc1947df7faade72cfe3a8c1afafdc2" installation_id=65fe34f132880bf6fb6f3db79d6c074c3a94b0a315ca068cd761c937db0c36cd group_id="32f52b31b2eb4e40cc592e4a594fac50" msg_id=36381
01-10 06:23:10.112  7459  7642 I xmtpv3  : async-compat/tokio-1 sync_with_conn:receive: xmtp_mls::groups::mls_sync: client [5ba963badd8739fa3cf8bb0c3f7da5432fc1947df7faade72cfe3a8c1afafdc2] is about to process own envelope [36381] for intent [5] inbox_id="5ba963badd8739fa3cf8bb0c3f7da5432fc1947df7faade72cfe3a8c1afafdc2" installation_id=65fe34f132880bf6fb6f3db79d6c074c3a94b0a315ca068cd761c937db0c36cd group_id="32f52b31b2eb4e40cc592e4a594fac50" msg_id=36381 intent_id=5 intent.kind=SendMessage
01-10 06:23:10.112  7459  7642 D xmtpv3  : async-compat/tokio-1 sync_with_conn:receive: xmtp_mls::storage::sql_key_store: read Tree
01-10 06:23:10.112  7459  7642 D xmtpv3  : async-compat/tokio-1 sync_with_conn:receive: xmtp_mls::storage::sql_key_store: read_list ProposalQueueRefs
01-10 06:23:10.112  7459  7642 D xmtpv3  : async-compat/tokio-1 sync_with_conn:receive: xmtp_mls::storage::sql_key_store: read GroupContext
01-10 06:23:10.112  7459  7642 D xmtpv3  : async-compat/tokio-1 sync_with_conn:receive: xmtp_mls::storage::sql_key_store: read InterimTranscriptHash
01-10 06:23:10.112  7459  7642 D xmtpv3  : async-compat/tokio-1 sync_with_conn:receive: xmtp_mls::storage::sql_key_store: read ConfirmationTag
01-10 06:23:10.112  7459  7642 D xmtpv3  : async-compat/tokio-1 sync_with_conn:receive: xmtp_mls::storage::sql_key_store: read EpochSecrets
01-10 06:23:10.112  7459  7642 D xmtpv3  : async-compat/tokio-1 sync_with_conn:receive: xmtp_mls::storage::sql_key_store: read OwnLeafNodeIndex
01-10 06:23:10.112  7459  7642 D xmtpv3  : async-compat/tokio-1 sync_with_conn:receive: xmtp_mls::storage::sql_key_store: read MessageSecrets
01-10 06:23:10.112  7459  7642 D xmtpv3  : async-compat/tokio-1 sync_with_conn:receive: xmtp_mls::storage::sql_key_store: read ResumptionPskStore
01-10 06:23:10.112  7459  7642 D xmtpv3  : async-compat/tokio-1 sync_with_conn:receive: xmtp_mls::storage::sql_key_store: read MlsGroupJoinConfig
01-10 06:23:10.112  7459  7642 D xmtpv3  : async-compat/tokio-1 sync_with_conn:receive: xmtp_mls::storage::sql_key_store: own_leaf_nodes
01-10 06:23:10.112  7459  7642 D xmtpv3  : async-compat/tokio-1 sync_with_conn:receive: xmtp_mls::storage::sql_key_store: read_list OwnLeafNodes
01-10 06:23:10.112  7459  7642 D xmtpv3  : async-compat/tokio-1 sync_with_conn:receive: xmtp_mls::storage::sql_key_store: read GroupState
01-10 06:23:10.112  7459  7642 D xmtpv3  : async-compat/tokio-1 sync_with_conn:receive: xmtp_mls::groups::mls_sync: [5ba963badd8739fa3cf8bb0c3f7da5432fc1947df7faade72cfe3a8c1afafdc2]-[32f52b31b2eb4e40cc592e4a594fac50] processing own message for intent 5 / SendMessage, message_epoch: 1 inbox_id="5ba963badd8739fa3cf8bb0c3f7da5432fc1947df7faade72cfe3a8c1afafdc2" installation_id=65fe34f132880bf6fb6f3db79d6c074c3a94b0a315ca068cd761c937db0c36cd group_id="32f52b31b2eb4e40cc592e4a594fac50" msg_id=36381 intent.id=5 intent.kind=SendMessage
01-10 06:23:10.113  7459  7642 W xmtpv3  : async-compat/tokio-1 sync_with_conn:receive: xmtp_mls::storage::encrypted_store::private: More than 1 strong connection references still exist during async transaction
01-10 06:23:10.115  7459  7642 D xmtpv3  : async-compat/tokio-1 sync_with_conn:receive: xmtp_mls::storage::encrypted_store::private: Transaction async being committed
01-10 06:23:10.115  7459  7642 I xmtpv3  : async-compat/tokio-1 sync_with_conn:receive: xmtp_mls::groups::mls_sync: Transaction completed successfully: process for group [32f52b31b2eb4e40cc592e4a594fac50] envelope cursor[36381]
01-10 06:23:10.116  7459  7659 V XMTPModule: sendMessage
01-10 06:23:10.117  7459  7659 D xmtpv3  : ThreadId(17) xmtp_mls::storage::encrypted_store::native: Pulling connection from pool, idle_connections=24, total_connections=25
01-10 06:23:10.118  7459  7659 D xmtpv3  : ThreadId(17) xmtp_mls::storage::encrypted_store::native: Pulling connection from pool, idle_connections=24, total_connections=25
01-10 06:23:10.118  7459  7659 D xmtpv3  : ThreadId(17) xmtp_mls::storage::sql_key_store: read Tree
01-10 06:23:10.118  7459  7659 D xmtpv3  : ThreadId(17) xmtp_mls::storage::sql_key_store: read_list ProposalQueueRefs
01-10 06:23:10.118  7459  7659 D xmtpv3  : ThreadId(17) xmtp_mls::storage::sql_key_store: read GroupContext
01-10 06:23:10.118  7459  7659 D xmtpv3  : ThreadId(17) xmtp_mls::storage::sql_key_store: read InterimTranscriptHash
01-10 06:23:10.118  7459  7659 D xmtpv3  : ThreadId(17) xmtp_mls::storage::sql_key_store: read ConfirmationTag
01-10 06:23:10.118  7459  7659 D xmtpv3  : ThreadId(17) xmtp_mls::storage::sql_key_store: read EpochSecrets
01-10 06:23:10.118  7459  7659 D xmtpv3  : ThreadId(17) xmtp_mls::storage::sql_key_store: read OwnLeafNodeIndex
01-10 06:23:10.118  7459  7659 D xmtpv3  : ThreadId(17) xmtp_mls::storage::sql_key_store: read MessageSecrets
01-10 06:23:10.118  7459  7659 D xmtpv3  : ThreadId(17) xmtp_mls::storage::sql_key_store: read ResumptionPskStore
01-10 06:23:10.118  7459  7659 D xmtpv3  : ThreadId(17) xmtp_mls::storage::sql_key_store: read MlsGroupJoinConfig
01-10 06:23:10.118  7459  7659 D xmtpv3  : ThreadId(17) xmtp_mls::storage::sql_key_store: own_leaf_nodes
01-10 06:23:10.118  7459  7659 D xmtpv3  : ThreadId(17) xmtp_mls::storage::sql_key_store: read_list OwnLeafNodes
01-10 06:23:10.118  7459  7659 D xmtpv3  : ThreadId(17) xmtp_mls::storage::sql_key_store: read GroupState
01-10 06:23:10.119  7459  7642 D xmtpv3  : async-compat/tokio-1 xmtp_mls::storage::encrypted_store::private: Transaction beginning
01-10 06:23:10.119  7459  7642 D xmtpv3  : async-compat/tokio-1 xmtp_mls::groups::intents: queued intent inbox_id="5ba963badd8739fa3cf8bb0c3f7da5432fc1947df7faade72cfe3a8c1afafdc2" intent_kind=SendMessage
01-10 06:23:10.120  7459  7659 D xmtpv3  : ThreadId(17) xmtp_mls::storage::encrypted_store::native: Pulling connection from pool, idle_connections=24, total_connections=25
01-10 06:23:10.121  7459  7642 D xmtpv3  : async-compat/tokio-1 xmtp_mls::storage::encrypted_store::private: Transaction being committed
01-10 06:23:10.121  7459  7642 D xmtpv3  : async-compat/tokio-1 xmtp_mls::groups: Failed to decode message as EncodedContent: failed to decode Protobuf message: buffer underflow
01-10 06:23:10.121  7459  7659 D xmtpv3  : ThreadId(17) xmtp_mls::groups: sending message inbox_id="5ba963badd8739fa3cf8bb0c3f7da5432fc1947df7faade72cfe3a8c1afafdc2"
01-10 06:23:10.122  7459  7659 D xmtpv3  : ThreadId(17) xmtp_mls::storage::encrypted_store::native: Pulling connection from pool, idle_connections=24, total_connections=25
01-10 06:23:10.122  7459  7659 D xmtpv3  : ThreadId(17) xmtp_mls::storage::encrypted_store::private: Transaction async beginning
01-10 06:23:10.122  7459  7659 D xmtpv3  : ThreadId(17) xmtp_mls::storage::encrypted_store::private: Transaction beginning
01-10 06:23:10.122  7459  7659 D xmtpv3  : ThreadId(17) xmtp_mls::storage::encrypted_store::private: Transaction being rolled back
01-10 06:23:10.122  7459  7659 W xmtpv3  : ThreadId(17) xmtp_mls::storage::encrypted_store::private: More than 1 strong connection references still exist during async transaction
01-10 06:23:10.122  7459  7659 D xmtpv3  : ThreadId(17) xmtp_mls::storage::encrypted_store::private: Transaction async being rolled back
01-10 06:23:10.123  7459  7642 D xmtpv3  : async-compat/tokio-1 xmtp_mls::storage::sql_key_store: read Tree
01-10 06:23:10.123  7459  7642 D xmtpv3  : async-compat/tokio-1 xmtp_mls::storage::sql_key_store: read_list ProposalQueueRefs
01-10 06:23:10.123  7459  7642 D xmtpv3  : async-compat/tokio-1 xmtp_mls::storage::sql_key_store: read GroupContext
01-10 06:23:10.123  7459  7642 D xmtpv3  : async-compat/tokio-1 xmtp_mls::storage::sql_key_store: read InterimTranscriptHash
01-10 06:23:10.123  7459  7642 D xmtpv3  : async-compat/tokio-1 xmtp_mls::storage::sql_key_store: read ConfirmationTag
01-10 06:23:10.123  7459  7642 D xmtpv3  : async-compat/tokio-1 xmtp_mls::storage::sql_key_store: read EpochSecrets
01-10 06:23:10.123  7459  7642 D xmtpv3  : async-compat/tokio-1 xmtp_mls::storage::sql_key_store: read OwnLeafNodeIndex
01-10 06:23:10.123  7459  7642 D xmtpv3  : async-compat/tokio-1 xmtp_mls::storage::sql_key_store: read MessageSecrets
01-10 06:23:10.123  7459  7642 D xmtpv3  : async-compat/tokio-1 xmtp_mls::storage::sql_key_store: read ResumptionPskStore
01-10 06:23:10.123  7459  7642 D xmtpv3  : async-compat/tokio-1 xmtp_mls::storage::sql_key_store: read MlsGroupJoinConfig
01-10 06:23:10.123  7459  7642 D xmtpv3  : async-compat/tokio-1 xmtp_mls::storage::sql_key_store: own_leaf_nodes
01-10 06:23:10.123  7459  7642 D xmtpv3  : async-compat/tokio-1 xmtp_mls::storage::sql_key_store: read_list OwnLeafNodes
01-10 06:23:10.123  7459  7642 D xmtpv3  : async-compat/tokio-1 xmtp_mls::storage::sql_key_store: read GroupState
01-10 06:23:10.124  7459  7642 D xmtpv3  : async-compat/tokio-1 xmtp_mls::storage::sql_key_store: write MessageSecrets
01-10 06:23:10.126  7459  7557 I ReactNativeJS: 'ERROR in send()', 'Call to function \'XMTP.sendMessage\' has been rejected.\n→ Caused by: uniffi.xmtpv3.GenericException$GroupException: Group error: storage error: Diesel result error: database is locked'
01-10 06:23:10.127  7459  7642 D xmtpv3  : async-compat/tokio-1 xmtp_mls::groups::mls_sync: client [5ba963badd8739fa3cf8bb0c3f7da5432fc1947df7faade72cfe3a8c1afafdc2] set stored intent [8] to state `published` inbox_id="5ba963badd8739fa3cf8bb0c3f7da5432fc1947df7faade72cfe3a8c1afafdc2" installation_id=65fe34f132880bf6fb6f3db79d6c074c3a94b0a315ca068cd761c937db0c36cd intent.id=8 intent.kind=SendMessage group_id="32f52b31b2eb4e40cc592e4a594fac50"

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Reviewers
No reviews
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

Successfully merging this pull request may close these issues.
1 participant
@cameronvoell