bug: "Unexpected Application Error! s is null" + Possible EventEmitter memory leak detected

[Dramatize1154]

Please check existing knowledge before opening an issue

• I have checked the FAQ and documentation
• I have searched through existing issues and discussions.

Describe the Bug

The app should scrobble all plays to Last.FM from Jellyfin when I am using the Gelli android playback client, but instead only the first song played gets scrobbled to Last.FM, and then the web UI of multi-scrobbler indicates a crash.

The live logs in docker don't seem to indicate a problem at the time of the crash, but no further plays after the first song and UI crash are sent to Last.FM.

After the first song completes playback in Gelli, the web UI of multi-scrobbler starts displaying this:

Unexpected Application Error!
s is null

$2@http://localhost:9078/assets/index-BMMuYTIL.js:660:8108
sp@http://localhost:9078/assets/index-BMMuYTIL.js:38:16998
_f@http://localhost:9078/assets/index-BMMuYTIL.js:40:3139
E0@http://localhost:9078/assets/index-BMMuYTIL.js:40:44804
b0@http://localhost:9078/assets/index-BMMuYTIL.js:40:39768
wx@http://localhost:9078/assets/index-BMMuYTIL.js:40:39696
js@http://localhost:9078/assets/index-BMMuYTIL.js:40:39547
Wf@http://localhost:9078/assets/index-BMMuYTIL.js:40:35914
Pm@http://localhost:9078/assets/index-BMMuYTIL.js:40:36717
Wr@http://localhost:9078/assets/index-BMMuYTIL.js:38:3274
Dt/<@http://localhost:9078/assets/index-BMMuYTIL.js:40:34246

Gelli continues playing, this initial song gets scrobbled, multi-scrobbler's UI continues displaying the error, and eventually the docker logs show 'MaxListenersExceededWarning: Possible EventEmitter memory leak detected'. No further scrobbling happens at this point.

This is not an issue when playing music from the web browser client or Jellyfin Media Player (windows client), multi-scrobbler handles the initial and subsequent scribbles as it should. This only occurs when I play from Gelli, and only after updating to 0.8.8.

I had the same issue as #239 after updating my installation from somewhere around 0.7.0 to 0.8.8. Switching to the :edge release cleared that issue up, but this is when I noticed the Gelli-related crash.

Platform

Docker

Versions

• multi-scrobbler master-38e5e4c (image: foxxmd/multi-scrobbler:edge) on docker
• jellyfin windows server 10.10.3
• Gelli android 1.3.5

Logs

[2024-12-26 01:56:35.590 -0500] DEBUG  : [App] [Scrobblers] Constructing lastfm (unnamed-lfm) client...
[2024-12-26 01:56:35.592 -0500] INFO   : [App] [Scrobblers] [Lastfm - unnamed-lfm] Client Added
[2024-12-26 01:56:35.716 -0500] DEBUG  : [App] [Sources] (unnamed) Constructing jellyfin source
[2024-12-26 01:56:35.719 -0500] VERBOSE: [App] [Heartbeat] [Clients] Starting check...
[2024-12-26 01:56:35.721 -0500] DEBUG  : [App] [Scrobblers] [Lastfm - unnamed-lfm] Attempting to initialize...
[2024-12-26 01:56:35.725 -0500] VERBOSE: [App] [Scrobblers] [Lastfm - unnamed-lfm] Building required data init succeeded
[2024-12-26 01:56:35.727 -0500] DEBUG  : [App] [Scrobblers] [Lastfm - unnamed-lfm] Connection check was not required.
[2024-12-26 01:56:36.025 -0500] INFO   : [App] [Scrobblers] [API - Lastfm - unnamed-lfm] Client authorized for user ***
[2024-12-26 01:56:36.026 -0500] INFO   : [App] [Scrobblers] [Lastfm - unnamed-lfm] Fully Initialized!
[2024-12-26 01:56:36.026 -0500] VERBOSE: [App] [Scrobblers] [Lastfm - unnamed-lfm] Fetching up to 200 initial scrobbles...
[2024-12-26 01:56:36.027 -0500] DEBUG  : [App] [Scrobblers] [Lastfm - unnamed-lfm] Refreshing recent scrobbles
[2024-12-26 01:56:36.752 -0500] DEBUG  : [App] [Scrobblers] [Lastfm - unnamed-lfm] Found 200 recent scrobbles
[2024-12-26 01:56:36.756 -0500] INFO   : [App] [Scrobblers] [Lastfm - unnamed-lfm] Should be processing scrobbles! Attempting to restart scrobbling...
    label: "Heartbeat"
