Cannot read property 'exitCode' of undefined on private app api access or deployment

[bbreijer]

Description:

After updating the to version 6.11.1 (snap) and updating the API level of our private app to 1.44.0 the issue surfaced.
At some point (after running properly for X time), the server responds with a 500 on a private app api request. After this, app deployment is broken and leads to "Error: Deployment error: Cannot read property 'exitCode' of undefined". See stack trace below.
Private apps page stays empty.

Steps to reproduce:

Not available yet. Seen behavior:

1. App with api level 1.44.0 is deployed
2. Server runs for x amount of time (observed 1:47, 0:20, 00:08)
3. App entrypoint fails with 500 and response "Cannot read property 'exitCode' of undefined"
4. stacktrace present in snap logs

Expected behavior:

Private apps and deployment keep working

Actual behavior:

App api stops working, app deployment stops working. Snap logs show stacktrace (see below).

Server Setup Information:

• Version of Rocket.Chat Server: 6.11.1
• License Type: Community
• Number of Users: 32
• Operating System: Linux (Ubuntu 22.04 LTS)
• Deployment Method: snap
• Number of Running Instances: 1
• DB Replicaset Oplog: Enabled
• NodeJS Version: v14.21.2 - x64
• MongoDB Version: 5.0.15 / wiredTiger (oplog Enabled)

Client Setup Information

Insomnia Rest client: insomnia/8.6.1

Additional context

Stacktrace relates to this line of code:

Rocket.Chat.Apps-engine/src/server/runtime/deno/AppsEngineDenoRuntime.ts

Line 203 in 7c81af6

