okTurtles / group-income

A decentralized and private (end-to-end encrypted) financial safety net for you and your friends.
https://groupincome.org
GNU Affero General Public License v3.0
330 stars 43 forks source link

Failure to join user on testing server #2159

Open taoeffect opened 2 months ago

taoeffect commented 2 months ago

Problem

In a private window I joined a new user to the testing group that was running 0.6.0:

Screenshot 2024-07-05 at 10 28 44 AM

Below you can see there's a deadlock in the invocation queue, and you can also see an error at the bottom that appeared after @corrideat joined another user to the group while this deadlock was happening:

Screenshot 2024-07-05 at 10 32 43 AM

Here is the stuck queue itself:

{
  "publish:z9brRu3VWcf9QG6AFiKNyGLs6q11GC9GSMEaydEJxaffMxYj3bCM": [],
  "z9brRu3VWcf9QG6AFiKNyGLs6q11GC9GSMEaydEJxaffMxYj3bCM": [
    [
      "chelonia/private/invoke",
      {},
      null
    ]
  ],
  "chelonia/db/z9brRu3VWcf9QG6AFiKNyGLs6q11GC9GSMEaydEJxaffMxYj3bCM": [],
  "kv-queue": [],
  "z9brRu3VK66SjfpzY4bFKnTbVW9mr2SzUXJfM2kxJqoQVuhwtyk4": [
    [
      "chelonia/private/invoke",
      {},
      [
        "chelonia/private/in/syncContract",
        "z9brRu3VK66SjfpzY4bFKnTbVW9mr2SzUXJfM2kxJqoQVuhwtyk4"
      ]
    ],
    [
      "chelonia/private/invoke",
      {},
      [
        "chelonia/private/noop"
      ]
    ],
    [
      "chelonia/private/invoke",
      {},
      [
        "chelonia/private/in/syncContract",
        "z9brRu3VK66SjfpzY4bFKnTbVW9mr2SzUXJfM2kxJqoQVuhwtyk4",
        {
          "force": true
        }
      ]
    ],
    [
      "chelonia/private/invoke",
      {},
      null
    ],
    [
      "chelonia/private/invoke",
      {},
      null
    ],
    [
      "chelonia/private/invoke",
      {},
      null
    ],
    [
      "chelonia/private/invoke",
      {},
      null
    ],
    [
      "chelonia/private/invoke",
      {},
      null
    ],
    [
      "chelonia/private/invoke",
      {},
      null
    ]
  ],
  "public:z9brRu3VK66SjfpzY4bFKnTbVW9mr2SzUXJfM2kxJqoQVuhwtyk4": [],
  "public:z9brRu3VWcf9QG6AFiKNyGLs6q11GC9GSMEaydEJxaffMxYj3bCM": [],
  "chelonia/db/z9brRu3VK66SjfpzY4bFKnTbVW9mr2SzUXJfM2kxJqoQVuhwtyk4": [],
  "encrypted-action": [],
  "JOIN_GROUP-z9brRu3VK66SjfpzY4bFKnTbVW9mr2SzUXJfM2kxJqoQVuhwtyk4": [],
  "publish:z9brRu3VK66SjfpzY4bFKnTbVW9mr2SzUXJfM2kxJqoQVuhwtyk4": []
}

The anonymous async function for the 2nd broken queue (the one for the identity contract that has chelonia/private/invoke stuck) is from here in internals.js:

Screenshot 2024-07-05 at 10 33 39 AM

Screenshot 2024-07-05 at 10 33 25 AM

The first stuck queue is the group contractID:

Screenshot 2024-07-05 at 10 34 40 AM

The second stuck queue is the identity contract of the user that just joined (my test user that got stuck):

Screenshot 2024-07-05 at 10 35 37 AM

Refreshing the page results in a spinning group income spinner and no error logs. Unregistering the service worker and refreshing again still results in the same problem:

Screenshot 2024-07-05 at 10 42 34 AM

The console logs with /app/?debug=true:

