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.

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

Testing thread safe groups libxmtp PR #566

Closed
wants to merge 5 commits into from

Conversation

cameronvoell
Copy link
Contributor

This branch is testing libxmtp PR xmtp/libxmtp#1404

currently set to libxmtp commit 7473a2462b98bd79afa469ea8940cc1c029bda69

uses android branch from xmtp/xmtp-android#350

Copy link

changeset-bot bot commented Dec 13, 2024

⚠️ No Changeset found

Latest commit: b254ed9

Merging this PR will not cause a version bump for any packages. If these changes should not result in a new version, you're good to go. If these changes should result in a version bump, you need to add a changeset.

This PR includes no changesets

When changesets are added to this PR, you'll see the packages that this PR includes changesets for and the associated semver types

Click here to learn what changesets are, and how to add one.

Click here if you're a maintainer who wants to add a changeset to this PR

@cameronvoell
Copy link
Contributor Author

The following test is causing the RN Example app to crash:

test('can stream both groups and messages at same time', async () => {
const [alix, bo] = await createClients(2)
let groupCallbacks = 0
let messageCallbacks = 0
await bo.conversations.stream(async () => {
groupCallbacks++
})
await bo.conversations.streamAllMessages(async () => {
messageCallbacks++
})
const group = await alix.conversations.newGroup([bo.address])
// await group.send('hello')
// await delayToPropogate()
// assert(
// messageCallbacks === 1,
// 'message stream should have received 1 message'
// )
// assert(groupCallbacks === 1, 'group stream should have received 1 group')
return true
})

log excerpt showing the crash:

12-12 17:46:25.240  9406  9594 I xmtpv3  : async-compat/tokio-1 retry: xmtp_mls::groups: Group membership validated
12-12 17:46:25.240  9406  9594 I xmtpv3  : async-compat/tokio-1 retry: xmtp_mls::storage::encrypted_store::group: Trying to insert group
12-12 17:46:25.240  9406  9594 I xmtpv3  : async-compat/tokio-1 retry: xmtp_mls::storage::encrypted_store::group: Group is inserted
12-12 17:46:25.240  9406  9594 W xmtpv3  : async-compat/tokio-1 retry: xmtp_mls::storage::encrypted_store::private: More than 1 strong connection references still exist during async transaction
12-12 17:46:25.241  9406  9594 D xmtpv3  : async-compat/tokio-1 retry: xmtp_mls::storage::encrypted_store::private: Transaction async being committed
12-12 17:46:25.241  9406  9594 D xmtpv3  : async-compat/tokio-1 load_mls_group_with_lock_async: xmtp_mls::storage::sql_key_store: read Tree
12-12 17:46:25.241  9406  9594 D xmtpv3  : async-compat/tokio-1 load_mls_group_with_lock_async: xmtp_mls::storage::sql_key_store: read_list ProposalQueueRefs
12-12 17:46:25.241  9406  9594 D xmtpv3  : async-compat/tokio-1 load_mls_group_with_lock_async: xmtp_mls::storage::sql_key_store: read GroupContext
12-12 17:46:25.241  9406  9594 D xmtpv3  : async-compat/tokio-1 load_mls_group_with_lock_async: xmtp_mls::storage::sql_key_store: read InterimTranscriptHash
12-12 17:46:25.241  9406  9594 D xmtpv3  : async-compat/tokio-1 load_mls_group_with_lock_async: xmtp_mls::storage::sql_key_store: read ConfirmationTag
12-12 17:46:25.241  9406  9594 D xmtpv3  : async-compat/tokio-1 load_mls_group_with_lock_async: xmtp_mls::storage::sql_key_store: read EpochSecrets
12-12 17:46:25.241  9406  9594 D xmtpv3  : async-compat/tokio-1 load_mls_group_with_lock_async: xmtp_mls::storage::sql_key_store: read OwnLeafNodeIndex
12-12 17:46:25.241  9406  9594 D xmtpv3  : async-compat/tokio-1 load_mls_group_with_lock_async: xmtp_mls::storage::sql_key_store: read MessageSecrets
12-12 17:46:25.241  9406  9594 D xmtpv3  : async-compat/tokio-1 load_mls_group_with_lock_async: xmtp_mls::storage::sql_key_store: read ResumptionPskStore
12-12 17:46:25.241  9406  9594 D xmtpv3  : async-compat/tokio-1 load_mls_group_with_lock_async: xmtp_mls::storage::sql_key_store: read MlsGroupJoinConfig
12-12 17:46:25.241  9406  9594 D xmtpv3  : async-compat/tokio-1 load_mls_group_with_lock_async: xmtp_mls::storage::sql_key_store: own_leaf_nodes
12-12 17:46:25.241  9406  9594 D xmtpv3  : async-compat/tokio-1 load_mls_group_with_lock_async: xmtp_mls::storage::sql_key_store: read_list OwnLeafNodes
12-12 17:46:25.241  9406  9594 D xmtpv3  : async-compat/tokio-1 load_mls_group_with_lock_async: xmtp_mls::storage::sql_key_store: read GroupState
12-12 17:46:25.241  9406  9594 I xmtpv3  : async-compat/tokio-1 xmtp_mls::subscriptions: Trigger conversation callback
12-12 17:46:25.243  9406  9594 D xmtpv3  : async-compat/tokio-1 xmtp_mls::storage::encrypted_store::native: Pulling connection from pool, idle_connections=24, total_connections=25
12-12 17:46:25.253  9406  9602 D xmtpv3  : ThreadId(15) xmtp_mls::storage::encrypted_store::native: Pulling connection from pool, idle_connections=25, total_connections=25
12-12 17:46:25.253  9406  9602 D xmtpv3  : ThreadId(15) load_mls_group_with_lock: xmtp_mls::storage::sql_key_store: read Tree
12-12 17:46:25.251  9613  9613 W linker64: type=1400 audit(0.0:349): avc:  denied  { search } for  name="tests" dev="dm-39" ino=65540 scontext=u:r:untrusted_app_32:s0:c190,c256,c512,c768 tcontext=u:object_r:shell_test_data_file:s0 tclass=dir permissive=0 app=expo.modules.xmtpreactnativesdk.example
12-12 17:46:25.251  9613  9613 W linker64: type=1400 audit(0.0:350): avc:  denied  { search } for  name="tests" dev="dm-39" ino=65540 scontext=u:r:untrusted_app_32:s0:c190,c256,c512,c768 tcontext=u:object_r:shell_test_data_file:s0 tclass=dir permissive=0 app=expo.modules.xmtpreactnativesdk.example
12-12 17:46:25.251  9613  9613 W linker64: type=1400 audit(0.0:351): avc:  denied  { search } for  name="tests" dev="dm-39" ino=65540 scontext=u:r:untrusted_app_32:s0:c190,c256,c512,c768 tcontext=u:object_r:shell_test_data_file:s0 tclass=dir permissive=0 app=expo.modules.xmtpreactnativesdk.example
12-12 17:46:25.251  9613  9613 W linker64: type=1400 audit(0.0:352): avc:  denied  { search } for  name="tests" dev="dm-39" ino=65540 scontext=u:r:untrusted_app_32:s0:c190,c256,c512,c768 tcontext=u:object_r:shell_test_data_file:s0 tclass=dir permissive=0 app=expo.modules.xmtpreactnativesdk.example
12-12 17:46:25.254  9406  9602 D xmtpv3  : ThreadId(15) load_mls_group_with_lock: xmtp_mls::storage::sql_key_store: read_list ProposalQueueRefs
12-12 17:46:25.254  9406  9602 D xmtpv3  : ThreadId(15) load_mls_group_with_lock: xmtp_mls::storage::sql_key_store: read GroupContext
12-12 17:46:25.254  9406  9602 D xmtpv3  : ThreadId(15) load_mls_group_with_lock: xmtp_mls::storage::sql_key_store: read InterimTranscriptHash
12-12 17:46:25.254  9406  9602 D xmtpv3  : ThreadId(15) load_mls_group_with_lock: xmtp_mls::storage::sql_key_store: read ConfirmationTag
12-12 17:46:25.255  9406  9602 D xmtpv3  : ThreadId(15) load_mls_group_with_lock: xmtp_mls::storage::sql_key_store: read EpochSecrets
12-12 17:46:25.255  9406  9602 D xmtpv3  : ThreadId(15) load_mls_group_with_lock: xmtp_mls::storage::sql_key_store: read OwnLeafNodeIndex
12-12 17:46:25.255  9406  9602 D xmtpv3  : ThreadId(15) load_mls_group_with_lock: xmtp_mls::storage::sql_key_store: read MessageSecrets
12-12 17:46:25.255  9406  9602 D xmtpv3  : ThreadId(15) load_mls_group_with_lock: xmtp_mls::storage::sql_key_store: read ResumptionPskStore
12-12 17:46:25.255  9406  9602 D xmtpv3  : ThreadId(15) load_mls_group_with_lock: xmtp_mls::storage::sql_key_store: read MlsGroupJoinConfig
12-12 17:46:25.255  9406  9602 D xmtpv3  : ThreadId(15) load_mls_group_with_lock: xmtp_mls::storage::sql_key_store: own_leaf_nodes
12-12 17:46:25.255  9406  9602 D xmtpv3  : ThreadId(15) load_mls_group_with_lock: xmtp_mls::storage::sql_key_store: read_list OwnLeafNodes
12-12 17:46:25.255  9406  9602 D xmtpv3  : ThreadId(15) load_mls_group_with_lock: xmtp_mls::storage::sql_key_store: read GroupState
12-12 17:46:25.256  9406  9602 D xmtpv3  : ThreadId(15) xmtp_mls::storage::encrypted_store::native: Pulling connection from pool, idle_connections=25, total_connections=25
12-12 17:46:25.258  9406  9602 D xmtpv3  : ThreadId(15) xmtp_mls::storage::encrypted_store::native: Pulling connection from pool, idle_connections=25, total_connections=25
12-12 17:46:25.258  9406  9602 D xmtpv3  : ThreadId(15) load_mls_group_with_lock: xmtp_mls::storage::sql_key_store: read Tree
12-12 17:46:25.258  9406  9602 D xmtpv3  : ThreadId(15) load_mls_group_with_lock: xmtp_mls::storage::sql_key_store: read_list ProposalQueueRefs
12-12 17:46:25.258  9406  9602 D xmtpv3  : ThreadId(15) load_mls_group_with_lock: xmtp_mls::storage::sql_key_store: read GroupContext
12-12 17:46:25.258  9406  9602 D xmtpv3  : ThreadId(15) load_mls_group_with_lock: xmtp_mls::storage::sql_key_store: read InterimTranscriptHash
12-12 17:46:25.258  9406  9602 D xmtpv3  : ThreadId(15) load_mls_group_with_lock: xmtp_mls::storage::sql_key_store: read ConfirmationTag
12-12 17:46:25.258  9406  9602 D xmtpv3  : ThreadId(15) load_mls_group_with_lock: xmtp_mls::storage::sql_key_store: read EpochSecrets
12-12 17:46:25.258  9406  9602 D xmtpv3  : ThreadId(15) load_mls_group_with_lock: xmtp_mls::storage::sql_key_store: read OwnLeafNodeIndex
12-12 17:46:25.258  9406  9602 D xmtpv3  : ThreadId(15) load_mls_group_with_lock: xmtp_mls::storage::sql_key_store: read MessageSecrets
12-12 17:46:25.258  9406  9602 D xmtpv3  : ThreadId(15) load_mls_group_with_lock: xmtp_mls::storage::sql_key_store: read ResumptionPskStore
12-12 17:46:25.258  9406  9602 D xmtpv3  : ThreadId(15) load_mls_group_with_lock: xmtp_mls::storage::sql_key_store: read MlsGroupJoinConfig
12-12 17:46:25.258  9406  9602 D xmtpv3  : ThreadId(15) load_mls_group_with_lock: xmtp_mls::storage::sql_key_store: own_leaf_nodes
12-12 17:46:25.258  9406  9602 D xmtpv3  : ThreadId(15) load_mls_group_with_lock: xmtp_mls::storage::sql_key_store: read_list OwnLeafNodes
12-12 17:46:25.258  9406  9602 D xmtpv3  : ThreadId(15) load_mls_group_with_lock: xmtp_mls::storage::sql_key_store: read GroupState
12-12 17:46:25.259  9406  9602 D xmtpv3  : ThreadId(15) xmtp_mls::storage::encrypted_store::native: Pulling connection from pool, idle_connections=25, total_connections=25
12-12 17:46:25.259  9406  9602 D xmtpv3  : ThreadId(15) load_mls_group_with_lock: xmtp_mls::storage::sql_key_store: read Tree
12-12 17:46:25.259  9406  9602 D xmtpv3  : ThreadId(15) load_mls_group_with_lock: xmtp_mls::storage::sql_key_store: read_list ProposalQueueRefs
12-12 17:46:25.259  9406  9602 D xmtpv3  : ThreadId(15) load_mls_group_with_lock: xmtp_mls::storage::sql_key_store: read GroupContext
12-12 17:46:25.260  9406  9602 D xmtpv3  : ThreadId(15) load_mls_group_with_lock: xmtp_mls::storage::sql_key_store: read InterimTranscriptHash
12-12 17:46:25.260  9406  9602 D xmtpv3  : ThreadId(15) load_mls_group_with_lock: xmtp_mls::storage::sql_key_store: read ConfirmationTag
12-12 17:46:25.260  9406  9602 D xmtpv3  : ThreadId(15) load_mls_group_with_lock: xmtp_mls::storage::sql_key_store: read EpochSecrets
12-12 17:46:25.260  9406  9602 D xmtpv3  : ThreadId(15) load_mls_group_with_lock: xmtp_mls::storage::sql_key_store: read OwnLeafNodeIndex
12-12 17:46:25.260  9406  9602 D xmtpv3  : ThreadId(15) load_mls_group_with_lock: xmtp_mls::storage::sql_key_store: read MessageSecrets
12-12 17:46:25.260  9406  9602 D xmtpv3  : ThreadId(15) load_mls_group_with_lock: xmtp_mls::storage::sql_key_store: read ResumptionPskStore
12-12 17:46:25.260  9406  9602 D xmtpv3  : ThreadId(15) load_mls_group_with_lock: xmtp_mls::storage::sql_key_store: read MlsGroupJoinConfig
12-12 17:46:25.260  9406  9602 D xmtpv3  : ThreadId(15) load_mls_group_with_lock: xmtp_mls::storage::sql_key_store: own_leaf_nodes
12-12 17:46:25.260  9406  9602 D xmtpv3  : ThreadId(15) load_mls_group_with_lock: xmtp_mls::storage::sql_key_store: read_list OwnLeafNodes
12-12 17:46:25.260  9406  9602 D xmtpv3  : ThreadId(15) load_mls_group_with_lock: xmtp_mls::storage::sql_key_store: read GroupState
12-12 17:46:25.261  9406  9602 D xmtpv3  : ThreadId(15) xmtp_mls::storage::encrypted_store::native: Pulling connection from pool, idle_connections=25, total_connections=25
12-12 17:46:25.261  9406  9602 D xmtpv3  : ThreadId(15) load_mls_group_with_lock: xmtp_mls::storage::sql_key_store: read Tree
12-12 17:46:25.261  9406  9602 D xmtpv3  : ThreadId(15) load_mls_group_with_lock: xmtp_mls::storage::sql_key_store: read_list ProposalQueueRefs
12-12 17:46:25.261  9406  9602 D xmtpv3  : ThreadId(15) load_mls_group_with_lock: xmtp_mls::storage::sql_key_store: read GroupContext
12-12 17:46:25.261  9406  9602 D xmtpv3  : ThreadId(15) load_mls_group_with_lock: xmtp_mls::storage::sql_key_store: read InterimTranscriptHash
12-12 17:46:25.261  9406  9602 D xmtpv3  : ThreadId(15) load_mls_group_with_lock: xmtp_mls::storage::sql_key_store: read ConfirmationTag
12-12 17:46:25.261  9406  9602 D xmtpv3  : ThreadId(15) load_mls_group_with_lock: xmtp_mls::storage::sql_key_store: read EpochSecrets
12-12 17:46:25.261  9406  9602 D xmtpv3  : ThreadId(15) load_mls_group_with_lock: xmtp_mls::storage::sql_key_store: read OwnLeafNodeIndex
12-12 17:46:25.261  9406  9602 D xmtpv3  : ThreadId(15) load_mls_group_with_lock: xmtp_mls::storage::sql_key_store: read MessageSecrets
12-12 17:46:25.261  9406  9602 D xmtpv3  : ThreadId(15) load_mls_group_with_lock: xmtp_mls::storage::sql_key_store: read ResumptionPskStore
12-12 17:46:25.261  9406  9602 D xmtpv3  : ThreadId(15) load_mls_group_with_lock: xmtp_mls::storage::sql_key_store: read MlsGroupJoinConfig
12-12 17:46:25.261  9406  9602 D xmtpv3  : ThreadId(15) load_mls_group_with_lock: xmtp_mls::storage::sql_key_store: own_leaf_nodes
12-12 17:46:25.261  9406  9602 D xmtpv3  : ThreadId(15) load_mls_group_with_lock: xmtp_mls::storage::sql_key_store: read_list OwnLeafNodes
12-12 17:46:25.261  9406  9602 D xmtpv3  : ThreadId(15) load_mls_group_with_lock: xmtp_mls::storage::sql_key_store: read GroupState
12-12 17:46:25.263  9406  9602 D xmtpv3  : ThreadId(15) xmtp_mls::storage::encrypted_store::native: Pulling connection from pool, idle_connections=25, total_connections=25
12-12 17:46:25.288  9613  9613 W libc    : Access denied finding property "ro.debuggable"
12-12 17:46:25.283  9613  9613 W linker64: type=1400 audit(0.0:353): avc:  denied  { read } for  name="u:object_r:userdebug_or_eng_prop:s0" dev="tmpfs" ino=310 scontext=u:r:untrusted_app_32:s0:c190,c256,c512,c768 tcontext=u:object_r:userdebug_or_eng_prop:s0 tclass=file permissive=0 app=expo.modules.xmtpreactnativesdk.example
12-12 17:46:25.313  9613  9613 E chromium: [1212/174625.313329:ERROR:elf_dynamic_array_reader.h(64)] tag not found
12-12 17:46:25.313  9613  9613 E chromium: [1212/174625.313703:ERROR:elf_dynamic_array_reader.h(64)] tag not found
--------- beginning of crash
12-12 17:46:25.340  9406  9594 F libc    : Fatal signal 6 (SIGABRT), code -1 (SI_QUEUE) in tid 9594 (Thread-56), pid 9406 (tivesdk.example)