if (this.deno.exitCode !== null) {

snap restart rocketchat-server temporarily fixes the issue

There was an older (api level not compatible; disabled) private app present, removing this app did not mitigate the issue.

Relevant logs:

_stacktrace_
2024-08-23T10:06:22+02:00 rocketchat-server.rocketchat-server[352766]: === UnHandledPromiseRejection ===
2024-08-23T10:06:22+02:00 rocketchat-server.rocketchat-server[352766]: TypeError: Cannot read property 'exitCode' of undefined
2024-08-23T10:06:22+02:00 rocketchat-server.rocketchat-server[352766]:     at DenoRuntimeSubprocessController.<anonymous> (/snap/rocketchat-server/1620/programs/server/npm/node_modules/@rocket.chat/apps-engine/server/runtime/deno/AppsEngineDenoRuntime.js:162:27)
2024-08-23T10:06:22+02:00 rocketchat-server.rocketchat-server[352766]:     at Generator.next (<anonymous>)
2024-08-23T10:06:22+02:00 rocketchat-server.rocketchat-server[352766]:     at /snap/rocketchat-server/1620/programs/server/npm/node_modules/@rocket.chat/apps-engine/server/runtime/deno/AppsEngineDenoRuntime.js:8:71
2024-08-23T10:06:22+02:00 rocketchat-server.rocketchat-server[352766]:     at new Promise (<anonymous>)
2024-08-23T10:06:22+02:00 rocketchat-server.rocketchat-server[352766]:     at __awaiter (/snap/rocketchat-server/1620/programs/server/npm/node_modules/@rocket.chat/apps-engine/server/runtime/deno/AppsEngineDenoRuntime.js:4:12)
2024-08-23T10:06:22+02:00 rocketchat-server.rocketchat-server[352766]:     at DenoRuntimeSubprocessController.getStatus (/snap/rocketchat-server/1620/programs/server/npm/node_modules/@rocket.chat/apps-engine/server/runtime/deno/AppsEngineDenoRuntime.js:160:16)
2024-08-23T10:06:22+02:00 rocketchat-server.rocketchat-server[352766]:     at ProxiedApp.<anonymous> (/snap/rocketchat-server/1620/programs/server/npm/node_modules/@rocket.chat/apps-engine/server/ProxiedApp.js:78:36)
2024-08-23T10:06:22+02:00 rocketchat-server.rocketchat-server[352766]:     at Generator.next (<anonymous>)
2024-08-23T10:06:22+02:00 rocketchat-server.rocketchat-server[352766]:     at /snap/rocketchat-server/1620/programs/server/npm/node_modules/@rocket.chat/apps-engine/server/ProxiedApp.js:8:71
2024-08-23T10:06:22+02:00 rocketchat-server.rocketchat-server[352766]:     at new Promise (<anonymous>)
2024-08-23T10:06:22+02:00 rocketchat-server.rocketchat-server[352766]:     at __awaiter (/snap/rocketchat-server/1620/programs/server/npm/node_modules/@rocket.chat/apps-engine/server/ProxiedApp.js:4:12)
2024-08-23T10:06:22+02:00 rocketchat-server.rocketchat-server[352766]:     at ProxiedApp.getStatus (/snap/rocketchat-server/1620/programs/server/npm/node_modules/@rocket.chat/apps-engine/server/ProxiedApp.js:77:16)
2024-08-23T10:06:22+02:00 rocketchat-server.rocketchat-server[352766]:     at ee/lib/misc/formatAppInstanceForRest.ts:20:21
2024-08-23T10:06:22+02:00 rocketchat-server.rocketchat-server[352766]:     at /snap/rocketchat-server/1620/programs/server/npm/node_modules/meteor/promise/node_modules/meteor-promise/fiber_pool.js:43:40
2024-08-23T10:06:22+02:00 rocketchat-server.rocketchat-server[352766]:  => awaited here:
2024-08-23T10:06:22+02:00 rocketchat-server.rocketchat-server[352766]:     at Function.Promise.await (/snap/rocketchat-server/1620/programs/server/npm/node_modules/meteor/promise/node_modules/meteor-promise/promise_server.js:56:12)
2024-08-23T10:06:22+02:00 rocketchat-server.rocketchat-server[352766]:     at ee/lib/misc/formatAppInstanceForRest.ts:20:9
2024-08-23T10:06:22+02:00 rocketchat-server.rocketchat-server[352766]:     at /snap/rocketchat-server/1620/programs/server/npm/node_modules/meteor/promise/node_modules/meteor-promise/fiber_pool.js:43:40
2024-08-23T10:06:22+02:00 rocketchat-server.rocketchat-server[352766]: ---------------------------------
2024-08-23T10:06:22+02:00 rocketchat-server.rocketchat-server[352766]: Errors like this can cause oplog processing errors.
2024-08-23T10:06:22+02:00 rocketchat-server.rocketchat-server[352766]: Setting EXIT_UNHANDLEDPROMISEREJECTION will cause the process to exit allowing your service to automatically restart the process
2024-08-23T10:06:22+02:00 rocketchat-server.rocketchat-server[352766]: Future node.js versions will automatically exit the process
2024-08-23T10:06:22+02:00 rocketchat-server.rocketchat-server[352766]: =================================

possibly relevant
2024-08-23T10:36:30+02:00 rocketchat-server.rocketchat-server[358274]: Subprocess stderr TypeError: r is not iterable
2024-08-23T10:36:30+02:00 rocketchat-server.rocketchat-server[358274]:     at eval (eval at wrapAppCode (file:///snap/rocketchat-server/1620/programs/server/npm/node_modules/@rocket.chat/apps-engine/deno-runtime/handlers/app/construct.ts:56:10), <anonymous>:17:2187)
2024-08-23T10:36:30+02:00 rocketchat-server.rocketchat-server[358274]:     at eventLoopTick (ext:core/01_core.js:183:11)
2024-08-23T10:36:30+02:00 rocketchat-server.rocketchat-server[358274]:     at async y.post (eval at wrapAppCode (file:///snap/rocketchat-server/1620/programs/server/npm/node_modules/@rocket.chat/apps-engine/deno-runtime/handlers/app/construct.ts:56:10), <anonymous>:17:359)
2024-08-23T10:36:30+02:00 rocketchat-server.rocketchat-server[358274]:     at async apiHandler (file:///snap/rocketchat-server/1620/programs/server/npm/node_modules/@rocket.chat/apps-engine/deno-runtime/handlers/api-handler.ts:30:24)
2024-08-23T10:36:30+02:00 rocketchat-server.rocketchat-server[358274]:     at async requestRouter (file:///snap/rocketchat-server/1620/programs/server/npm/node_modules/@rocket.chat/apps-engine/deno-runtime/main.ts:73:20)

before failure (seems to be the last message processed)
2024-08-23T10:56:30+02:00 rocketchat-server.rocketchat-server[358274]: [app-uuid] Error executing handler Error: No process configured to receive a message
2024-08-23T10:56:30+02:00 rocketchat-server.rocketchat-server[358274]:     at ProcessMessenger.strategyError (/snap/rocketchat-server/1620/programs/server/npm/node_modules/@rocket.chat/apps-engine/server/runtime/deno/ProcessMessenger.js:31:15)
2024-08-23T10:56:30+02:00 rocketchat-server.rocketchat-server[358274]:     at DenoRuntimeSubprocessController.<anonymous> (/snap/rocketchat-server/1620/programs/server/npm/node_modules/@rocket.chat/apps-engine/server/runtime/deno/AppsEngineDenoRuntime.js:381:32)
2024-08-23T10:56:30+02:00 rocketchat-server.rocketchat-server[358274]:     at Generator.next (<anonymous>)
2024-08-23T10:56:30+02:00 rocketchat-server.rocketchat-server[358274]:     at fulfilled (/snap/rocketchat-server/1620/programs/server/npm/node_modules/@rocket.chat/apps-engine/server/runtime/deno/AppsEngineDenoRuntime.js:5:58)
2024-08-23T10:56:30+02:00 rocketchat-server.rocketchat-server[358274]:     at /snap/rocketchat-server/1620/programs/server/npm/node_modules/meteor/promise/node_modules/meteor-promise/fiber_pool.js:43:40 {
2024-08-23T10:56:30+02:00 rocketchat-server.rocketchat-server[358274]:   jsonrpc: '2.0',
2024-08-23T10:56:30+02:00 rocketchat-server.rocketchat-server[358274]:   id: '9tuvio1f83s',
2024-08-23T10:56:30+02:00 rocketchat-server.rocketchat-server[358274]:   method: 'bridges:getMessageBridge:doCreate',
2024-08-23T10:56:30+02:00 rocketchat-server.rocketchat-server[358274]:   params: [
2024-08-23T10:56:30+02:00 rocketchat-server.rocketchat-server[358274]:     {
2024-08-23T10:56:30+02:00 rocketchat-server.rocketchat-server[358274]:       attachments: [],
2024-08-23T10:56:30+02:00 rocketchat-server.rocketchat-server[358274]:       alias: 'grafana',
2024-08-23T10:56:30+02:00 rocketchat-server.rocketchat-server[358274]:       text: ' <<message>>',
2024-08-23T10:56:30+02:00 rocketchat-server.rocketchat-server[358274]:       room: [Object],
2024-08-23T10:56:30+02:00 rocketchat-server.rocketchat-server[358274]:       sender: [Object]
2024-08-23T10:56:30+02:00 rocketchat-server.rocketchat-server[358274]:     },
2024-08-23T10:56:30+02:00 rocketchat-server.rocketchat-server[358274]:     'app-uuid'
2024-08-23T10:56:30+02:00 rocketchat-server.rocketchat-server[358274]:   ]
2024-08-23T10:56:30+02:00 rocketchat-server.rocketchat-server[358274]: }
2024-08-23T10:56:40+02:00 rocketchat-server.rocketchat-server[358274]: Error: [app-uuid] Request "0ewtfp6dxi3v" for method "api:api:post" timed out
2024-08-23T10:56:40+02:00 rocketchat-server.rocketchat-server[358274]:     at Timeout._onTimeout (/snap/rocketchat-server/1620/programs/server/npm/node_modules/@rocket.chat/apps-engine/server/runtime/deno/AppsEngineDenoRuntime.js:239:24)
2024-08-23T10:56:40+02:00 rocketchat-server.rocketchat-server[358274]:     at listOnTimeout (internal/timers.js:557:17)
2024-08-23T10:56:40+02:00 rocketchat-server.rocketchat-server[358274]:     at processTimers (internal/timers.js:500:7)

sometimes before "Error executing handler ..." stacktrace
2024-08-23T11:46:30+02:00 rocketchat-server.rocketchat-server[359050]: Subprocess stderr error: Uncaught (in promise) TypeError: r is not iterable
2024-08-23T11:46:30+02:00 rocketchat-server.rocketchat-server[359050]:     at eval (eval at wrapAppCode (file:///snap/rocketchat-server/1620/programs/server/npm/node_modules/@rocket.chat/apps-engine/deno-runtime/handlers/app/construct.ts:56:10), <anonymous>:17:2161)
2024-08-23T11:46:30+02:00 rocketchat-server.rocketchat-server[359050]:     at eventLoopTick (ext:core/01_core.js:183:11)