jeopardy-bot icon indicating copy to clipboard operation
jeopardy-bot copied to clipboard
verified publisher icon kesne

[docker] client dies after a while

Open fwenzel opened this issue 6 years ago • 11 comments

Seems like the service dies on occasion and needs to be restarted.

The end of docker logs:

jeopardybot_1  | JeopardyBot connected to Slack instance.
jeopardybot_1  | Attempting to generate a new board from episode link http://www.j-archive.com/showgame.php?game_id=4834
jeopardybot_1  | Attempting to generate a new board from episode link http://www.j-archive.com/showgame.php?game_id=1718
jeopardybot_1  | (node:1) UnhandledPromiseRejectionWarning: Error: An API error occurred: message_not_found
jeopardybot_1  |     at platformErrorFromResult (/app/node_modules/@slack/client/dist/WebClient.js:747:42)
jeopardybot_1  |     at __await.makeRequest.then (/app/node_modules/@slack/client/dist/WebClient.js:464:39)
jeopardybot_1  |     at process._tickCallback (internal/process/next_tick.js:68:7)
jeopardybot_1  | (node:1) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). (rejection id: 2)
jeopardybot_1  | (node:1) [DEP0018] DeprecationWarning: Unhandled promise rejections are deprecated. In the future, promise rejections that are not handled will terminate theNode.js process with a non-zero exit code.
jeopardybot_1  | (node:1) UnhandledPromiseRejectionWarning: Error: An API error occurred: message_not_found
jeopardybot_1  |     at platformErrorFromResult (/app/node_modules/@slack/client/dist/WebClient.js:747:42)
jeopardybot_1  |     at __await.makeRequest.then (/app/node_modules/@slack/client/dist/WebClient.js:464:39)
jeopardybot_1  |     at process._tickCallback (internal/process/next_tick.js:68:7)
jeopardybot_1  | (node:1) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). (rejection id: 4)
jeopardybot_1  | (node:1) UnhandledPromiseRejectionWarning: Error: An API error occurred: message_not_found
jeopardybot_1  |     at platformErrorFromResult (/app/node_modules/@slack/client/dist/WebClient.js:747:42)
jeopardybot_1  |     at __await.makeRequest.then (/app/node_modules/@slack/client/dist/WebClient.js:464:39)
jeopardybot_1  |     at process._tickCallback (internal/process/next_tick.js:68:7)
jeopardybot_1  | (node:1) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). (rejection id: 6)
jeopardybot_1  | (node:1) UnhandledPromiseRejectionWarning: Error: An API error occurred: message_not_found
jeopardybot_1  |     at platformErrorFromResult (/app/node_modules/@slack/client/dist/WebClient.js:747:42)
jeopardybot_1  |     at __await.makeRequest.then (/app/node_modules/@slack/client/dist/WebClient.js:464:39)
jeopardybot_1  |     at process._tickCallback (internal/process/next_tick.js:68:7)
jeopardybot_1  | (node:1) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). (rejection id: 8)
jeopardybot_1  | (node:1) UnhandledPromiseRejectionWarning: Error: An API error occurred: message_not_found
jeopardybot_1  |     at platformErrorFromResult (/app/node_modules/@slack/client/dist/WebClient.js:747:42)
jeopardybot_1  |     at __await.makeRequest.then (/app/node_modules/@slack/client/dist/WebClient.js:464:39)
jeopardybot_1  |     at process._tickCallback (internal/process/next_tick.js:68:7)
jeopardybot_1  | (node:1) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). (rejection id: 10)
jeopardybot_1  | (node:1) UnhandledPromiseRejectionWarning: Error: An API error occurred: message_not_found
jeopardybot_1  |     at platformErrorFromResult (/app/node_modules/@slack/client/dist/WebClient.js:747:42)
jeopardybot_1  |     at __await.makeRequest.then (/app/node_modules/@slack/client/dist/WebClient.js:464:39)
jeopardybot_1  |     at process._tickCallback (internal/process/next_tick.js:68:7)
jeopardybot_1  | (node:1) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). (rejection id: 12)
jeopardybot_1  | JeopardyBot connected to Slack instance.
jeopardybot_1  | (node:1) UnhandledPromiseRejectionWarning: Error: An API error occurred: message_not_found
jeopardybot_1  |     at platformErrorFromResult (/app/node_modules/@slack/client/dist/WebClient.js:747:42)
jeopardybot_1  |     at __await.makeRequest.then (/app/node_modules/@slack/client/dist/WebClient.js:464:39)
jeopardybot_1  |     at process._tickCallback (internal/process/next_tick.js:68:7)
jeopardybot_1  | (node:1) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). (rejection id: 14)
jeopardybot_1  | (node:1) UnhandledPromiseRejectionWarning: Error: An API error occurred: message_not_found
jeopardybot_1  |     at platformErrorFromResult (/app/node_modules/@slack/client/dist/WebClient.js:747:42)
jeopardybot_1  |     at __await.makeRequest.then (/app/node_modules/@slack/client/dist/WebClient.js:464:39)
jeopardybot_1  |     at process._tickCallback (internal/process/next_tick.js:68:7)
jeopardybot_1  | (node:1) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). (rejection id: 16)
jeopardybot_1  | (node:1) UnhandledPromiseRejectionWarning: Error: An API error occurred: message_not_found
jeopardybot_1  |     at platformErrorFromResult (/app/node_modules/@slack/client/dist/WebClient.js:747:42)
jeopardybot_1  |     at __await.makeRequest.then (/app/node_modules/@slack/client/dist/WebClient.js:464:39)
jeopardybot_1  |     at process._tickCallback (internal/process/next_tick.js:68:7)
jeopardybot_1  | (node:1) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). (rejection id: 18)
jeopardybot_1  | (node:1) UnhandledPromiseRejectionWarning: Error: An API error occurred: message_not_found
jeopardybot_1  |     at platformErrorFromResult (/app/node_modules/@slack/client/dist/WebClient.js:747:42)
jeopardybot_1  |     at __await.makeRequest.then (/app/node_modules/@slack/client/dist/WebClient.js:464:39)
jeopardybot_1  |     at process._tickCallback (internal/process/next_tick.js:68:7)
jeopardybot_1  | (node:1) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). (rejection id: 20)

