Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

Last.fm -> Maloja stuck processing recent #180

Closed
doot opened this issue Aug 26, 2024 · 8 comments
Closed

Last.fm -> Maloja stuck processing recent #180

doot opened this issue Aug 26, 2024 · 8 comments
Labels
bug Something isn't working

Comments

@doot
Copy link

doot commented Aug 26, 2024

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):

  • multi-scrobbler: foxxmd/multi-scrobbler:latest docker image (master-4fdd346)
  • maloja: 3.2.2
@FoxxMD
Copy link
Owner

FoxxMD commented Aug 26, 2024 •
edited
Loading

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 added a commit that referenced this issue Aug 26, 2024
@FoxxMD
fix(maloja): Improve handling for Maloja warnings-as-errors
5b53b74 
* Fixes incorrect handling for duplicate scrobble error from Maloja 3.2.2 #180
* More defensive Maloja scrobble parsing
@FoxxMD FoxxMD mentioned this issue Aug 26, 2024
Merged
@FoxxMD FoxxMD added the bug Something isn't working label Aug 26, 2024
@FoxxMD
Copy link
Owner

FoxxMD commented Aug 26, 2024

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
Copy link
Owner

FoxxMD commented Aug 26, 2024

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

@doot
Copy link
Author

doot commented Aug 26, 2024

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
Copy link
Author

doot commented Aug 26, 2024

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
Copy link
Owner

FoxxMD commented Aug 27, 2024

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

@doot
Copy link
Author

doot commented Aug 27, 2024

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
Copy link
Owner

FoxxMD commented Aug 28, 2024

Fixed in v0.8.3

@FoxxMD FoxxMD closed this as completed Aug 28, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
bug Something isn't working
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
3 participants
@doot @FoxxMD and others