[2024-12-26 01:56:36.759 -0500] INFO   : [App] [Scrobblers] [Lastfm - unnamed-lfm] Scrobble processing started
[2024-12-26 01:56:36.764 -0500] VERBOSE: [App] [Heartbeat] [Clients] Checked Dead letter queue for 1 clients.
[2024-12-26 01:56:36.766 -0500] INFO   : [App] [Heartbeat] [Clients] Attempted to start 1 clients that were not processing scrobbles.
[2024-12-26 01:56:37.720 -0500] VERBOSE: [App] [Heartbeat] [Sources] Starting check...
[2024-12-26 01:56:37.721 -0500] INFO   : [App] Scheduler started.
[2024-12-26 01:56:37.721 -0500] DEBUG  : [App] [Sources] [Jellyfin - unnamed] Attempting to initialize...
[2024-12-26 01:56:37.722 -0500] VERBOSE: [App] [Sources] [Jellyfin - unnamed] Building required data init succeeded
[2024-12-26 01:56:37.765 -0500] VERBOSE: [App] [Sources] [Jellyfin - unnamed] Connection check succeeded => Found Server *** (10.10.3)
[2024-12-26 01:56:37.776 -0500] INFO   : [App] [Sources] [Jellyfin - unnamed] Authenticated with API Key on behalf of user Dramatize1154
[2024-12-26 01:56:37.778 -0500] INFO   : [App] [Sources] [Jellyfin - unnamed] Fully Initialized!
[2024-12-26 01:56:37.778 -0500] INFO   : [App] [Sources] [Jellyfin - unnamed] Should be polling, attempting to start polling...
    label: "Heartbeat"
