Error upon manual payment registration

[snowteamer]

Problem

The following error showed up after I registered a manual payment:

Here are the accompanying logs: gi_logs.zip

The error was also visible in the browser console:

[taoeffect]

Interesting, here's the log you uploaded @snowteamer:

$ cat gi_logs.json | jq '.logs | .[] | .msg | if length == 1 then .[0] else .[0], .[1:] end' 
"[pubsub] Connection re-established"
"[chelonia] loading contract 'group-slim.js'@'0.1.0' from manifest: 21XWnNL8ZgB2KqtKgAimKMRe6sMhb7kVGFMRGPbztb3rgGEZmB"
"[pubsub] Event: error"
[
  {
    "isTrusted": true
  }
]
"[pubsub] Scheduled connection attempt 1 in ~955 ms"
"[pubsub] Trying to reconnect..."
"[pubsub] Event: error"
[
  {
    "isTrusted": true
  }
]
"[pubsub] Scheduled connection attempt 2 in ~1013 ms"
"[pubsub] Trying to reconnect..."
"[pubsub] Connection re-established"
"[chelonia] loading contract 'chatroom-slim.js'@'0.1.0' from manifest: 21XWnNSmVduYCvua7PERV6Z433kt6fXbFgcXNkZGCgq5aaNjJq"
"[chelonia] ERROR: 'Error' [chelonia] selector not on allowlist: '21XWnNL8ZgB2KqtKgAimKMRe6sMhb7kVGFMRGPbztb3rgGEZmB/gi.contracts/group/archivePayments', for pushed sideEffect of <op_ae|21XWnNY3KUTnok1m9w869njdy4XX8yPgE4bpar7e3bhgemQFhq of 21XWnNWZzYYPfezAq9HN85b4by9TWt3o5GPUVzw9baSVjeQ49w>:"
[
  [
    "21XWnNL8ZgB2KqtKgAimKMRe6sMhb7kVGFMRGPbztb3rgGEZmB/gi.contracts/group/archivePayments",
    "21XWnNWZzYYPfezAq9HN85b4by9TWt3o5GPUVzw9baSVjeQ49w",
    {
      "paymentsByPeriod": {},
      "payments": {}
    }
  ]
]
"[chelonia] ERROR 'Error' in sideEffect for <op_ae|21XWnNY3KUTnok1m9w869njdy4XX8yPgE4bpar7e3bhgemQFhq of 21XWnNWZzYYPfezAq9HN85b4by9TWt3o5GPUVzw9baSVjeQ49w>: [chelonia] selector not on allowlist: '21XWnNL8ZgB2KqtKgAimKMRe6sMhb7kVGFMRGPbztb3rgGEZmB/gi.contracts/group/archivePayments'"
[
  "p@https://live.groupincome.org/assets/js/chunk-FUA6HVJS-cached.js:1:8202\n21XWnNVnVCvQgNsJYNz3t65WeKhDhmngueCoFt6spZHemb62Z2/gi.contracts/group/payment/sideEffect@https://live.groupincome.org/assets/js/chunk-FUA6HVJS-cached.js:17:18218\nu@https://live.groupincome.org/assets/js/chunk-SSANYCJJ-cached.js:1:222\nprocessSideEffects@https://live.groupincome.org/assets/js/chunk-FUA6HVJS-cached.js:17:6515\nchelonia/private/in/handleEvent@https://live.groupincome.org/assets/js/chunk-FUA6HVJS-cached.js:17:4627\n",
  {
    "message": "{\"message\":\"{\\\"version\\\":\\\"1.0.0\\\",\\\"previousHEAD\\\":\\\"21XWnNGDMmboFxeeTFRjeej5BavP1Qq8bGLYRnYzS5xWjBhFzY\\\",\\\"contractID\\\":\\\"21XWnNWZzYYPfezAq9HN85b4by9TWt3o5GPUVzw9baSVjeQ49w\\\",\\\"op\\\":[\\\"ae\\\",\\\"{\\\\\\\"action\\\\\\\":\\\\\\\"gi.contracts/group/payment\\\\\\\",\\\\\\\"data\\\\\\\":{\\\\\\\"toUser\\\\\\\":\\\\\\\"aeons\\\\\\\",\\\\\\\"amount\\\\\\\":21.27659574,\\\\\\\"total\\\\\\\":21.27659574,\\\\\\\"isLate\\\\\\\":false,\\\\\\\"partial\\\\\\\":false,\\\\\\\"currencyFromTo\\\\\\\":[\\\\\\\"USD\\\\\\\",\\\\\\\"USD\\\\\\\"],\\\\\\\"exchangeRate\\\\\\\":1,\\\\\\\"txid\\\\\\\":\\\\\\\"0.5390088792294749\\\\\\\",\\\\\\\"status\\\\\\\":\\\\\\\"pending\\\\\\\",\\\\\\\"paymentType\\\\\\\":\\\\\\\"manual\\\\\\\"},\\\\\\\"meta\\\\\\\":{\\\\\\\"createdDate\\\\\\\":\\\\\\\"2023-05-31T17:54:55.680Z\\\\\\\",\\\\\\\"username\\\\\\\":\\\\\\\"snowteamer\\\\\\\",\\\\\\\"identityContractID\\\\\\\":\\\\\\\"21XWnNRE8WzmC9EFFVyEsRPtFu5LWQAQHQSEqCPMt2W5CshieQ\\\\\\\"}}\\\"],\\\"manifest\\\":\\\"21XWnNVnVCvQgNsJYNz3t65WeKhDhmngueCoFt6spZHemb62Z2\\\",\\\"nonce\\\":\\\"ca346e72-eace-4f4f-8b32-ff884ce45b1a\\\"}\",\"sig\":{\"type\":\"default\",\"sig\":\"21XWnNTpmfALe1rbv15W3KaJ6AN7w1txMCG2MCxho1Vx1fRjCd\"}}"
  }
]
"[pubsub] Connection re-established"