See corresponding log from running that test:
test-logcat-2024-12-12_17-45-16.log

@cameronvoell
Copy link
Contributor Author

Updated to libxmtp ba0b09c the following test is failing about 2/3 of the time now:

test('groups cannot fork short version', async () => {
const [alix, bo, new_one, new_two] = await createClients(4)
// Create group with 2 users
const alixGroup = await alix.conversations.newGroup([
bo.address,
new_one.address,
new_two.address,
])
// sync clients
await alix.conversations.sync()
await bo.conversations.sync()
const boGroup: Group<DefaultContentTypes> = (await bo.conversations.findGroup(alixGroup.id))!
// Remove two members in parallel
// NB => if we don't use Promise.all but a loop, we don't get a fork
console.log('*************libxmtp*********************: Removing members in parallel')
await Promise.all([
alixGroup.removeMembers([new_one.address]),
alixGroup.removeMembers([new_two.address])
])
// Helper to send a message from a bunch of senders and make sure it is received by all receivers
const testMessageSending = async (senderGroup: Group<DefaultContentTypes>, receiverGroup: Group<DefaultContentTypes>) => {
const messageContent = Math.random().toString(36)
await senderGroup.sync()
await alixGroup.send(messageContent)
await delayToPropogate(500)
await alixGroup.sync()
await receiverGroup.sync()
const messages = await receiverGroup.messages({
direction: 'DESCENDING',
})
const lastMessage = messages[0]
console.log(
`${receiverGroup.client.address} sees ${messages.length} messages in group`
)
assert(
lastMessage !== undefined &&
lastMessage.nativeContent.text === messageContent,
`${receiverGroup.client.address} should have received the message, FORK? ${lastMessage?.nativeContent.text} !== ${messageContent}`
)
}
// When forked, it stays forked even if we try 5 times
// but sometimes it is not forked and works 5/5 times
let forkCount = 0
const tryCount = 5
for (let i = 0; i < tryCount; i++) {
console.log(`Checking fork status ${i+1}/${tryCount}`)
try {
await alixGroup.sync()
await boGroup.sync()
await delayToPropogate(500)
await testMessageSending(alixGroup, boGroup)
console.log('Not forked!')
} catch (e: any) {
console.log('Forked!')
console.log(e)
forkCount++
}
}
assert(forkCount === 0, `Forked ${forkCount}/${tryCount} times`)
return true
})

failing run:
forked-test-logcat-2024-12-13_12-14-21.log

passing run:
not-forked-test-logcat-2024-12-13_12-15-10.log

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

1 participant