[2024-12-26 01:56:37.781 -0500] VERBOSE: [App] [Heartbeat] [Sources] Checked 1 sources for start signals.
[2024-12-26 01:56:37.782 -0500] INFO   : [App] [Heartbeat] [Sources] Attempted to start 1 sources.
[2024-12-26 01:56:37.790 -0500] INFO   : [App] [Sources] [Jellyfin - unnamed] Polling started
[2024-12-26 01:56:37.834 -0500] VERBOSE: [App] [Sources] [Jellyfin - unnamed] [Player 6164edbec1-Gelli-Dramatize1154] New Play: (f09212c43a403b126925ad1b82048bd4) Lagwagon - Faithfully
[2024-12-26 01:56:37.836 -0500] DEBUG  : [App] [Sources] [Jellyfin - unnamed] [Player 6164edbec1-Gelli-Dramatize1154] Started new Player listen range.
[2024-12-26 01:56:37.848 -0500] DEBUG  : [App] [Sources] [Jellyfin - unnamed] Last activity was at 01:56:37-05:00 | Next check in 10.00s | No new tracks discovered
[2024-12-26 01:56:47.881 -0500] DEBUG  : [App] [Sources] [Jellyfin - unnamed] [Player 6164edbec1-Gelli-Dramatize1154] Incoming play state ((ae18507a8e0d354616ae33474ae8f06e) Lagwagon - Weak) does not match existing state, removing existing: (f09212c43a403b126925ad1b82048bd4) Lagwagon - Faithfully
[2024-12-26 01:56:47.883 -0500] DEBUG  : [App] [Sources] [Jellyfin - unnamed] [Player 6164edbec1-Gelli-Dramatize1154] Generating play object with playDateCompleted
[2024-12-26 01:56:47.883 -0500] VERBOSE: [App] [Sources] [Jellyfin - unnamed] [Player 6164edbec1-Gelli-Dramatize1154] New Play: (ae18507a8e0d354616ae33474ae8f06e) Lagwagon - Weak
[2024-12-26 01:56:47.884 -0500] DEBUG  : [App] [Sources] [Jellyfin - unnamed] [Player 6164edbec1-Gelli-Dramatize1154] Started new Player listen range.
[2024-12-26 01:56:47.886 -0500] VERBOSE: [App] [Sources] [Jellyfin - unnamed] [Player 6164edbec1-Gelli-Dramatize1154] (f09212c43a403b126925ad1b82048bd4) Lagwagon - Faithfully not added because did not meet thresholds with tracked time of 0.00s (wanted 240s) and tracked percent of 0.00% (wanted 50%).
[2024-12-26 01:56:47.890 -0500] DEBUG  : [App] [Sources] [Jellyfin - unnamed] Last activity was at 01:56:47-05:00 | Next check in 10.00s | No new tracks discovered
[2024-12-26 01:56:57.925 -0500] VERBOSE: [App] [Sources] [Jellyfin - unnamed] [Player 6164edbec1-Gelli-Dramatize1154] Detected player was seeked -4.56s, starting new listen range
[2024-12-26 01:56:57.925 -0500] DEBUG  : [App] [Sources] [Jellyfin - unnamed] [Player 6164edbec1-Gelli-Dramatize1154] Started new Player listen range.
[2024-12-26 01:56:57.929 -0500] DEBUG  : [App] [Sources] [Jellyfin - unnamed] Last activity was at 01:56:57-05:00 | Next check in 10.00s | No new tracks discovered
[2024-12-26 01:57:07.973 -0500] DEBUG  : [App] [Sources] [Jellyfin - unnamed] [Player 6164edbec1-Gelli-Dramatize1154] Player position changed between current -> last update. Updated calculated status to playing
[2024-12-26 01:57:07.982 -0500] DEBUG  : [App] [Sources] [Jellyfin - unnamed] Last activity was at 01:57:07-05:00 | Next check in 10.00s | No new tracks discovered
[2024-12-26 01:57:18.028 -0500] DEBUG  : [App] [Sources] [Jellyfin - unnamed] Last activity was at 01:57:18-05:00 | Next check in 10.00s | No new tracks discovered
[2024-12-26 01:57:28.069 -0500] DEBUG  : [App] [Sources] [Jellyfin - unnamed] Last activity was at 01:57:28-05:00 | Next check in 10.00s | No new tracks discovered
[2024-12-26 01:57:38.112 -0500] DEBUG  : [App] [Sources] [Jellyfin - unnamed] Last activity was at 01:57:38-05:00 | Next check in 10.00s | No new tracks discovered
[2024-12-26 01:57:48.134 -0500] DEBUG  : [App] [Sources] [Jellyfin - unnamed] Last activity was at 01:57:48-05:00 | Next check in 10.00s | No new tracks discovered
[2024-12-26 01:57:58.157 -0500] DEBUG  : [App] [Sources] [Jellyfin - unnamed] Last activity was at 01:57:58-05:00 | Next check in 10.00s | No new tracks discovered
[2024-12-26 01:58:08.177 -0500] DEBUG  : [App] [Sources] [Jellyfin - unnamed] Last activity was at 01:58:08-05:00 | Next check in 10.00s | No new tracks discovered
[2024-12-26 01:58:18.201 -0500] DEBUG  : [App] [Sources] [Jellyfin - unnamed] Last activity was at 01:58:18-05:00 | Next check in 10.00s | No new tracks discovered
[2024-12-26 01:58:28.222 -0500] DEBUG  : [App] [Sources] [Jellyfin - unnamed] Last activity was at 01:58:28-05:00 | Next check in 10.00s | No new tracks discovered
[2024-12-26 01:58:38.242 -0500] DEBUG  : [App] [Sources] [Jellyfin - unnamed] Last activity was at 01:58:38-05:00 | Next check in 10.00s | No new tracks discovered
[2024-12-26 01:58:48.261 -0500] DEBUG  : [App] [Sources] [Jellyfin - unnamed] Last activity was at 01:58:48-05:00 | Next check in 10.00s | No new tracks discovered
[2024-12-26 01:58:58.285 -0500] DEBUG  : [App] [Sources] [Jellyfin - unnamed] Last activity was at 01:58:58-05:00 | Next check in 10.00s | No new tracks discovered
[2024-12-26 01:59:08.312 -0500] DEBUG  : [App] [Sources] [Jellyfin - unnamed] Last activity was at 01:59:08-05:00 | Next check in 10.00s | No new tracks discovered
[2024-12-26 01:59:18.334 -0500] DEBUG  : [App] [Sources] [Jellyfin - unnamed] Temporarily decreasing polling interval to 4.35s due to Player 6164edbec1-Gelli-Dramatize1154 reporting track duration remaining (6.35s) less than normal interval (10.00s)
[2024-12-26 01:59:18.335 -0500] DEBUG  : [App] [Sources] [Jellyfin - unnamed] Last activity was at 01:59:18-05:00 | Next check in 4.35s | No new tracks discovered
[2024-12-26 01:59:22.850 -0500] DEBUG  : [App] [Sources] [Jellyfin - unnamed] Temporarily decreasing polling interval to 1.00s due to Player 6164edbec1-Gelli-Dramatize1154 reporting track duration remaining (2.35s) less than normal interval (10.00s)
[2024-12-26 01:59:22.851 -0500] DEBUG  : [App] [Sources] [Jellyfin - unnamed] Last activity was at 01:59:22-05:00 | Next check in 1.00s | No new tracks discovered
[2024-12-26 01:59:23.865 -0500] DEBUG  : [App] [Sources] [Jellyfin - unnamed] Temporarily decreasing polling interval to 1.00s due to Player 6164edbec1-Gelli-Dramatize1154 reporting track duration remaining (1.36s) less than normal interval (10.00s)
[2024-12-26 01:59:23.866 -0500] DEBUG  : [App] [Sources] [Jellyfin - unnamed] Last activity was at 01:59:23-05:00 | Next check in 1.00s | No new tracks discovered
[2024-12-26 01:59:24.873 -0500] DEBUG  : [App] [Sources] [Jellyfin - unnamed] [Player 6164edbec1-Gelli-Dramatize1154] Incoming play state ((7ef21655e875c5b0c3dd363399fe0fc9) Lagwagon - Fan Fiction) does not match existing state, removing existing: (ae18507a8e0d354616ae33474ae8f06e) Lagwagon - Weak
[2024-12-26 01:59:24.874 -0500] DEBUG  : [App] [Sources] [Jellyfin - unnamed] [Player 6164edbec1-Gelli-Dramatize1154] Ended current Player listen range.
[2024-12-26 01:59:24.874 -0500] DEBUG  : [App] [Sources] [Jellyfin - unnamed] [Player 6164edbec1-Gelli-Dramatize1154] Generating play object with playDateCompleted
[2024-12-26 01:59:24.875 -0500] VERBOSE: [App] [Sources] [Jellyfin - unnamed] [Player 6164edbec1-Gelli-Dramatize1154] New Play: (7ef21655e875c5b0c3dd363399fe0fc9) Lagwagon - Fan Fiction
[2024-12-26 01:59:24.876 -0500] DEBUG  : [App] [Sources] [Jellyfin - unnamed] [Player 6164edbec1-Gelli-Dramatize1154] Started new Player listen range.
[2024-12-26 01:59:24.877 -0500] VERBOSE: [App] [Sources] [Jellyfin - unnamed] [Player 6164edbec1-Gelli-Dramatize1154] (ae18507a8e0d354616ae33474ae8f06e) Lagwagon - Weak added after met thresholds with tracked time of 146.36s (wanted 240s) and tracked percent of 94.00% (wanted 50%) and not matching any prior plays
[2024-12-26 01:59:24.882 -0500] INFO   : [App] [Sources] [Jellyfin - unnamed] Discovered => Lagwagon - Weak @ 2024-12-26T01:56:47-05:00 (S)
[2024-12-26 01:59:24.884 -0500] DEBUG  : [App] [Sources] [Jellyfin - unnamed] Last activity was at 01:59:24-05:00 | Next check in 10.00s
[2024-12-26 01:59:26.793 -0500] DEBUG  : [App] [Scrobblers] [Lastfm - unnamed-lfm] [Upstream Refresh] Should refresh => newest queued scrobble playDate is newer than last refresh
[2024-12-26 01:59:26.794 -0500] DEBUG  : [App] [Scrobblers] [Lastfm - unnamed-lfm] Refreshing recent scrobbles
[2024-12-26 01:59:27.316 -0500] DEBUG  : [App] [Scrobblers] [Lastfm - unnamed-lfm] Found 40 recent scrobbles
[2024-12-26 01:59:27.394 -0500] INFO   : [App] [Scrobblers] [Lastfm - unnamed-lfm] Scrobbled (Backlog) => (Jellyfin) Lagwagon - Weak @ 2024-12-26T01:56:47-05:00 (S)
[2024-12-26 01:59:27.395 -0500] DEBUG  : [App] [Scrobblers] [Lastfm - unnamed-lfm] Raw Payload: 
[2024-12-26 01:59:34.902 -0500] DEBUG  : [App] [Sources] [Jellyfin - unnamed] Last activity was at 01:59:34-05:00 | Next check in 10.00s | No new tracks discovered