[sbp] chelonia/config []
state.js:608 registering getters for 'gi.contracts/group' (z9brRu3VMBcjcPy2d5pH1YAzEQdv8tG76MXHGqs8tYLLoo9JsApH)
main.js:89 [sbp] chelonia/private/loadManifest (2) ['gi.contracts/identity', 'z9brRu3VPTrb4aGvoCnSLBL1oT8rLHSbRonHNRLLgg4ar187V9iN']
sw-primary.js:23 [sw] fetch : GET - https://testing.groupincome.org/file/z9brRu3VPTrb4aGvoCnSLBL1oT8rLHSbRonHNRLLgg4ar187V9iN
main.js:89 [sbp] chelonia/private/verifyManifestSignature (3) ['gi.contracts/identity', 'z9brRu3VPTrb4aGvoCnSLBL1oT8rLHSbRonHNRLLgg4ar187V9iN', {…}]
internals.js:211 [chelonia] verifying signature for z9brRu3VPTrb4aGvoCnSLBL1oT8rLHSbRonHNRLLgg4ar187V9iN (named gi.contracts/identity) for the first time
internals.js:231 [chelonia] successful signature verification for z9brRu3VPTrb4aGvoCnSLBL1oT8rLHSbRonHNRLLgg4ar187V9iN (named gi.contracts/identity) using z2DrjgbCDg34SaBhFjNEF45AVodCUu7QwcFBksz3BDgN4BekrdN. The following key IDs will now be trusted for this contract name ['z2DrjgbCDg34SaBhFjNEF45AVodCUu7QwcFBksz3BDgN4BekrdN']
internals.js:260 [chelonia] loading contract 'identity-slim.js'@'0.6.0' from manifest: z9brRu3VPTrb4aGvoCnSLBL1oT8rLHSbRonHNRLLgg4ar187V9iN
sw-primary.js:23 [sw] fetch : GET - https://testing.groupincome.org/file/z9brRu3VPYGaiYhWjCDKEn4at4SJyUCLNqBfZAHJY5QmJSJ42gJv
main.js:89 [sbp] chelonia/defineContract [{…}]
main.js:89 [sbp] okTurtles.events/emit (2) ['contract-registered', {…}]
main.js:89 [sbp] chelonia/config []
state.js:608 registering getters for 'gi.contracts/identity' (z9brRu3VPTrb4aGvoCnSLBL1oT8rLHSbRonHNRLLgg4ar187V9iN)
main.js:89 [sbp] chelonia/connect [{…}]
main.js:89 [sbp] chelonia/private/startClockSync []
main.js:89 [sbp] okTurtles.events/on (2) ['contracts-modified', ƒ]
main.js:89 [sbp] translations/init ['en-US']
main.js:89 [sbp] service-workers/setup []
sw-primary.js:23 [sw] fetch : GET - https://testing.groupincome.org/time
sw-primary.js:43 [sw] message from cb38e3f6-e563-4749-bb74-e5fa1c35f286. Current store: {clientId: '4ad51f84-191f-4d86-b790-f59095cec9e0'}
sw-primary.js:47 [sw] event received: {type: 'store-client-id'}
main.js:89 [sbp] okTurtles.events/on (2) ['open-modal', ƒ]
main.js:89 [sbp] okTurtles.events/on (2) ['close-modal', ƒ]
main.js:89 [sbp] okTurtles.events/on (2) ['replace-modal', ƒ]
main.js:89 [sbp] okTurtles.events/on (2) ['set-modal-queries', ƒ]
main.js:89 [sbp] okTurtles.events/on (2) ['message-receive', ƒ]
main.js:89 [sbp] okTurtles.events/on (2) ['message-send', ƒ]
main.js:89 [sbp] gi.periodicNotifications/importNotifications [Array(3)]
main.js:89 [sbp] okTurtles.events/off (2) ['contract-is-syncing', ƒ]
main.js:89 [sbp] okTurtles.events/on (2) ['contract-is-syncing', ƒ]
main.js:89 [sbp] okTurtles.events/on (2) ['login', ƒ]
main.js:89 [sbp] okTurtles.events/on (2) ['logout', ƒ]
main.js:89 [sbp] okTurtles.events/once (2) ['login-error', ƒ]
main.js:89 [sbp] okTurtles.events/on (2) ['login-error', ƒ]
main.js:89 [sbp] okTurtles.events/on (2) ['switch-group', ƒ]
main.js:89 [sbp] okTurtles.events/emit (2) ['theme-change', 'dark']
main.js:89 [sbp] gi.db/settings/load ['@settings/currentUser']
sw-primary.js:23 [sw] fetch : GET - https://testing.groupincome.org/assets/images/group-income-icon-transparent.png
sw-primary.js:23 [sw] fetch : GET - https://testing.groupincome.org/assets/audio/msg-received.mp3
sw-primary.js:23 [sw] fetch : GET - https://testing.groupincome.org/assets/audio/msg-sent.mp3
pubsub.js:349 [pubsub] Event: open
main.js:89 [sbp] okTurtles.events/emit (2) ['pubsub-reconnection-succeeded', {…}]
pubsub.js:378 [pubsub] Connection re-established
main.js:89 [sbp] gi.ui/clearBanner []
main.js:220 VERSION_INFO received: {ourVersion: '0.6.0', theirVersion: '0.6.0', ourContractsVersion: '0.6.0', theirContractsVersion: '0.6.0'}

Solution

Identify the deadlock that happens on joining the group and fix.

taoeffect commented 2 months ago

Fixing the 2nd problem that happens after refreshing the page seems very difficult because it's likely a browser bug.

After using the debugger @corrideat and I were able to narrow it down to these lines:

main.js:

      // Now that the app is ready, we proceed to call /login (which will restore
      // the user's session, if they are already logged in)
      // Since this is asynchronous, we must check this.ephemeral.finishedLogin
      // to ensure that we don't override user interactions that have already
      // happened (an example where things can happen this quickly is in the
      // tests).
      sbp('gi.db/settings/load', SETTING_CURRENT_USER).then(identityContractID => {

And then it's getting stuck waiting on the promise returned by 'gi.db/settings/load' (in frontend/model/database.js) which is waiting on IndexedDB:

  'gi.db/settings/load': function (user        )               {
    return appSettings.getItem(user)
  },

I also couldn't view the IndexedDB in the developer tools, clicking on it did nothing:

Screenshot 2024-07-05 at 11 04 34 AM

It seems like a browser bug in either localforage, or more likely Brave or Chromium.

FWIW @corrideat removes localforage in #2137, but I don't think that will fix this issue since it's likely a browser bug. 😕