TryQuiet / quiet

A private, p2p alternative to Slack and Discord built on Tor & IPFS
https://www.tryquiet.org
GNU General Public License v3.0
1.94k stars 85 forks source link

Detox tests are not deterministic #2458

Open siepra opened 5 months ago

siepra commented 5 months ago

Branch: develop

Currently, on develop branch there're bunch of problems making Detox runs non-deterministic.

EDIT: Problems persists on manual runs as well

siepra commented 5 months ago

App got stuck while creating a community Note it should get past this step quickly during creation

Image Image

siepra commented 5 months ago

I observed it gets stuck even earlier, on "Connecting process started". Here's raw logs dump

create network saga
  backend:SocketService Creating network for community elsao9wm0g79eia5 +6s
  backend:ConnectionsManagerService socketService - createNetwork +6s
  backend:TorControl Connecting to Tor, host: localhost port: 19638 +0ms
Apr 19 11:52:12.000 [notice] New control connection opened from 127.0.0.1.
  backend:TorControl Tor connected +8ms
  backend:TorControl Connecting to Tor, host: localhost port: 19638 +11ms
Apr 19 11:52:12.000 [notice] New control connection opened from 127.0.0.1.
  backend:TorControl Tor connected +3ms
-[RTIInputSystemClient remoteTextInputSessionWithID:performInputOperation:]  perform input operation requires a valid sessionID. inputModality = Keyboard, inputOperation = <null selector>, customInfoType = UIEmojiSearchOperations
  backend:ConnectionsManagerService Created network for peer bafzbeiccjzscks4m6tmjomndohfphjjcrs3wbexzlxv62azoqnqclggioe. Address: wutt57yw7ck7vno5kaewn25ujmad2s7p6iy7uzso4pyouzlu6ztvv4qd.onion +242ms
-[RTIInputSystemClient remoteTextInputSessionWithID:performInputOperation:]  perform input operation requires a valid sessionID. inputModality = Keyboard, inputOperation = <null selector>, customInfoType = UIEmojiSearchOperations
-[RTIInputSystemClient remoteTextInputSessionWithID:performInputOperation:]  perform input operation requires a valid sessionID. inputModality = Keyboard, inputOperation = <null selector>, customInfoType = UIEmojiSearchOperations
{ isCommunity: undefined,
  areMessages: false,
  areChannels: false,
  areCertificates: false }
-[RTIInputSystemClient remoteTextInputSessionWithID:performInputOperation:]  perform input operation requires a valid sessionID. inputModality = Keyboard, inputOperation = <null selector>, customInfoType = UIEmojiSearchOperations
  backend:SocketService Creating community elsao9wm0g79eia5 +3s
  backend:ConnectionsManagerService socketService - createCommunity +2s
  backend:ConnectionsManagerService Creating community: peers: undefined +0ms
  backend:LocalDbService Getting 'communities' [Error: NotFound: ] {
  code: 'LEVEL_NOT_FOUND',
  notFound: true,
  status: 404
} +9s
  backend:ConnectionsManagerService Launching community elsao9wm0g79eia5: peer: QmSoUwtVqJgojEHZ9vxP3RLg73PPGWHXu924WkzxbDGmCk +48ms
  backend:ConnectionsManagerService Spawning hidden service for community elsao9wm0g79eia5, peer: QmSoUwtVqJgojEHZ9vxP3RLg73PPGWHXu924WkzxbDGmCk +1ms
  backend:TorControl Connecting to Tor, host: localhost port: 19638 +3s
Apr 19 11:52:14.000 [notice] New control connection opened from 127.0.0.1.
  backend:TorControl Tor connected +3ms
[Nest] 47775  - 1713520334742     LOG [LazyModuleLoader] SocketModule dependencies initialized
[Nest] 47775  - 1713520334742     LOG [LazyModuleLoader] Libp2pModule dependencies initialized
  backend:ConnectionsManagerService Launching community elsao9wm0g79eia5: payload peers: /dns4/wutt57yw7ck7vno5kaewn25ujmad2s7p6iy7uzso4pyouzlu6ztvv4qd.onion/tcp/80/ws/p2p/QmSoUwtVqJgojEHZ9vxP3RLg73PPGWHXu924WkzxbDGmCk +21ms
  backend:Libp2pService Local peerId: QmSoUwtVqJgojEHZ9vxP3RLg73PPGWHXu924WkzxbDGmCk +0ms
  backend:Libp2pService Initializing libp2p for QmSoUwtVqJgojEHZ9vxP3RLg73PPGWHXu924WkzxbDGmCk, bootstrapping with 0 peers +0ms
  backend:ProcessInChunksService Initializing process-in-chunks.service with peers [] +0ms
  backend:ProcessInChunksService Updating data with 0 items +1ms
  backend:ProcessInChunksService Adding 0 items to the task queue +0ms
  backend:ProcessInChunksService Adding 0 items to the task queue +0ms
  backend:ProcessInChunksService Processing function length () {
  backend:ProcessInChunksService     var current = queueHead
  backend:ProcessInChunksService     var counter = 0
  backend:ProcessInChunksService 
  backend:ProcessInChunksService     while (current) {
  backend:ProcessInChunksService       current = current.next
  backend:ProcessInChunksService       counter++
  backend:ProcessInChunksService     }
  backend:ProcessInChunksService 
  backend:ProcessInChunksService     return counter
  backend:ProcessInChunksService   } items +0ms
  backend:Libp2pService Initialized libp2p for peer QmSoUwtVqJgojEHZ9vxP3RLg73PPGWHXu924WkzxbDGmCk +3ms
  backend:StorageService Initializing storage +0ms
  backend:StorageService Initialized storage +1ms