fwenzel avatar May 06 '19 17:05 fwenzel

Then I do a docker-compose restart and new game works again:

jeopardybot_1  | Store state successfully persisted!
jeopardybot_1  | HTTP server started.
jeopardybot_1  | JeopardyBot connected to Slack instance.
jeopardybot_1  | Attempting to generate a new board from episode link http://www.j-archive.com/showgame.php?game_id=4182

fwenzel avatar May 06 '19 17:05 fwenzel

Looks like it’s an issue with the storage system. I’m guessing that the loop-hole I used was patched up. I’ll try to find a workaround.

kesne avatar May 07 '19 17:05 kesne

ooo storage to save state on slack itself? Can the bot send a message to itself and edit that message as needed?

fwenzel avatar May 08 '19 01:05 fwenzel

Lol this is exactly what it does: https://github.com/kesne/jeopardy-bot/blob/master/src/CleverPersistence.ts

kesne avatar May 08 '19 03:05 kesne

@fwenzel I updated some of the error handling and added logging around persistence. Can you try the latest code or container and see if it resolves the issue? I also just booted a long-running container to see if I can reproduce it.

kesne avatar May 12 '19 05:05 kesne

ah good call; I'll update the container (what's the docker-compose command for that 🤔) and see.

It just died again, oddly, one of the people in the room says it works if you add it to a new channel. So maybe the new client code also helps.

fwenzel avatar May 13 '19 21:05 fwenzel

I'm not sure about the command, maybe re-pull the image or something? Compose might want you to run rebuild too. The image is a lot smaller now, as an added benefit.

kesne avatar May 13 '19 22:05 kesne 

ESC[36mjeopardybot_1  |ESC[0m Persisting Jeopardy state...
ESC[36mjeopardybot_1  |ESC[0m Persisting Jeopardy state...
ESC[36mjeopardybot_1  |ESC[0m Persisting Jeopardy state...
ESC[36mjeopardybot_1  |ESC[0m Persisting Jeopardy state...
ESC[36mjeopardybot_1  |ESC[0m Failed at deleting old history messages.
ESC[36mjeopardybot_1  |ESC[0m { Error: An API error occurred: message_not_found
ESC[36mjeopardybot_1  |ESC[0m     at Object.platformErrorFromResult (/app/node_modules/@slack/web-api/dist/errors.js:50:33)
ESC[36mjeopardybot_1  |ESC[0m     at WebClient.apiCall (/app/node_modules/@slack/web-api/dist/WebClient.js:374:28)
ESC[36mjeopardybot_1  |ESC[0m     at process._tickCallback (internal/process/next_tick.js:68:7)
ESC[36mjeopardybot_1  |ESC[0m   code: 'slack_webapi_platform_error',
ESC[36mjeopardybot_1  |ESC[0m   data:
ESC[36mjeopardybot_1  |ESC[0m    { ok: false,
ESC[36mjeopardybot_1  |ESC[0m      error: 'message_not_found',
ESC[36mjeopardybot_1  |ESC[0m      response_metadata: { scopes: [Array], acceptedScopes: [Array] } } }
ESC[36mjeopardybot_1  |ESC[0m Persisting Jeopardy state...
ESC[36mjeopardybot_1  |ESC[0m Persisting Jeopardy state...
ESC[36mjeopardybot_1  |ESC[0m Persisting Jeopardy state...
ESC[36mjeopardybot_1  |ESC[0m Persisting Jeopardy state...
ESC[36mjeopardybot_1  |ESC[0m Persisting Jeopardy state...
ESC[36mjeopardybot_1  |ESC[0m Persisting Jeopardy state...

fwenzel avatar May 15 '19 01:05 fwenzel

persistence and restore after restart seems to work mostly?

fwenzel avatar May 15 '19 01:05 fwenzel

Okay a little more info when this happens, the bot is not dead nor disconnected. In the channel, someone says "new game" and the logs show: Attempting to generate a new board from episode link http://www.j-archive.com/showgame.php?game_id=4417

but nothing further happens, no more logs and no output in the channel.

The logs then continue periodically as expected:

ESC[36mjeopardybot_1  |ESC[0m Persisting Jeopardy state...
ESC[36mjeopardybot_1  |ESC[0m Persisting Jeopardy state...
ESC[36mjeopardybot_1  |ESC[0m Persisting Jeopardy state...
ESC[36mjeopardybot_1  |ESC[0m Persisting Jeopardy state...

fwenzel avatar May 15 '19 21:05 fwenzel

dumping more context here (for my reference or anyone who wants to fix it). Channel behavior when this happens:

image

fwenzel avatar May 23 '19 17:05 fwenzel