Program hangs when launching Chromium process

[sigboe]

Describe the bug
I enabled the notification feature in the json file, and I updated/restarted the container.
The log stops at Testing all configured notifiers and doesn't continue. I do not get a notification, I do not know if it is working, I assume its working. When I disable the test notification in the json the log continues through and checks for free games successfully, and starts the cron job.

Screenshots or Logs
Log when the test is enabled.

> epicgames-freegames-node@4.0.0 entrypoint-config /usr/app
> node dist/src/entrypoint-config.js

Setting timezone: Europe/Oslo
Run on startup: true
[2021-10-11 10:03:11.100 +0200] INFO (53 on 70063f6bab4d): Testing all configured notifiers

Log when the test is disabled (set to false)

> epicgames-freegames-node@4.0.0 entrypoint-config /usr/app
> node dist/src/entrypoint-config.js

Setting timezone: Europe/Oslo
Run on startup: true
[2021-10-11 10:08:23.484 +0200] INFO (42 on 70063f6bab4d): Checking free games for REDACTED@gmail.com
[2021-10-11 10:08:30.030 +0200] INFO (42 on 70063f6bab4d): Successfully refreshed login
user: "REDACTED@gmail.com"
[2021-10-11 10:08:30.030 +0200] INFO (42 on 70063f6bab4d): Successfully refreshed login
user: "REDACTED@gmail.com"
[2021-10-11 10:08:33.260 +0200] INFO (42 on 70063f6bab4d): Available free games
user: "REDACTED@gmail.com"
availableGames: [
"PC Building Simulator"
]
[2021-10-11 10:08:33.617 +0200] INFO (42 on 70063f6bab4d): Unpurchased free games
user: "REDACTED@gmail.com"
purchasableGames: []
Run once: false
Setting cron schedule as 8 17 * * *

[claabs]

Can you set "logLevel": "trace"? Hopefully that can show exactly where it's getting stuck.

[sigboe]

@claabs Sadly no more information with log level trace, but the line with testing all configured notifiers is printed twice

> epicgames-freegames-node@4.0.0 entrypoint-config /usr/app
> node dist/src/entrypoint-config.js

Setting timezone: Europe/Oslo
Run on startup: true
[2021-10-11 20:40:10.060 +0200] INFO (53 on 26533ffe07c8): Testing all configured notifiers
[2021-10-11 20:40:10.060 +0200] INFO (53 on 26533ffe07c8): Testing all configured notifiers

[claabs]

Alright, this is gonna be ugly, but can you add the environment variable: DEBUG=* to your Docker config? It's gonna spit out a crapload, but it might at least show something.

[sigboe]

Oh it wasn't that bad

I sent you an email with the logs, I think I redacted all the information but wasn't sure when there was session ID's and similar.

[claabs]

I'm a little stumped. It seems it's just stuck on puppeteer.launch(). I do remember seeing some strange effects on Chromium in Alpine Docker depending on the host OS.

What host OS are you using? It works fine for me in WSL2 and Unraid.

[sigboe]

@claabs I am using unraid

[claabs]

Can you post your config with the sensitive stuff redacted?

[sigboe]

@claabs Here is the command generated by unraids dockerman

root@localhost:# /usr/local/emhttp/plugins/dynamix.docker.manager/scripts/docker run -d --name='epicgames-freegames' --net='bridge' -e TZ="Europe/Berlin" -e HOST_OS="Unraid" -e 'TZ'='Europe/Oslo' -p '3000:3000/tcp' -v '/mnt/user/appdata/epicgames-freegames/':'/usr/app/config':'rw' 'charlocharlie/epicgames-freegames:latest' 

{
  "searchStrategy": "promotion",
  "runOnStartup": true,
  "cronSchedule": "8 17 * * *",
  "logLevel": "trace",
  "testNotifiers": true,
  "hcaptchaAccessibilityUrl": "https://accounts.hcaptcha.com/verify_email/REDACTED",
  "webPortalConfig": {
    "baseUrl": "REDACTED"
  },
  "accounts": [
    {
      "email": "REDACTED",
      "password": "REDACTED",
      "totp": "REDACTED"
    }
  ],
  "notifiers": [
    {
      "type": "discord",
      "webhookUrl": "https://discord.com/api/webhooks/REDACTED/REDACTED"
    }
  ]
}

[claabs]

I have a few ideas that I'm just jotting down so I can try out later:

• The chromium version may have updated in APK, so I either have to upgrade puppeteer, or find a way to pin the chromium version
• maybe it has to do with setting new cookies, which is why I'm not seeing it on my side
• maybe it's a weird Alpine thing, so maybe a Debian image would fix it

[claabs]

I don't think the Chromium version was the issue, as it was already using the correct version. These docs from puppeteer recommended the --disable-dev-shm-usage argument in Alpine, so I added that.

I'm still not able to recreate this on my systems, so please try again when available.

[KairuByte]

Issue #166 is still persisting for me (DEBUG (42 on 95858038f6aa): Setting hCaptcha accessibility cookies) however there is a cookies.json being created.

For shits and giggles I checked with "testNotifiers": true and am seeing similar results to above. (Stalls at INFO (42 on 95858038f6aa): Testing all configured notifiers)

Edit: Actually, after a few restarts it seems to have moved past DEBUG (42 on 95858038f6aa): Setting hCaptcha accessibility cookies and now stalls at DEBUG (42 on 95858038f6aa): Logging in with puppeteer user: "[REDACTED]"

Edit2: A few more restarts and everything seems to just work now? I changed virtually nothing in the config except toggling testNotifiers a few times. Notifiers are now properly running, and everything seems to just work?

Edit3: I have no idea what's going on, I am back to not being able to run test notifications. Apologies for all the edits.

Edit4: I'm at a loss. It did properly go through the ordering of the three available games, then I restarted to correct an issue with the URL I provided for the notification and... it just stalls again. It almost feels like a race condition.

[claabs]

The puppeteer docs recommend adding docker run --cap-add=SYS_ADMIN to your Docker config. Can you try adding that and see if it's any more consistent?

Yeah it's either a race condition or memory related. I'm just surprised I've never run into it myself.

[KairuByte]

Took me a bit to test this, but no change with that flag set.

[claabs]

I published a Debian version of the image to my test tag: charlocharlie/epicgames-freegames-test:bullseye-slim. It uses Debian slim and Chrome rather than Chromium.

Feel free to test it for consistency. If it fixes your issue, I'll publish it to the project's official images.

[KairuByte]

I'm seeing that image work immediately and consistently, but I can't be sure it isn't "just working" as before. Would likely be a good idea to have @sigboe confirm.

[claabs]

I think this is the same as the various issues mentioned in this puppeteer PR fix: puppeteer/puppeteer#7802

Although Alpine doesn't have Chromium 97 that puppeteer 13.0.0 uses, I think Chromium 96 should work okay. At the very least, it's better than Chromium 93 we were using previously.

[claabs]

Scratch that, Chromium 96 doesn't run in Alpine 3.14. We'll have to wait a few days until the Node 3.15 image releases. However puppeteer 13.0.0 still seems to operate in Chromium 93, so maybe it will still be resolved.

[claabs]

I added a fix that will retry launching the browser until it actually works. It's kind of a memory risk as it doesn't actually close the failed launched Chromium process (more here). In my personal testing, I've only seen it retry once, so it sees double the memory usage for the duration of the process.

I'd have to track the process ID of the failed launch, which is kind of tricky. I'll have to dig into it later.

[sigboe]

I don't think I have had the this problem this whole year