[Nest] 47775  - 1713520334803     LOG [LazyModuleLoader] IpfsModule dependencies initialized
counter ipfs 1
[Nest] 47775  - 1713520334806     LOG [LazyModuleLoader] SocketModule dependencies initialized
[Nest] 47775  - 1713520334806     LOG [LazyModuleLoader] Libp2pModule dependencies initialized
to get started, enter:

    jsipfs cat /ipfs/QmRaaUwTNfwgFZpeUy8qrZwrp2dY4kCKmmB5xEqvH3vtD1/readme

  backend:OrbitDb [create]:started +0ms
(node:47775) [DEP0005] DeprecationWarning: Buffer() is deprecated due to security and usability issues. Please use the Buffer.alloc(), Buffer.allocUnsafe(), or Buffer.from() methods instead.
(Use `node --trace-deprecation ...` to show where the warning was created)
[Nest] 47775  - 1713520341516     LOG [LazyModuleLoader] IpfsFileManagerModule dependencies initialized
[Nest] 47775  - 1713520341516     LOG [LazyModuleLoader] IpfsModule dependencies initialized
  backend:StorageService 1/3 +7s
  backend:StorageService 2/3 +1ms
  backend:CommunityMetadataStore Initializing community metadata key/value store +0ms
  backend:CommunityMetadataStore Loaded community metadata to memory +25ms
  backend:CertificatesStore Initializing certificates log store +0ms
  backend:CertificatesStore Loaded certificates to memory +18ms
  backend:CertificatesStore Initialized +0ms
  backend:CertificatesRequestsStore Initializing certificates requests store +0ms
  backend:CertificatesRequestsStore Initialized +16ms
  backend:UserProfileStore Initializing user profiles key/value store +0ms
  backend:UserProfileStore Loaded user profiles to memory +20ms
  backend:StorageService 3/3 +80ms
  backend:StorageService createDbForChannels init +0ms
  backend:StorageService Channels count: 0 +19ms
  backend:StorageService Channels names: [] +0ms
  backend:StorageService STORAGE: Finished createDbForChannels +0ms
Storage.initDatabases: 99.705ms
  backend:StorageService Initialized DBs +1ms
  backend:StorageService Starting IPFS +0ms
  backend:ConnectionsManagerService Storage initialized +7s
  backend:ConnectionsManagerService Launched community elsao9wm0g79eia5 +0ms
  backend:CommunityMetadataStore About to update community metadata elsao9wm0g79eia5 +86ms
  backend:CommunityMetadataStore Updating community metadata +0ms
preparing listener
  backend:libp2p:websockets prepareListener +0ms
  backend:StorageService IPFS started +6s
  backend:StorageService Pubsub - subscribe to /orbitdb/zdpuAubkQfjh7bUVJFvuCuNpkXc9LYF4NuPX7VS12e4ciy851/public-channels +0ms
  backend:StorageService Pubsub - subscribe to /orbitdb/zdpuAtjfjLokx2PW6UGrDQoB8VmEyq2i2endX4KuuD8efo7Vj/certificates +0ms
  backend:StorageService Pubsub - subscribe to /orbitdb/zdpuAq8czmPVqfV7B5fchXdFY11jVPNNymTnCJtvPDR1dCV3h/csrs +0ms
  backend:StorageService Pubsub - subscribe to /orbitdb/zdpuAtLG6WrE13SaXWmg52e1odsV3c97BPDQRudzzXFNqDoQD/community-metadata +0ms
  backend:StorageService Pubsub - subscribe to /orbitdb/zdpuAyScVHonV7KUdb3rdNmC9ZurssGdfgveYm3ds7KNJ6CpU/user-profiles +0ms
  backend:CertificatesStore Loaded certificates to memory +6s
  backend:CertificatesStore All certificates: 0 +0ms
  backend:CertificatesStore Valid certificates: 0 +0ms
  backend:ConnectionsManagerService Storage - certificatesStored +6s
  backend:StorageService csrs count: 0 +45ms
updatePeersList, peers count: 0
  backend:ConnectionsManagerService Created and launched community elsao9wm0g79eia5 +1ms
  backend:LocalDbService Getting 'peers' [Error: NotFound: ] {
  code: 'LEVEL_NOT_FOUND',
  notFound: true,
  status: 404
} +13s
  backend:LocalDbService Local peer /dns4/wutt57yw7ck7vno5kaewn25ujmad2s7p6iy7uzso4pyouzlu6ztvv4qd.onion/tcp/80/ws/p2p/QmSoUwtVqJgojEHZ9vxP3RLg73PPGWHXu924WkzxbDGmCk +0ms
