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:
App with api level 1.44.0 is deployed
Server runs for x amount of time (observed 1:47, 0:20, 00:08)
App entrypoint fails with 500 and response "Cannot read property 'exitCode' of undefined"
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).
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)
Description:
After updating the to version 6.11.1 (snap) and updating the API level of our private app to
1.44.0the 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:
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:
Client Setup Information
Insomnia Rest client: insomnia/8.6.1
Additional context
Stacktrace relates to this line of code: https://github.com/RocketChat/Rocket.Chat.Apps-engine/blob/7c81af699fe5783e13e178046fdee1d677e0ab77/src/server/runtime/deno/AppsEngineDenoRuntime.ts#L203
snap restart rocketchat-servertemporarily fixes the issueThere was an older (api level not compatible; disabled) private app present, removing this app did not mitigate the issue.
Relevant logs: