search

FoxxMD / multi-scrobbler

Scrobble plays from multiple sources to multiple clients
https://foxxmd.github.io/multi-scrobbler
MIT License
337 stars 17 forks source link

Last.fm -> Maloja stuck processing recent #180

Closed doot closed 2 weeks ago

doot commented 2 weeks ago

I just wanted to thank you for this project, it's been incredibly useful!

Describe the bug I noticed some behavior recently and I am not sure if it's due to a misconfiguration on my part or a bug. I have multi-scrobbler set up to scrobble from last.fm -> Maloja. Recently, the multi-scrobbler queue will get stuck where Queued Scrobbles continues to go up while Tracks Scrobbled and Failed Scrobbles never increase. The logs are full of Cannot read properties of undefined (reading 'reduce') errors (see full stack trace below).

From the logs, it seems like backlogged or recently played tracks from the source (last.fm), which have already been scrobbled, are failing to scrobble to Maloja as they are duplicates. My understanding is that would be expected behavior (I wouldn't want it to actually scrobble the duplicate). However, they appear to be causing the queue to get stuck instead of being ignored or showing up as Failed Scrobbles.

If I delete the recent tracks from Maloja and restart multi-scrobbler, it successfully scrobbles them again and the queue continues to be processed from that point. However, as soon as multi-scrobbler is restarted it grabs a few recent tracks from last.fm, which have obviously already been scrobbled, and immediately gets stuck again.

image

Expected behavior I would expect the previously scrobbled tracks to either be ignored (not attempted to scrobble them at all), or the duplicate error from Maloja would be handled and the track ignored.

Logs Below are the logs for one of these events at startup. I included the maloja error as well (I have them in same systemd service)

multi-scrobbler-1  | [2024-08-25 19:10:23.433 -0700] DEBUG  : [App] [Scrobblers] [Maloja - Maloja] <artist> - <track> @ 2024-08-23T17:32:01-07:00 (S) => No Match because no recent scrobbles returned from API
maloja-1           | [database] Incoming scrobble [Client: multi-scrobbler | API: native/v1]: {'track_artists': ['<artist>'], 'track_title': '<track>', 'album_title': '<album>', 'scrobble_time': 1724459521}
maloja-1           | [sqldb] 1 Scrobbles have not been written to database (already exist)
maloja-1           | Traceback (most recent call last):
maloja-1           |   File "/venv/lib/python3.11/site-packages/maloja/apis/native_v1.py", line 126, in protector
maloja-1           |     return func(*args,**kwargs)
maloja-1           |            ^^^^^^^^^^^^^^^^^^^^
maloja-1           |   File "/venv/lib/python3.11/site-packages/maloja/apis/native_v1.py", line 631, in post_scrobble
maloja-1           |     result = database.incoming_scrobble(
maloja-1           |              ^^^^^^^^^^^^^^^^^^^^^^^^^^^
maloja-1           |   File "/venv/lib/python3.11/site-packages/maloja/database/__init__.py", line 115, in incoming_scrobble
maloja-1           |     sqldb.add_scrobble(scrobbledict,update_album=albumupdate,dbconn=dbconn)
maloja-1           |   File "/venv/lib/python3.11/site-packages/maloja/database/sqldb.py", line 159, in wrapper
maloja-1           |     return func(*args,**kwargs)
maloja-1           |            ^^^^^^^^^^^^^^^^^^^^
maloja-1           |   File "/venv/lib/python3.11/site-packages/maloja/database/sqldb.py", line 364, in add_scrobble
maloja-1           |     raise exc.DuplicateScrobble(scrobble=scrobbledict)
maloja-1           | maloja.database.exceptions.DuplicateScrobble
maloja-1           |
multi-scrobbler-1  | [2024-08-25 19:10:23.594 -0700] WARN   : [App] [Scrobblers] [Maloja - Maloja] Maloja Warning: This scrobble exists in the database (same timestamp and track). The submitted scrobble was not added. => null
multi-scrobbler-1  | [2024-08-25 19:10:23.596 -0700] ERROR  : [App] [Scrobblers] [Maloja - Maloja] Scrobble Error (Backlog)
multi-scrobbler-1  | [2024-08-25 19:10:23.598 -0700] DEBUG  : [App] [Scrobblers] [Maloja - Maloja] Raw Payload:
multi-scrobbler-1  | [2024-08-25 19:10:23.598 -0700] ERROR  : [App] [Scrobblers] [Maloja - Maloja] Scrobble processing interrupted
multi-scrobbler-1  | [2024-08-25 19:10:23.599 -0700] ERROR  : [App] [Scrobblers] [Maloja - Maloja] Error occurred while trying to scrobble
multi-scrobbler-1  | Error: Error occurred while trying to scrobble
multi-scrobbler-1  |     at MalojaScrobbler.doProcessing (CWD/src/backend/scrobblers/AbstractScrobbleClient.ts:598:39)
multi-scrobbler-1  |     at process.processTicksAndRejections (node:internal/process/task_queues:95:5)
multi-scrobbler-1  |     at MalojaScrobbler.startScrobbling (CWD/src/backend/scrobblers/AbstractScrobbleClient.ts:515:27)
multi-scrobbler-1  | caused by: TypeError: Cannot read properties of undefined (reading 'reduce')
multi-scrobbler-1  |     at Function.formatPlayObj (CWD/src/backend/scrobblers/MalojaScrobbler.ts:99:39)
multi-scrobbler-1  |     at MalojaScrobbler.formatPlayObj (CWD/src/backend/scrobblers/MalojaScrobbler.ts:128:90)
multi-scrobbler-1  |     at MalojaScrobbler.doScrobble (CWD/src/backend/scrobblers/MalojaScrobbler.ts:465:38)
multi-scrobbler-1  |     at process.processTicksAndRejections (node:internal/process/task_queues:95:5)
multi-scrobbler-1  |     at MalojaScrobbler.doProcessing (CWD/src/backend/scrobblers/AbstractScrobbleClient.ts:589:51)
multi-scrobbler-1  |     at MalojaScrobbler.startScrobbling (CWD/src/backend/scrobblers/AbstractScrobbleClient.ts:515:27)
multi-scrobbler-1  | [2024-08-25 19:10:23.611 -0700] INFO   : [App] [Scrobblers] [Maloja - Maloja] Scrobble processing retries (0) less than max processing retries (5), restarting processing after 3 second delay...

One other interesting part of the logs I noticed was this: [Scrobblers] [Maloja - Maloja] <artist> - <track> @ 2024-08-25T11:51:08-07:00 (S) => No Match because no recent scrobbles returned from API Is there a chance this is caused by failing to get the list of recently scrobbled tracks from the Maloja api? The API appears to be working when querying it manually, at least.

I can include more logs, if that would be helpful.

Versions (please complete the following information):

FoxxMD commented 2 weeks ago

Thanks for the detailed writeup and logs.

This is partially an issue with Maloja and partially an issue with MS.

When Maloja 2.3.2 (current version) detects a duplicate the response is returned as "OK" with a "warning" for duplicate but the actual response data does not contain a scrobble. This should be an error since the scrobble was not successful and has since been fixed in Maloja but the fix has not been published to a new release yet. MS handles this scenario correctly when using Maloja with the fix but that's not useful for anyone using official releases, of course. I'm not sure if/when the fix will get published so I'll go ahead and compensate for that now.

There's an also issue where MS's parsing of Maloja scrobbles is not defensive enough (caused by the issue above) and that is causing the actual error Cannot read properties of undefined (reading 'reduce') which causes the scrobble process to fail and get stuck rather than push scrobbles to failed queue. I'll address that as well.

FoxxMD commented 2 weeks ago

No Match because no recent scrobbles returned from API Is there a chance this is caused by failing to get the list of recently scrobbled tracks from the Maloja api?

This is interesting...did this message appear when first starting up multi-scrobbler or after it was running for a bit? Additionally, when first starting Maloja do you see something like this in logs:

[2024-08-26 11:17:48.949 -0400] DEBUG  : [App] [Scrobblers] [Maloja - default] Attempting to initialize...
[2024-08-26 11:17:48.950 -0400] VERBOSE: [App] [Scrobblers] [Maloja - default] Building required data init succeeded
[2024-08-26 11:17:48.963 -0400] INFO   : [App] [Scrobblers] [Maloja - default] Communication test succeeded.
[2024-08-26 11:17:48.963 -0400] INFO   : [App] [Scrobblers] [Maloja - default] Maloja Server Version: 3.2.2
[2024-08-26 11:17:48.965 -0400] VERBOSE: [App] [Scrobblers] [Maloja - default] Connection check succeeded
[2024-08-26 11:17:48.967 -0400] INFO   : [App] [Scrobblers] [Maloja - default] Auth test passed!
[2024-08-26 11:17:48.968 -0400] INFO   : [App] [Scrobblers] [Maloja - default] Fully Initialized!
[2024-08-26 11:17:48.968 -0400] VERBOSE: [App] [Scrobblers] [Maloja - default] Fetching up to 100 initial scrobbles...
[2024-08-26 11:17:48.968 -0400] DEBUG  : [App] [Scrobblers] [Maloja - default] Refreshing recent scrobbles
[2024-08-26 11:17:48.981 -0400] DEBUG  : [App] [Scrobblers] [Maloja - default] Found 100 recent scrobbles
[2024-08-26 11:17:48.982 -0400] INFO   : [App] [Scrobblers] [Maloja - default] Scrobble processing started

Specifically the Found 100 recent scrobbles line?

FoxxMD commented 2 weeks ago

Please try using foxxmd/multi-scrobbler:pr-181 docker image to see if this fixes duplicate error problems.

doot commented 2 weeks ago

When Maloja 2.3.2 (current version) detects a duplicate the response is returned as "OK" with a "warning" for duplicate but the actual response data does not contain a scrobble. This should be an error since the scrobble was not successful and has since been fixed in Maloja but the fix has not been published to a new release yet. MS handles this scenario correctly when using Maloja with the fix but that's not useful for anyone using official releases, of course. I'm not sure if/when the fix will get published so I'll go ahead and compensate for that now.

Awesome, thanks for taking a look!

Sorry, it looks like I actually misspoke when noting the version of Maloja. That is the reported version on the web-ui, but I had forgotten that I was actually using a locally built image from the latest master (I presume that would include the change you mentioned).

This is interesting...did this message appear when first starting up multi-scrobbler or after it was running for a bit? Additionally, when first starting Maloja do you see something like this in logs:

It appears when first starting up. After the logs you mentioned, directly after the last.fm source discovers recently played tracks. Here are a bit more of the logs starting from startup to the error. 

multi-scrobbler-1  | [2024-08-26 13:04:00.939 -0700] DEBUG  : [App] [Scrobblers] Constructing maloja (Maloja) client...
multi-scrobbler-1  | [2024-08-26 13:04:00.940 -0700] WARN   : [App] [Scrobblers] [Maloja - Maloja] Setting verbose matching may produce noisy logs! Use with care.
multi-scrobbler-1  | [2024-08-26 13:04:00.940 -0700] INFO   : [App] [Scrobblers] [Maloja - Maloja] Client Added
multi-scrobbler-1  | [2024-08-26 13:04:00.941 -0700] INFO   : [App] Starting scrobble clients...
multi-scrobbler-1  | [2024-08-26 13:04:00.942 -0700] DEBUG  : [App] [Scrobblers] [Maloja - Maloja] Attempting to initialize...
multi-scrobbler-1  | [2024-08-26 13:04:00.942 -0700] VERBOSE: [App] [Scrobblers] [Maloja - Maloja] Building required data init succeeded
multi-scrobbler-1  | [2024-08-26 13:04:00.952 -0700] INFO   : [App] [Scrobblers] [Maloja - Maloja] Communication test succeeded.
multi-scrobbler-1  | [2024-08-26 13:04:00.952 -0700] INFO   : [App] [Scrobblers] [Maloja - Maloja] Maloja Server Version: 3.2.2
multi-scrobbler-1  | [2024-08-26 13:04:00.956 -0700] VERBOSE: [App] [Scrobblers] [Maloja - Maloja] Connection check succeeded
multi-scrobbler-1  | [2024-08-26 13:04:00.959 -0700] INFO   : [App] [Scrobblers] [Maloja - Maloja] Auth test passed!
multi-scrobbler-1  | [2024-08-26 13:04:00.959 -0700] INFO   : [App] [Scrobblers] [Maloja - Maloja] Fully Initialized!
multi-scrobbler-1  | [2024-08-26 13:04:00.960 -0700] VERBOSE: [App] [Scrobblers] [Maloja - Maloja] Fetching up to 100 initial scrobbles...
multi-scrobbler-1  | [2024-08-26 13:04:00.960 -0700] DEBUG  : [App] [Scrobblers] [Maloja - Maloja] Refreshing recent scrobbles
multi-scrobbler-1  | [2024-08-26 13:04:00.979 -0700] DEBUG  : [App] [Scrobblers] [Maloja - Maloja] Found 100 recent scrobbles
multi-scrobbler-1  | [2024-08-26 13:04:00.979 -0700] INFO   : [App] [Scrobblers] [Maloja - Maloja] Scrobble processing started
multi-scrobbler-1  | [2024-08-26 13:04:01.058 -0700] DEBUG  : [App] [Sources] (last.fm - Source) Constructing lastfm source
multi-scrobbler-1  | [2024-08-26 13:04:01.060 -0700] INFO   : [App] [Sources] [Lastfm - last.fm - Source] Note: The player for this source is an analogue for the 'Now Playing' status exposed by lastfm which is NOT used for scrobbling. Instead, the 'recently played' or 'history' information provided by this source is used for scrobbles.
multi-scrobbler-1  | [2024-08-26 13:04:01.061 -0700] DEBUG  : [App] [Sources] [Lastfm - last.fm - Source] Attempting to initialize...
multi-scrobbler-1  | [2024-08-26 13:04:01.063 -0700] VERBOSE: [App] [Sources] [Lastfm - last.fm - Source] Building required data init succeeded
multi-scrobbler-1  | [2024-08-26 13:04:01.133 -0700] VERBOSE: [App] [Sources] [Lastfm - last.fm - Source] Connection check succeeded
multi-scrobbler-1  | [2024-08-26 13:04:01.531 -0700] INFO   : [App] [Sources] [Lastfm - last.fm - Source] [API - Lastfm - last.fm - Source] Client authorized for user <user>
multi-scrobbler-1  | [2024-08-26 13:04:01.534 -0700] INFO   : [App] [Sources] [Lastfm - last.fm - Source] Fully Initialized!
multi-scrobbler-1  | [2024-08-26 13:04:03.038 -0700] INFO   : [App] Scheduler started.
multi-scrobbler-1  | [2024-08-26 13:04:03.040 -0700] INFO   : [App] [Sources] [Lastfm - last.fm - Source] Discovering backlogged tracks from recently played API...
multi-scrobbler-1  | [2024-08-26 13:04:03.042 -0700] VERBOSE: [App] [Sources] [Lastfm - last.fm - Source] Fetching the last 10 listens to check for backlogging...
multi-scrobbler-1  | [2024-08-26 13:04:03.216 -0700] INFO   : [App] [Sources] [Lastfm - last.fm - Source] Discovered => <artist> - <track 1> @ 2024-08-25T18:58:10-07:00 (S)
multi-scrobbler-1  | [2024-08-26 13:04:03.217 -0700] INFO   : [App] [Sources] [Lastfm - last.fm - Source] Discovered => <artist> - <track 2> @ 2024-08-25T19:01:17-07:00 (S)
multi-scrobbler-1  | [2024-08-26 13:04:03.217 -0700] INFO   : [App] [Sources] [Lastfm - last.fm - Source] Discovered => <artist> - <track 3> @ 2024-08-25T19:07:54-07:00 (S)
multi-scrobbler-1  | [2024-08-26 13:04:03.217 -0700] INFO   : [App] [Sources] [Lastfm - last.fm - Source] Discovered => <artist> - <track 4> @ 2024-08-25T19:10:13-07:00 (S)
multi-scrobbler-1  | [2024-08-26 13:04:03.218 -0700] INFO   : [App] [Sources] [Lastfm - last.fm - Source] Discovered => <artist> - <track 5> @ 2024-08-25T19:12:49-07:00 (S)
multi-scrobbler-1  | [2024-08-26 13:04:03.218 -0700] INFO   : [App] [Sources] [Lastfm - last.fm - Source] Discovered => <artist> - <track 5> @ 2024-08-25T19:15:05-07:00 (S)
multi-scrobbler-1  | [2024-08-26 13:04:03.219 -0700] INFO   : [App] [Sources] [Lastfm - last.fm - Source] Discovered => <artist> - <track 6> @ 2024-08-25T19:26:37-07:00 (S)
multi-scrobbler-1  | [2024-08-26 13:04:03.219 -0700] INFO   : [App] [Sources] [Lastfm - last.fm - Source] Discovered => <artist> - <track 7> @ 2024-08-25T19:30:42-07:00 (S)
multi-scrobbler-1  | [2024-08-26 13:04:03.220 -0700] INFO   : [App] [Sources] [Lastfm - last.fm - Source] Discovered => <artist> - <track 8> @ 2024-08-25T19:34:45-07:00 (S)
multi-scrobbler-1  | [2024-08-26 13:04:03.221 -0700] INFO   : [App] [Sources] [Lastfm - last.fm - Source] Discovered => <artist> - <track 9> @ 2024-08-25T19:38:29-07:00 (S)
multi-scrobbler-1  | [2024-08-26 13:04:03.221 -0700] INFO   : [App] [Sources] [Lastfm - last.fm - Source] Backlog scrobbling is disabled by config, skipping...
multi-scrobbler-1  | [2024-08-26 13:04:03.222 -0700] INFO   : [App] [Sources] [Lastfm - last.fm - Source] Polling started
multi-scrobbler-1  | [2024-08-26 13:04:03.222 -0700] DEBUG  : [App] [Sources] [Lastfm - last.fm - Source] Refreshing recently played
multi-scrobbler-1  | [2024-08-26 13:04:03.442 -0700] INFO   : [App] [Sources] [Lastfm - last.fm - Source] Discovered => <artist> - <track 10> @ 2024-08-25T12:01:14-07:00 (S)
multi-scrobbler-1  | [2024-08-26 13:04:03.445 -0700] INFO   : [App] [Sources] [Lastfm - last.fm - Source] Discovered => <artist> - <track 11> @ 2024-08-25T12:04:26-07:00 (S)
multi-scrobbler-1  | [2024-08-26 13:04:03.448 -0700] INFO   : [App] [Sources] [Lastfm - last.fm - Source] Discovered => <artist> - <track 11> @ 2024-08-25T12:09:05-07:00 (S)
multi-scrobbler-1  | [2024-08-26 13:04:03.451 -0700] INFO   : [App] [Sources] [Lastfm - last.fm - Source] Discovered => <artist> - <track 12> @ 2024-08-25T14:57:28-07:00 (S)
multi-scrobbler-1  | [2024-08-26 13:04:03.451 -0700] INFO   : [App] [Sources] [Lastfm - last.fm - Source] Discovered => <artist> - <track 13> @ 2024-08-25T15:02:54-07:00 (S)
multi-scrobbler-1  | [2024-08-26 13:04:03.452 -0700] INFO   : [App] [Sources] [Lastfm - last.fm - Source] Discovered => <artist> - <track 14> @ 2024-08-25T15:07:43-07:00 (S)
multi-scrobbler-1  | [2024-08-26 13:04:03.453 -0700] INFO   : [App] [Sources] [Lastfm - last.fm - Source] Discovered => <artist> - <track 15> @ 2024-08-25T15:14:16-07:00 (S)
multi-scrobbler-1  | [2024-08-26 13:04:03.454 -0700] INFO   : [App] [Sources] [Lastfm - last.fm - Source] Discovered => <artist> - <track 16> @ 2024-08-25T18:51:21-07:00 (S)
multi-scrobbler-1  | [2024-08-26 13:04:03.455 -0700] INFO   : [App] [Sources] [Lastfm - last.fm - Source] Discovered => <artist> - <track 17> @ 2024-08-25T18:53:06-07:00 (S)
multi-scrobbler-1  | [2024-08-26 13:04:03.455 -0700] INFO   : [App] [Sources] [Lastfm - last.fm - Source] Discovered => <artist> - <track 18> @ 2024-08-25T18:56:15-07:00 (S)
multi-scrobbler-1  | [2024-08-26 13:04:03.463 -0700] DEBUG  : [App] [Sources] [Lastfm - last.fm - Source] Last activity was at 2024-08-26T13:04:03-07:00 | Next check interval: 15.00s
multi-scrobbler-1  | [2024-08-26 13:04:04.984 -0700] DEBUG  : [App] [Scrobblers] [Maloja - Maloja] Scrobble refresh not needed
multi-scrobbler-1  | [2024-08-26 13:04:04.987 -0700] DEBUG  : [App] [Scrobblers] [Maloja - Maloja] <artist> - <track 10> @ 2024-08-25T12:01:14-07:00 (S) => No Match because no recent scrobbles returned from API
maloja-1           | [database] Incoming scrobble [Client: multi-scrobbler | API: native/v1]: {'track_artists': ['<artist>'], 'track_title': '<track 10>', 'album_title': '<album>', 'scrobble_time': 1724612474}
maloja-1           | [sqldb] 1 Scrobbles have not been written to database (already exist)
maloja-1           | Traceback (most recent call last):
maloja-1           |   File "/venv/lib/python3.11/site-packages/maloja/apis/native_v1.py", line 126, in protector
maloja-1           |     return func(*args,**kwargs)
maloja-1           |            ^^^^^^^^^^^^^^^^^^^^
maloja-1           |   File "/venv/lib/python3.11/site-packages/maloja/apis/native_v1.py", line 631, in post_scrobble
maloja-1           |     result = database.incoming_scrobble(
maloja-1           |              ^^^^^^^^^^^^^^^^^^^^^^^^^^^
maloja-1           |   File "/venv/lib/python3.11/site-packages/maloja/database/__init__.py", line 115, in incoming_scrobble
maloja-1           |     sqldb.add_scrobble(scrobbledict,update_album=albumupdate,dbconn=dbconn)
maloja-1           |   File "/venv/lib/python3.11/site-packages/maloja/database/sqldb.py", line 159, in wrapper
maloja-1           |     return func(*args,**kwargs)
maloja-1           |            ^^^^^^^^^^^^^^^^^^^^
maloja-1           |   File "/venv/lib/python3.11/site-packages/maloja/database/sqldb.py", line 364, in add_scrobble
maloja-1           |     raise exc.DuplicateScrobble(scrobble=scrobbledict)
maloja-1           | maloja.database.exceptions.DuplicateScrobble
maloja-1           |
multi-scrobbler-1  | [2024-08-26 13:04:05.220 -0700] WARN   : [App] [Scrobblers] [Maloja - Maloja] Maloja Warning: This scrobble exists in the database (same timestamp and track). The submitted scrobble was not added. => null
multi-scrobbler-1  | [2024-08-26 13:04:05.220 -0700] ERROR  : [App] [Scrobblers] [Maloja - Maloja] Scrobble Error (Backlog)
multi-scrobbler-1  | [2024-08-26 13:04:05.221 -0700] DEBUG  : [App] [Scrobblers] [Maloja - Maloja] Raw Payload:
multi-scrobbler-1  | [2024-08-26 13:04:05.221 -0700] ERROR  : [App] [Scrobblers] [Maloja - Maloja] Scrobble processing interrupted
multi-scrobbler-1  | [2024-08-26 13:04:05.222 -0700] ERROR  : [App] [Scrobblers] [Maloja - Maloja] Error occurred while trying to scrobble
multi-scrobbler-1  | Error: Error occurred while trying to scrobble
multi-scrobbler-1  |     at MalojaScrobbler.doProcessing (CWD/src/backend/scrobblers/AbstractScrobbleClient.ts:598:39)
multi-scrobbler-1  |     at process.processTicksAndRejections (node:internal/process/task_queues:95:5)
multi-scrobbler-1  |     at MalojaScrobbler.startScrobbling (CWD/src/backend/scrobblers/AbstractScrobbleClient.ts:515:27)
multi-scrobbler-1  | caused by: TypeError: Cannot read properties of undefined (reading 'reduce')
multi-scrobbler-1  |     at Function.formatPlayObj (CWD/src/backend/scrobblers/MalojaScrobbler.ts:99:39)
multi-scrobbler-1  |     at MalojaScrobbler.formatPlayObj (CWD/src/backend/scrobblers/MalojaScrobbler.ts:128:90)
multi-scrobbler-1  |     at MalojaScrobbler.doScrobble (CWD/src/backend/scrobblers/MalojaScrobbler.ts:465:38)
multi-scrobbler-1  |     at process.processTicksAndRejections (node:internal/process/task_queues:95:5)
multi-scrobbler-1  |     at MalojaScrobbler.doProcessing (CWD/src/backend/scrobblers/AbstractScrobbleClient.ts:589:51)
multi-scrobbler-1  |     at MalojaScrobbler.startScrobbling (CWD/src/backend/scrobblers/AbstractScrobbleClient.ts:515:27)
multi-scrobbler-1  | [2024-08-26 13:04:05.227 -0700] INFO   : [App] [Scrobblers] [Maloja - Maloja] Scrobble processing retries (0) less than max processing retries (5), restarting processing after 3 second delay...
multi-scrobbler-1  | [2024-08-26 13:04:08.227 -0700] INFO   : [App] [Scrobblers] [Maloja - Maloja] Scrobble processing started
multi-scrobbler-1  | [2024-08-26 13:04:08.227 -0700] DEBUG  : [App] [Scrobblers] [Maloja - Maloja] Scrobble refresh not needed
doot commented 2 weeks ago

Please try using foxxmd/multi-scrobbler:pr-181 docker image to see if this fixes duplicate error problems.

I just tried this out and it appears to fix the queue getting stuck! multi-scrobbler-1 | caused by: Error: Maloja returned a warning but MS treating as error: (scrobble_exists) This scrobble exists in the database (same timestamp and track). The submitted scrobble was not added.

It looks like it is properly marking them as failed now and the queue continues to progress.

However, now every time it starts up it attempts to process and fails these 200 recent duplicate tracks every time. It's way less of an issue since it doesn't block it from processing any longer, but I am wondering if I have something misconfigured to cause this.

image Then again, after restarting it processes 200 tracks and fails them all (but then continues successfully) image

FoxxMD commented 2 weeks ago

@doot please update to the newest image for foxxmd/multi-scrobbler:pr-181 and let me know if that fixes everything for you.

doot commented 2 weeks ago

Awesome! Just tried that out and it looks like it's fixed all of the issues I was seeing! The queue is no longer getting stuck and it's not failing to scrobble already scrobbled tracks at startup.

FoxxMD commented 2 weeks ago

Fixed in v0.8.3