'WEBSOCKET', 'Entered restore connection saga', true, { dataPort: 11000, socketIOSecret: 'AcO4uSD7FYif9JHspqmF' }
[Tor error] Problem bootstrapping. Stuck at 5% (conn): Connecting to a relay. (Network is unreachable; NOROUTE; count 2; recommendation warn; host 22AC139C979C0509154D18E033491AD40524AF91 at 5.59.227.51:9001)
Apr 19 11:53:07.000 [warn] Problem bootstrapping. Stuck at 5% (conn): Connecting to a relay. (Network is unreachable; NOROUTE; count 2; recommendation warn; host 22AC139C979C0509154D18E033491AD40524AF91 at 5.59.227.51:9001)
[Tor error] 1 connections have failed:
Apr 19 11:53:07.000 [warn] 1 connections have failed:
[Tor error] 1 connections died in state connect()ing with SSL state (No SSL object)
Apr 19 11:53:07.000 [warn]  1 connections died in state connect()ing with SSL state (No SSL object)
Apr 19 11:53:08.000 [notice] Bootstrapped 10% (conn_done): Connected to a relay
Apr 19 11:53:08.000 [notice] Bootstrapped 14% (handshake): Handshaking with a relay
Apr 19 11:53:08.000 [notice] Bootstrapped 15% (handshake_done): Handshake with a relay done
Apr 19 11:53:08.000 [notice] Bootstrapped 20% (onehop_create): Establishing an encrypted directory connection
Apr 19 11:53:09.000 [notice] Bootstrapped 25% (requesting_status): Asking for networkstatus consensus
Apr 19 11:53:09.000 [notice] Bootstrapped 30% (loading_status): Loading networkstatus consensus
Apr 19 11:53:10.000 [notice] I learned some more directory information, but not enough to build a circuit: We have no usable consensus.
Apr 19 11:53:10.000 [notice] Bootstrapped 40% (loading_keys): Loading authority key certs
Apr 19 11:53:10.000 [notice] The current consensus has no exit nodes. Tor can only build internal paths, such as paths to onion services.
Apr 19 11:53:10.000 [notice] Bootstrapped 45% (requesting_descriptors): Asking for relay descriptors
Apr 19 11:53:10.000 [notice] I learned some more directory information, but not enough to build a circuit: We need more microdescriptors: we have 0/7768, and can only build 0% of likely paths. (We have 0% of guards bw, 0% of midpoint bw, and 0% of end bw (no exits in consensus, using mid) = 0% of path bw.)
Apr 19 11:53:11.000 [notice] Bootstrapped 50% (loading_descriptors): Loading relay descriptors
Apr 19 11:53:14.000 [notice] The current consensus contains exit nodes. Tor can build exit and internal paths.
Apr 19 11:53:31.000 [notice] Bootstrapped 56% (loading_descriptors): Loading relay descriptors
Apr 19 11:53:32.000 [notice] Bootstrapped 62% (loading_descriptors): Loading relay descriptors
Apr 19 11:53:32.000 [notice] Bootstrapped 71% (loading_descriptors): Loading relay descriptors
Apr 19 11:53:32.000 [notice] Bootstrapped 75% (enough_dirinfo): Loaded enough directory info to build circuits
Apr 19 11:53:32.000 [notice] Bootstrapped 80% (ap_conn): Connecting to a relay to build circuits
Apr 19 11:53:32.000 [notice] Bootstrapped 85% (ap_conn_done): Connected to a relay to build circuits
Apr 19 11:53:32.000 [notice] Bootstrapped 89% (ap_handshake): Finishing handshake with a relay to build circuits
Apr 19 11:53:32.000 [notice] Bootstrapped 90% (ap_handshake_done): Handshake finished with a relay to build circuits
Apr 19 11:53:32.000 [notice] Bootstrapped 95% (circuit_create): Establishing a Tor circuit
Apr 19 11:53:32.000 [notice] Bootstrapped 100% (done): Done
siepra commented 5 months ago

It passed on CI (branch based on develop) https://github.com/TryQuiet/quiet/actions/runs/8752750512/job/24021001942 but it keeps getting stuck locally

siepra commented 5 months ago

Android tests seem to get stuck randomly https://github.com/TryQuiet/quiet/actions/runs/8752477080/job/24020210754 (creates new channel) https://github.com/TryQuiet/quiet/actions/runs/8752631194/job/24021747993?pr=2453 (deletes channel) They also seem not to finish until timeout

siepra commented 5 months ago

All the above are caused by detaching state-manager's sagas, which is caused by recent web socket connection adjustments made for Detox.

siepra commented 5 months ago

Here's a fix for Android https://github.com/TryQuiet/quiet/pull/2453