Notice the offending message is a gi.contracts/group/payment which uses a manifest of 21XWnNVnVCvQgNsJYNz3t65WeKhDhmngueCoFt6spZHemb62Z2 (2Z2) which is for group.js@0.1.4, but the selector that's not on the allowlist uses a manifest of 21XWnNL8ZgB2KqtKgAimKMRe6sMhb7kVGFMRGPbztb3rgGEZmB (ZmB), which is for group.js@0.1.0

In other words, the message that was received is for 2Z2 which is group.js version 0.1.4, and yet the selector that got called was for the old 0.1.0 version of the contract.

Other lines in the log show, just before the error, show:

"[pubsub] Scheduled connection attempt 2 in ~1013 ms"
"[pubsub] Trying to reconnect..."
"[pubsub] Connection re-established"
"[chelonia] loading contract 'chatroom-slim.js'@'0.1.0' from manifest: 21XWnNSmVduYCvua7PERV6Z433kt6fXbFgcXNkZGCgq5aaNjJq"

We would normally expect to see a loading message somewhere that says you loaded 0.1.4 of the contracts, but we don't see that. Even weirder, is that you generated the message that was sent, that is a 0.1.4 (manifest 2Z2) message!

I am very confused but feel like I'm making some progress. Somehow you generated a message using the latest version of the contracts, but an old version of the contracts is actually being run when processing this message? Very confusing. Progress though.

[taoeffect]

OK, while I don't understand how it's possible that this happened, I do see a possibility for this to happen if we have the following scenario: we process a 0.1.0 message, then a 0.1.4 message, then a 0.1.0 message again, which is possible. Although it would result in a different error than the one you ran into (it would show manifest hash 2Z2 instead of ZmB in the error message). EDIT: I'm actually not sure whether it would show an error message at all... will need to look deeper

Currently 'chelonia/private/loadManifest' will be skipped for that last message, which means that this.defContractSBP will be pointing to the wrong version. That's something I can and should fix, so I'll work on that, and maybe it'll fix this problem too.

[taoeffect]

What I wrote above is incorrect, I think.

I do see a possibility for this to happen if we have the following scenario: we process a 0.1.0 message, then a 0.1.4 message, then a 0.1.0 message again, which is possible.

That should be handled correctly. I am still not sure how this error is possible.

[taoeffect]

Current working theory:

1. The app loaded up with 0.1.4 contracts
2. It got a message for 0.1.0 that it missed, and loaded 0.1.0 contracts
3. Then it created this 0.1.4 message and sent it, received it, and broke for some reason

If this theory is correct, then the problem is related to these lines from chelonia.js:

      [`${contract.manifest}/${contract.name}/pushSideEffect`]: (contractID: string, asyncSbpCall: Array<*>) => {
        // if this version of the contract is pushing a sideEffect to a function defined by the
        // contract itself, make sure that it calls the same version of the sideEffect
        const [sel] = asyncSbpCall
        if (sel.startsWith(contract.name)) {
          asyncSbpCall[0] = `${contract.manifest}/${sel}`
        }
        this.sideEffectStack(contractID).push(asyncSbpCall)
      }

And specifically:

          asyncSbpCall[0] = `${contract.manifest}/${sel}`

Somehow contract.manifest has the wrong value. It should be 2Z2 but is getting ZmB.