If I let some music play from Gelli for a bit, after noticing the failure, the docker live logs continue, but the multi-scrobbler web UI continues to show the error I mentioned in the description. I then start to see messages related to a memory leak. None of these further songs get scrobbled - again, only the first one. (Lagwagon - Weak in this case...Lagwagon - Goin' South and  Falling Apart do not get scrobbled)

[2024-12-26 02:31:42.825 -0500] DEBUG  : [App] [Sources] [Jellyfin - unnamed] Last activity was at 02:31:42-05:00 | Next check in 10.00s | No new tracks discovered
[2024-12-26 02:31:52.860 -0500] DEBUG  : [App] [Sources] [Jellyfin - unnamed] Last activity was at 02:31:52-05:00 | Next check in 10.00s | No new tracks discovered
[2024-12-26 02:32:02.917 -0500] DEBUG  : [App] [Sources] [Jellyfin - unnamed] Last activity was at 02:32:02-05:00 | Next check in 10.00s | No new tracks discovered
(node:176) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 * listeners added to [WildcardEmitter]. Use emitter.setMaxListeners() to increase limit
(Use `node --trace-warnings ...` to show where the warning was created)
(node:176) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 * listeners added to [WildcardEmitter]. Use emitter.setMaxListeners() to increase limit
[2024-12-26 02:32:12.985 -0500] DEBUG  : [App] [Sources] [Jellyfin - unnamed] Last activity was at 02:32:12-05:00 | Next check in 10.00s | No new tracks discovered
[2024-12-26 02:32:23.030 -0500] DEBUG  : [App] [Sources] [Jellyfin - unnamed] Last activity was at 02:32:23-05:00 | Next check in 10.00s | No new tracks discovered
[2024-12-26 02:32:33.078 -0500] DEBUG  : [App] [Sources] [Jellyfin - unnamed] Last activity was at 02:32:33-05:00 | Next check in 10.00s | No new tracks discovered
[2024-12-26 02:32:43.130 -0500] DEBUG  : [App] [Sources] [Jellyfin - unnamed] Last activity was at 02:32:43-05:00 | Next check in 10.00s | No new tracks discovered
[2024-12-26 02:32:53.170 -0500] DEBUG  : [App] [Sources] [Jellyfin - unnamed] Temporarily decreasing polling interval to 5.61s due to Player 6164edbec1-Gelli-Dramatize1154 reporting track duration remaining (7.61s) less than normal interval (10.00s)
[2024-12-26 02:32:53.172 -0500] DEBUG  : [App] [Sources] [Jellyfin - unnamed] Last activity was at 02:32:53-05:00 | Next check in 5.61s | No new tracks discovered
[2024-12-26 02:32:59.209 -0500] DEBUG  : [App] [Sources] [Jellyfin - unnamed] Temporarily decreasing polling interval to 1.00s due to Player 6164edbec1-Gelli-Dramatize1154 reporting track duration remaining (1.61s) less than normal interval (10.00s)
[2024-12-26 02:32:59.210 -0500] DEBUG  : [App] [Sources] [Jellyfin - unnamed] Last activity was at 02:32:59-05:00 | Next check in 1.00s | No new tracks discovered
[2024-12-26 02:33:00.241 -0500] DEBUG  : [App] [Sources] [Jellyfin - unnamed] [Player 6164edbec1-Gelli-Dramatize1154] Incoming play state ((1550b30eb846afefe2007bd799d00756) Lagwagon - Goin' South) does not match existing state, removing existing: (fa76170b0679e1bbb08248242013d3d4) Lagwagon - Falling Apart
[2024-12-26 02:33:00.245 -0500] DEBUG  : [App] [Sources] [Jellyfin - unnamed] [Player 6164edbec1-Gelli-Dramatize1154] Ended current Player listen range.
[2024-12-26 02:33:00.246 -0500] DEBUG  : [App] [Sources] [Jellyfin - unnamed] [Player 6164edbec1-Gelli-Dramatize1154] Generating play object with playDateCompleted
[2024-12-26 02:33:00.248 -0500] VERBOSE: [App] [Sources] [Jellyfin - unnamed] [Player 6164edbec1-Gelli-Dramatize1154] New Play: (1550b30eb846afefe2007bd799d00756) Lagwagon - Goin' South
[2024-12-26 02:33:00.249 -0500] DEBUG  : [App] [Sources] [Jellyfin - unnamed] [Player 6164edbec1-Gelli-Dramatize1154] Started new Player listen range.
[2024-12-26 02:33:00.250 -0500] VERBOSE: [App] [Sources] [Jellyfin - unnamed] [Player 6164edbec1-Gelli-Dramatize1154] (fa76170b0679e1bbb08248242013d3d4) Lagwagon - Falling Apart not added because did not meet thresholds with tracked time of NaNs (wanted 240s) and tracked percent of NaN% (wanted 50%).
[2024-12-26 02:33:00.257 -0500] DEBUG  : [App] [Sources] [Jellyfin - unnamed] Last activity was at 02:33:00-05:00 | Next check in 10.00s | No new tracks discovered
(node:176) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 data listeners added to [Transform]. Use emitter.setMaxListeners() to increase limit
(node:176) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 end listeners added to [Transform]. Use emitter.setMaxListeners() to increase limit
(node:176) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 close listeners added to [Transform]. Use emitter.setMaxListeners() to increase limit
(node:176) MaxListenersExceededWarning: Possible EventEmitter memory leak detected. 11 error listeners added to [Transform]. Use emitter.setMaxListeners() to increase limit
[2024-12-26 02:33:10.304 -0500] DEBUG  : [App] [Sources] [Jellyfin - unnamed] Last activity was at 02:33:10-05:00 | Next check in 10.00s | No new tracks discovered
[2024-12-26 02:33:20.354 -0500] DEBUG  : [App] [Sources] [Jellyfin - unnamed] Last activity was at 02:33:20-05:00 | Next check in 10.00s | No new tracks discovered
[2024-12-26 02:33:30.401 -0500] DEBUG  : [App] [Sources] [Jellyfin - unnamed] Last activity was at 02:33:30-05:00 | Next check in 10.00s | No new tracks discovered

Additional Context

I have tried playing other songs from other devices at the same time trying to reproduce this issue, but I can only get it to reliably occur when playing from Gelli.

If I'm watching the live output from Docker logs, the multi-scrobbler web UI flips over to showing the error I mentioned in the description (Unexpected Application Error! s is null) at approximately the same time that 'Incoming play state' appears in the Docker logs, when the song switches over on the Gelli client.

[FoxxMD]

Thanks for the bug report. Can you please pull the latest foxxmd/multi-scrobbler:edge image and see if this resolves your issue? MS should report the version as master-f43c31f.

If it does not fix things for you, then please enable additional debugging by setting the ENV DEBUG_MODE=true in your docker run or compose file.

[Dramatize1154]

Thank you for the quick response! This does seem to have fixed the issue. The multi-scrobbler web UI no longer crashes after a song finishes playing in Gelli and all my test plays were scrobbled to Last.FM successfully. Nice!

[FoxxMD]

Fixed in v0.9.0