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.

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

Ignore Duplicate Scrobbles from Last.fm #173

Closed
HidYn opened this issue Jul 23, 2024 · 22 comments
Closed

Ignore Duplicate Scrobbles from Last.fm #173

HidYn opened this issue Jul 23, 2024 · 22 comments
Labels
bug Something isn't working

Comments

@HidYn
Copy link

HidYn commented Jul 23, 2024

Firstly, thank you for such a wonderful project. MS has allowed me to focus on ListenBrainz and Maloja instead of Last.fm

I've got what more like a feature request. I use an application called Roon which only supports Last.fm scrobbling and it appears to have a long-standing bug that never gets addressed that involves duplicate scrobbles. https://community.roonlabs.com/t/play-count-not-updating-as-expected/218686/67

Screenshot_20240723_111517

The track names appear to be slightly different, but the scrobble time is exactly the same down to the second.

I've got Last.fm setup as a source only for Roon and I would love the ability to have those duplicate scrobbles ignored when pulled through to ListenBrainz as at the moment the duplicates get pushed there. It appears to be already ignoring them when pushed through to Maloja to which I have ListenBrainz as the source so no duplicates get posted there.

Keep up the great work.

@FoxxMD
Copy link
Owner

FoxxMD commented Jul 23, 2024

Let me make sure I understand your MS configuration:

flowchart TB

    rn1[Roon] --> rnlfm[Last.fm]

    subgraph multi-scrobbler
    rnlfm[Last.fm Source] --> lzc[Listenbrainz Client]

    lz[Listenbrainz Source] --> ml[Maloja]
    end
Loading

Is this correct?


I would love the ability to have those duplicate scrobbles ignored

MS should already be detecting small differences in scrobbles with the same timestamp as duplicates, I have a whole test suite for it :) Let's try to figure out why this isn't working for your use case.

If you are not already using it please switch to using File or AIO File for your listenbrainz client configuration. Then, add the following verbose properties to options in your config:

(example of listenbrainz.json)

[
  {
    "name": "brainz",
    "enable": true,
    "configureAs": "client",
    "data": {
      "token": "029b081ba-9156-4pe7-88e5-3be671f5ea2b",
      "username": "MyUSer"
    },
+    "options": {
+     "verbose": {
+        "match": {
+          "onNoMatch": true,
+          "confidenceBreakdown": true
+        }
+      }
+    }
  }
]

This will make multi-scrobbler log details to the DEBUG log level when a scrobble client does not find duplicate scrobbles, like this:

[2024-07-23 09:18:36.986 -0400] DEBUG  : [Test - Test] Source: 9th Wonder / Cordae / Dinner Party / Kamasi Washington / Phoelix / Robert Glasper / Terrace Martin - Freeze Tag @ 2024-07-23T09:17:50-04:00 (S) => Closest Scrobble: 9th Wonder / Cordae / Dinner Party / Kamasi Washington / Phoelix / Robert Glasper / Terrace Martin - Freeze Tag @ 2024-07-23T09:16:49-04:00 (S) => Score 0.70 => No Match
[2024-07-23 09:18:36.986 -0400] DEBUG  : [Test - Test] Breakdown:
Artist: 1.00 * 0.3 = 0.30
Title: 1.00 * 0.4 = 0.40
Time: (No correlation) 0 * 0.5 = 0.00
Time Detail => Existing: 09:16:49-04:00 - Candidate: 09:17:50-04:00 | Temporal Sameness: No correlation | Play Diff: 61s (Needed <60s) | Range Comparison N/A
Score 0.70 => No Match

Make sure MS is logging to DEBUG -- if you have not modified env LOG_LEVEL or loglevel in config.json then you are good to go.

Please turn on these settings and restart MS. Then wait for a duplicate scrobble to occur and copy-paste the detailed logs here so we can figure out what is going on.

@HidYn
Copy link
Author

HidYn commented Jul 23, 2024

Pretty much spot on, and I've added that extra config now, so will monitor.

I've attached my config files to make it even more clear. Once again thank you :)

lastfm.json
listenbrainz.json
maloja.json

@FoxxMD
Copy link
Owner

FoxxMD commented Jul 23, 2024

Ignoring visyn configs, it seems you have a circular reference in your configs:

flowchart TB

    subgraph verbose

    lfms[src-hidyn-lastfm] --> lzc[cli-hidyn-listenbrainz]
    lzs[src-hidyn-listenbrainz] --> ml[Maloja]
    lzs --> lfmc[cli-hidyn-lastfm]
%%    lfmc <-.-> lfms
%%    lzs <-.-> lzc
   end

   subgraph simplified
   lfm[hidyn-lastfm] --> lz[hidyn-listenbrainz]
   lz --> mls[Maloja]
   lz --> lfm
   end
Loading

Is this on purpose? MS isn't really designed/tested for handing this kind of feedback loop. Ideally, all data should flow in one direction.

@HidYn
Copy link
Author

HidYn commented Jul 23, 2024

Yeah that's on purpose and seems to be working okay so far. I'm pretty sure it's not the cause of this issues as I've had Roon randomly posting duplicate scrobbles before I used MS.

I scrobble from my phone with Pano Scrobbler to ListenBrainz and as the whole setup is new wasn't ready to ditch Last.fm fully so setup the loop and controlled it by limiting the clients each source scrobbles too.

If worst comes to the worst and that is the cause I can always remove it.

@HidYn
Copy link
Author

HidYn commented Jul 23, 2024

I suppose I can always just make Pano scrobble to Last.fm too as a backup if that will play nicely and I won't get duplicate imports into ListenBrainz. The reason I didn't go this route initially is because Last.fm is awful at handling multi-artist tracks compared to ListenBrainz and Maloja so wasn't sure how to handle it.

@HidYn
Copy link
Author

HidYn commented Jul 23, 2024

We finally have a duplicate.

Last.fm
Screenshot_20240723_152739

ListenBrainz
Screenshot_20240723_152816

2024-07-23 15:21:29.182 +0100] DEBUG  : [App] [Sources] [Lastfm - src-hidyn-lastfm] Refreshing recently played
[2024-07-23 15:21:31.058 +0100] DEBUG  : [App] [Sources] [Lastfm - src-hidyn-lastfm] No new tracks discovered
[2024-07-23 15:21:31.059 +0100] DEBUG  : [App] [Sources] [Lastfm - src-hidyn-lastfm] Last activity was at 2024-07-23T15:21:14+01:00 | Next check interval: 15.00s
[2024-07-23 15:21:44.564 +0100] DEBUG  : [App] [Sources] [Lastfm - src-hidyn-lastfm] Refreshing recently played
[2024-07-23 15:21:44.832 +0100] DEBUG  : [App] [Sources] [Lastfm - src-hidyn-lastfm] No new tracks discovered
[2024-07-23 15:21:44.832 +0100] DEBUG  : [App] [Sources] [Lastfm - src-hidyn-lastfm] Last activity was at 2024-07-23T15:21:44+01:00 | Next check interval: 15.00s
[2024-07-23 15:21:44.918 +0100] DEBUG  : [App] [Sources] [Listenbrainz - src-hidyn-listenbrainz] Refreshing recently played
[2024-07-23 15:21:45.567 +0100] DEBUG  : [App] [Sources] [Listenbrainz - src-hidyn-listenbrainz] No new tracks discovered
[2024-07-23 15:21:45.567 +0100] DEBUG  : [App] [Sources] [Listenbrainz - src-hidyn-listenbrainz] Last activity 2024-07-23T15:15:24+01:00 is a minute outside of polling period (last activity + 300s) | Next check interval: (15 + 35)s
[2024-07-23 15:21:59.839 +0100] DEBUG  : [App] [Sources] [Lastfm - src-hidyn-lastfm] Refreshing recently played
[2024-07-23 15:22:00.211 +0100] DEBUG  : [App] [Sources] [Lastfm - src-hidyn-lastfm] [Player NoDevice-SingleUser] Incoming play state (Blur - Barbaric) does not match existing state, removing existing: Queens of the Stone Age - Feel Good Hit of the Summer (Album Version)
[2024-07-23 15:22:00.212 +0100] DEBUG  : [App] [Sources] [Lastfm - src-hidyn-lastfm] [Player NoDevice-SingleUser] Ended current Player listen range.
[2024-07-23 15:22:00.213 +0100] DEBUG  : [App] [Sources] [Lastfm - src-hidyn-lastfm] [Player NoDevice-SingleUser] Generating play object with playDateCompleted
[2024-07-23 15:22:00.213 +0100] DEBUG  : [App] [Sources] [Lastfm - src-hidyn-lastfm] [Player NoDevice-SingleUser] New Play: Blur - Barbaric
[2024-07-23 15:22:00.213 +0100] DEBUG  : [App] [Sources] [Lastfm - src-hidyn-lastfm] [Player NoDevice-SingleUser] Started new Player listen range.
[2024-07-23 15:22:00.216 +0100] INFO   : [App] [Sources] [Lastfm - src-hidyn-lastfm] Discovered => Queens of the Stone Age - Feel Good Hit of the Summer (Album Version) @ 2024-07-23T15:19:06+01:00 (S)
[2024-07-23 15:22:00.216 +0100] DEBUG  : [App] [Scrobblers] [Maloja - cli-hidyn-maloja] Client was filtered out by Source 'Source - Lastfm - src-hidyn-lastfm'
[2024-07-23 15:22:00.217 +0100] DEBUG  : [App] [Scrobblers] [Lastfm - cli-hidyn-lastfm] Client was filtered out by Source 'Source - Lastfm - src-hidyn-lastfm'
[2024-07-23 15:22:00.217 +0100] DEBUG  : [App] [Scrobblers] [Listenbrainz - cli-visyn-listenbrainz] Client was filtered out by Source 'Source - Lastfm - src-hidyn-lastfm'
[2024-07-23 15:22:00.217 +0100] DEBUG  : [App] [Sources] [Lastfm - src-hidyn-lastfm] Last activity was at 2024-07-23T15:22:00+01:00 | Next check interval: 15.00s
[2024-07-23 15:22:00.791 +0100] DEBUG  : [App] [Scrobblers] [Listenbrainz - cli-hidyn-listenbrainz] Refreshing recent scrobbles
[2024-07-23 15:22:01.397 +0100] DEBUG  : [App] [Scrobblers] [Listenbrainz - cli-hidyn-listenbrainz] Found 40 recent scrobbles
[2024-07-23 15:22:01.409 +0100] DEBUG  : [App] [Scrobblers] [Listenbrainz - cli-hidyn-listenbrainz] Lastfm: Queens of the Stone Age - Feel Good Hit of the Summer... @ 2024-07-23T15:19:06+01:00 (S) => Closest Scrobble: Queens of the Stone Age - What the Peephole Say @ 2024-07-23T14:00:13+01:00 (S) => Score 0.35 => No Match
[2024-07-23 15:22:01.409 +0100] DEBUG  : [App] [Scrobblers] [Listenbrainz - cli-hidyn-listenbrainz] Breakdown:
Artist: 1.00 * 0.3 = 0.30
Title: 0.12 * 0.4 = 0.05
Time: (No correlation) 0 * 0.5 = 0.00
Time Detail => Existing: 14:00:13+01:00 - Candidate: 15:19:06+01:00 | Temporal Sameness: No correlation | Play Diff: 4,733s (Needed <10s) | Range Comparison N/A
Score 0.35 => No Match
[2024-07-23 15:22:01.521 +0100] INFO   : [App] [Scrobblers] [Listenbrainz - cli-hidyn-listenbrainz] Scrobbled (Backlog) => (Lastfm) Queens of the Stone Age - Feel Good Hit of the Summer (Album Version) @ 2024-07-23T15:19:06+01:00 (S)
[2024-07-23 15:22:01.522 +0100] DEBUG  : [App] [Scrobblers] [Listenbrainz - cli-hidyn-listenbrainz] Raw Payload:
[2024-07-23 15:22:15.224 +0100] DEBUG  : [App] [Sources] [Lastfm - src-hidyn-lastfm] Refreshing recently played
[2024-07-23 15:22:15.518 +0100] DEBUG  : [App] [Sources] [Lastfm - src-hidyn-lastfm] No new tracks discovered
[2024-07-23 15:22:15.519 +0100] DEBUG  : [App] [Sources] [Lastfm - src-hidyn-lastfm] Last activity was at 2024-07-23T15:22:15+01:00 | Next check interval: 15.00s
[2024-07-23 15:22:28.779 +0100] DEBUG  : [App] [Sources] [Lastfm - src-visyn-lastfm] Refreshing recently played
[2024-07-23 15:22:29.068 +0100] DEBUG  : [App] [Sources] [Lastfm - src-visyn-lastfm] No new tracks discovered
[2024-07-23 15:22:29.068 +0100] DEBUG  : [App] [Sources] [Lastfm - src-visyn-lastfm] Last activity 2024-07-23T14:28:59+01:00 is an hour outside of polling period (last activity + 300s) | Next check interval: (15 + 45)s
[2024-07-23 15:22:30.533 +0100] DEBUG  : [App] [Sources] [Lastfm - src-hidyn-lastfm] Refreshing recently played
[2024-07-23 15:22:30.967 +0100] DEBUG  : [App] [Sources] [Lastfm - src-hidyn-lastfm] No new tracks discovered
[2024-07-23 15:22:30.968 +0100] DEBUG  : [App] [Sources] [Lastfm - src-hidyn-lastfm] Last activity was at 2024-07-23T15:22:30+01:00 | Next check interval: 15.00s
[2024-07-23 15:22:35.096 +0100] DEBUG  : [App] [Sources] [Listenbrainz - src-hidyn-listenbrainz] Refreshing recently played
[2024-07-23 15:22:35.753 +0100] INFO   : [App] [Sources] [Listenbrainz - src-hidyn-listenbrainz] Discovered => Queens of the Stone Age - Feel Good Hit of the Summer @ 2024-07-23T15:19:06+01:00 (S)
[2024-07-23 15:22:35.759 +0100] DEBUG  : [App] [Scrobblers] [Listenbrainz - cli-hidyn-listenbrainz] Client was filtered out by Source 'Source - Listenbrainz - src-hidyn-listenbrainz'
[2024-07-23 15:22:35.759 +0100] DEBUG  : [App] [Scrobblers] [Listenbrainz - cli-visyn-listenbrainz] Client was filtered out by Source 'Source - Listenbrainz - src-hidyn-listenbrainz'
[2024-07-23 15:22:35.759 +0100] DEBUG  : [App] [Sources] [Listenbrainz - src-hidyn-listenbrainz] Last activity was at 2024-07-23T15:19:06+01:00 | Next check interval: 15.00s
[2024-07-23 15:22:36.495 +0100] INFO   : [App] [Scrobblers] [Maloja - cli-hidyn-maloja] Scrobbled (Backlog)     => (listenbrainz) Queens of the Stone Age - Feel Good Hit of the Summer @ 2024-07-23T15:19:06+01:00 (S)
[2024-07-23 15:22:36.495 +0100] DEBUG  : [App] [Scrobblers] [Maloja - cli-hidyn-maloja] Raw Payload:
[2024-07-23 15:22:36.779 +0100] INFO   : [App] [Scrobblers] [Lastfm - cli-hidyn-lastfm] Scrobbled (Backlog) => (listenbrainz) Queens of the Stone Age - Feel Good Hit of the Summer @ 2024-07-23T15:19:06+01:00 (S)
[2024-07-23 15:22:36.780 +0100] DEBUG  : [App] [Scrobblers] [Lastfm - cli-hidyn-lastfm] Raw Payload: 
[2024-07-23 15:22:45.975 +0100] DEBUG  : [App] [Sources] [Lastfm - src-hidyn-lastfm] Refreshing recently played
[2024-07-23 15:22:46.293 +0100] INFO   : [App] [Sources] [Lastfm - src-hidyn-lastfm] Discovered => Queens of the Stone Age - Feel Good Hit of the Summer @ 2024-07-23T15:19:06+01:00 (S)
[2024-07-23 15:22:46.294 +0100] DEBUG  : [App] [Scrobblers] [Maloja - cli-hidyn-maloja] Client was filtered out by Source 'Source - Lastfm - src-hidyn-lastfm'
[2024-07-23 15:22:46.294 +0100] DEBUG  : [App] [Scrobblers] [Lastfm - cli-hidyn-lastfm] Client was filtered out by Source 'Source - Lastfm - src-hidyn-lastfm'
[2024-07-23 15:22:46.294 +0100] DEBUG  : [App] [Scrobblers] [Listenbrainz - cli-visyn-listenbrainz] Client was filtered out by Source 'Source - Lastfm - src-hidyn-lastfm'
[2024-07-23 15:22:46.294 +0100] DEBUG  : [App] [Sources] [Lastfm - src-hidyn-lastfm] Last activity was at 2024-07-23T15:22:46+01:00 | Next check interval: 15.00s
[2024-07-23 15:22:47.540 +0100] DEBUG  : [App] [Scrobblers] [Listenbrainz - cli-hidyn-listenbrainz] Lastfm: Queens of the Stone Age - Feel Good Hit of the Summer @ 2024-07-23T15:19:06+01:00 (S) => Closest Scrobble: Queens of the Stone Age - What the Peephole Say @ 2024-07-23T14:00:13+01:00 (S) => Score 0.41 => No Match
[2024-07-23 15:22:47.541 +0100] DEBUG  : [App] [Scrobblers] [Listenbrainz - cli-hidyn-listenbrainz] Breakdown:
Artist: 1.00 * 0.3 = 0.30
Title: 0.27 * 0.4 = 0.11
Time: (No correlation) 0 * 0.5 = 0.00
Time Detail => Existing: 14:00:13+01:00 - Candidate: 15:19:06+01:00 | Temporal Sameness: No correlation | Play Diff: 4,733s (Needed <10s) | Range Comparison N/A
Score 0.41 => No Match
[2024-07-23 15:22:47.651 +0100] INFO   : [App] [Scrobblers] [Listenbrainz - cli-hidyn-listenbrainz] Scrobbled (Backlog) => (Lastfm) Queens of the Stone Age - Feel Good Hit of the Summer @ 2024-07-23T15:19:06+01:00 (S)
[2024-07-23 15:22:47.652 +0100] DEBUG  : [App] [Scrobblers] [Listenbrainz - cli-hidyn-listenbrainz] Raw Payload:
[2024-07-23 15:22:50.274 +0100] DEBUG  : [App] [Sources] [Listenbrainz - src-hidyn-listenbrainz] Refreshing recently played
[2024-07-23 15:22:50.914 +0100] DEBUG  : [App] [Sources] [Listenbrainz - src-hidyn-listenbrainz] No new tracks discovered
[2024-07-23 15:22:50.914 +0100] DEBUG  : [App] [Sources] [Listenbrainz - src-hidyn-listenbrainz] Last activity was at 2024-07-23T15:19:06+01:00 | Next check interval: 15.00s
[2024-07-23 15:23:01.302 +0100] DEBUG  : [App] [Sources] [Lastfm - src-hidyn-lastfm] Refreshing recently played
[2024-07-23 15:23:01.619 +0100] DEBUG  : [App] [Sources] [Lastfm - src-hidyn-lastfm] No new tracks discovered
[2024-07-23 15:23:01.620 +0100] DEBUG  : [App] [Sources] [Lastfm - src-hidyn-lastfm] Last activity was at 2024-07-23T15:23:01+01:00 | Next check interval: 15.00s
[2024-07-23 15:23:05.421 +0100] DEBUG  : [App] [Sources] [Listenbrainz - src-hidyn-listenbrainz] Refreshing recently played
[2024-07-23 15:23:06.040 +0100] DEBUG  : [App] [Sources] [Listenbrainz - src-hidyn-listenbrainz] No new tracks discovered
[2024-07-23 15:23:06.041 +0100] DEBUG  : [App] [Sources] [Listenbrainz - src-hidyn-listenbrainz] Last activity was at 2024-07-23T15:19:06+01:00 | Next check interval: 15.00s
[2024-07-23 15:23:16.630 +0100] DEBUG  : [App] [Sources] [Lastfm - src-hidyn-lastfm] Refreshing recently played

@FoxxMD
Copy link
Owner

FoxxMD commented Jul 23, 2024

the reason I didn't go this route initially is because Last.fm is awful at handling multi-artist tracks compared to ListenBrainz and Maloja

True, LFM has the least data-rich scrobbling. Why do you need to scrobble back to LFM from LZ? Couldn't it be:

Roon -> LFM -> LZ
Pano -> LZ
LZ -> Maloja

Or is LFM for recommendations?

P.S. Roon has an API and I've been wanting to implement it as a source but I've had a hard time getting the company to communicate. I don't want to pay for it as I won't really be using it, just developing for it.

@HidYn
Copy link
Author

HidYn commented Jul 23, 2024

If I didn't have a brand new 4 day old to look after I'd look to spring for a licence for you just to add Roon as a source. Honestly Roon is amazing and I struggle to find anything as good for playlists and auto-radio. The fact it can cast to pretty much any speaker in the house flawlessly too (AirPlay/Chromecast etc) I tried replacing it with MusicAssistant but it's not there yet.

@FoxxMD
Copy link
Owner

FoxxMD commented Jul 23, 2024

Thanks for the logs. Do you have any logs from when the original scrobble was made?

brand new 4 day old

Congratulations! Totally get it I appreciate the donations already. I'll get to Roon eventually...

@HidYn
Copy link
Author

HidYn commented Jul 23, 2024

Sorry was just trying to keep it to what you might need so you don't have to read loads you might not need.

Only Roon log I could find

07/23 15:21:49 Debug: Lastfm 'jfjfjyjhjghdsfgdsfgdfghdfgh' DONE: Queens of the Stone Age - Feel Good Hit Of The Summer (Album Version)

So it seems Roon is only logging the (Album Version) I don't get what's happening on Last.fm's side to remove that and duplicate the log.

Here's a more expanded log from MS

[2024-07-23 15:19:12.664 +0100] DEBUG  : [App] [Scrobblers] [Listenbrainz - cli-hidyn-listenbrainz] Lastfm: Foo Fighters - Under You @ 2024-07-23T15:15:24+01:00 (S) => Closest Scrobble: H.E.R. & Foo Fighters - The Glass @ 2024-07-23T14:22:33+01:00 (S) => Score 0.14 => No Match
[2024-07-23 15:19:12.664 +0100] DEBUG  : [App] [Scrobblers] [Listenbrainz - cli-hidyn-listenbrainz] Breakdown:
Artist: 0.38 * 0.3 = 0.12
Title: 0.06 * 0.4 = 0.02
Time: (No correlation) 0 * 0.5 = 0.00
Time Detail => Existing: 14:22:33+01:00 - Candidate: 15:15:24+01:00 | Temporal Sameness: No correlation | Play Diff: 3,171s (Needed <10s) | Range Comparison N/A
Score 0.14 => No Match
[2024-07-23 15:19:12.776 +0100] INFO   : [App] [Scrobblers] [Listenbrainz - cli-hidyn-listenbrainz] Scrobbled (Backlog) => (Lastfm) Foo Fighters - Under You @ 2024-07-23T15:15:24+01:00 (S)
[2024-07-23 15:19:12.777 +0100] DEBUG  : [App] [Scrobblers] [Listenbrainz - cli-hidyn-listenbrainz] Raw Payload:
[2024-07-23 15:19:26.972 +0100] DEBUG  : [App] [Sources] [Lastfm - src-hidyn-lastfm] Refreshing recently played
[2024-07-23 15:19:27.475 +0100] DEBUG  : [App] [Sources] [Lastfm - src-visyn-lastfm] Refreshing recently played
[2024-07-23 15:19:27.497 +0100] DEBUG  : [App] [Sources] [Lastfm - src-hidyn-lastfm] No new tracks discovered
[2024-07-23 15:19:27.498 +0100] DEBUG  : [App] [Sources] [Lastfm - src-hidyn-lastfm] Last activity was at 2024-07-23T15:19:27+01:00 | Next check interval: 15.00s
[2024-07-23 15:19:27.923 +0100] DEBUG  : [App] [Sources] [Lastfm - src-visyn-lastfm] No new tracks discovered
[2024-07-23 15:19:27.923 +0100] DEBUG  : [App] [Sources] [Lastfm - src-visyn-lastfm] Last activity 2024-07-23T14:28:59+01:00 is an hour outside of polling period (last activity + 300s) | Next check interval: (15 + 45)s
[2024-07-23 15:19:42.008 +0100] DEBUG  : [App] [Sources] [Lastfm - src-hidyn-lastfm] Refreshing recently played
[2024-07-23 15:19:42.736 +0100] DEBUG  : [App] [Sources] [Lastfm - src-hidyn-lastfm] No new tracks discovered
[2024-07-23 15:19:42.736 +0100] DEBUG  : [App] [Sources] [Lastfm - src-hidyn-lastfm] Last activity was at 2024-07-23T15:19:42+01:00 | Next check interval: 15.00s
[2024-07-23 15:19:57.244 +0100] DEBUG  : [App] [Sources] [Lastfm - src-hidyn-lastfm] Refreshing recently played
[2024-07-23 15:19:57.529 +0100] DEBUG  : [App] [Sources] [Lastfm - src-hidyn-lastfm] No new tracks discovered
[2024-07-23 15:19:57.530 +0100] DEBUG  : [App] [Sources] [Lastfm - src-hidyn-lastfm] Last activity was at 2024-07-23T15:19:57+01:00 | Next check interval: 15.00s
[2024-07-23 15:20:10.253 +0100] DEBUG  : [App] [Sources] [Listenbrainz - src-hidyn-listenbrainz] Refreshing recently played
[2024-07-23 15:20:10.911 +0100] INFO   : [App] [Sources] [Listenbrainz - src-hidyn-listenbrainz] Discovered => Foo Fighters - Under You @ 2024-07-23T15:15:24+01:00 (S)
[2024-07-23 15:20:10.916 +0100] DEBUG  : [App] [Scrobblers] [Listenbrainz - cli-hidyn-listenbrainz] Client was filtered out by Source 'Source - Listenbrainz - src-hidyn-listenbrainz'
[2024-07-23 15:20:10.916 +0100] DEBUG  : [App] [Scrobblers] [Listenbrainz - cli-visyn-listenbrainz] Client was filtered out by Source 'Source - Listenbrainz - src-hidyn-listenbrainz'
[2024-07-23 15:20:10.916 +0100] DEBUG  : [App] [Sources] [Listenbrainz - src-hidyn-listenbrainz] Last activity was at 2024-07-23T15:15:24+01:00 | Next check interval: 15.00s
[2024-07-23 15:20:12.244 +0100] DEBUG  : [App] [Scrobblers] [Lastfm - cli-hidyn-lastfm] Refreshing recent scrobbles
[2024-07-23 15:20:12.353 +0100] DEBUG  : [App] [Scrobblers] [Maloja - cli-hidyn-maloja] Refreshing recent scrobbles
[2024-07-23 15:20:12.380 +0100] DEBUG  : [App] [Scrobblers] [Maloja - cli-hidyn-maloja] Found 40 recent scrobbles
[2024-07-23 15:20:12.432 +0100] INFO   : [App] [Scrobblers] [Maloja - cli-hidyn-maloja] Scrobbled (Backlog)     => (listenbrainz) Foo Fighters - Under You @ 2024-07-23T15:15:24+01:00 (S)
[2024-07-23 15:20:12.432 +0100] DEBUG  : [App] [Scrobblers] [Maloja - cli-hidyn-maloja] Raw Payload:
[2024-07-23 15:20:12.535 +0100] DEBUG  : [App] [Sources] [Lastfm - src-hidyn-lastfm] Refreshing recently played
[2024-07-23 15:20:12.582 +0100] DEBUG  : [App] [Scrobblers] [Lastfm - cli-hidyn-lastfm] Ignoring 'now playing' track returned from Last.fm client
[2024-07-23 15:20:12.583 +0100] DEBUG  : [App] [Scrobblers] [Lastfm - cli-hidyn-lastfm] Found 40 recent scrobbles
[2024-07-23 15:20:12.838 +0100] DEBUG  : [App] [Sources] [Lastfm - src-hidyn-lastfm] No new tracks discovered
[2024-07-23 15:20:12.838 +0100] DEBUG  : [App] [Sources] [Lastfm - src-hidyn-lastfm] Last activity was at 2024-07-23T15:20:12+01:00 | Next check interval: 15.00s
[2024-07-23 15:20:25.423 +0100] DEBUG  : [App] [Sources] [Listenbrainz - src-hidyn-listenbrainz] Refreshing recently played
[2024-07-23 15:20:26.067 +0100] DEBUG  : [App] [Sources] [Listenbrainz - src-hidyn-listenbrainz] No new tracks discovered
[2024-07-23 15:20:26.067 +0100] DEBUG  : [App] [Sources] [Listenbrainz - src-hidyn-listenbrainz] Last activity 2024-07-23T15:15:24+01:00 is a few seconds outside of polling period (last activity + 300s) | Next check interval: (15 + 5)s
[2024-07-23 15:20:27.848 +0100] DEBUG  : [App] [Sources] [Lastfm - src-hidyn-lastfm] Refreshing recently played
[2024-07-23 15:20:27.957 +0100] DEBUG  : [App] [Sources] [Lastfm - src-visyn-lastfm] Refreshing recently played
[2024-07-23 15:20:28.126 +0100] DEBUG  : [App] [Sources] [Lastfm - src-hidyn-lastfm] No new tracks discovered
[2024-07-23 15:20:28.126 +0100] DEBUG  : [App] [Sources] [Lastfm - src-hidyn-lastfm] Last activity was at 2024-07-23T15:20:28+01:00 | Next check interval: 15.00s
[2024-07-23 15:20:28.396 +0100] DEBUG  : [App] [Sources] [Lastfm - src-visyn-lastfm] No new tracks discovered
[2024-07-23 15:20:28.397 +0100] DEBUG  : [App] [Sources] [Lastfm - src-visyn-lastfm] Last activity 2024-07-23T14:28:59+01:00 is an hour outside of polling period (last activity + 300s) | Next check interval: (15 + 45)s
[2024-07-23 15:20:43.133 +0100] DEBUG  : [App] [Sources] [Lastfm - src-hidyn-lastfm] Refreshing recently played
[2024-07-23 15:20:43.395 +0100] DEBUG  : [App] [Sources] [Lastfm - src-hidyn-lastfm] No new tracks discovered
[2024-07-23 15:20:43.396 +0100] DEBUG  : [App] [Sources] [Lastfm - src-hidyn-lastfm] Last activity was at 2024-07-23T15:20:43+01:00 | Next check interval: 15.00s
[2024-07-23 15:20:45.575 +0100] DEBUG  : [App] [Sources] [Listenbrainz - src-hidyn-listenbrainz] Refreshing recently played
[2024-07-23 15:20:46.223 +0100] DEBUG  : [App] [Sources] [Listenbrainz - src-hidyn-listenbrainz] No new tracks discovered
[2024-07-23 15:20:46.224 +0100] DEBUG  : [App] [Sources] [Listenbrainz - src-hidyn-listenbrainz] Last activity 2024-07-23T15:15:24+01:00 is a few seconds outside of polling period (last activity + 300s) | Next check interval: (15 + 9)s
[2024-07-23 15:20:58.404 +0100] DEBUG  : [App] [Sources] [Lastfm - src-hidyn-lastfm] Refreshing recently played
[2024-07-23 15:20:58.843 +0100] DEBUG  : [App] [Sources] [Lastfm - src-hidyn-lastfm] No new tracks discovered
[2024-07-23 15:20:58.844 +0100] DEBUG  : [App] [Sources] [Lastfm - src-hidyn-lastfm] Last activity was at 2024-07-23T15:20:58+01:00 | Next check interval: 15.00s
[2024-07-23 15:21:09.749 +0100] DEBUG  : [App] [Sources] [Listenbrainz - src-hidyn-listenbrainz] Refreshing recently played
[2024-07-23 15:21:10.406 +0100] DEBUG  : [App] [Sources] [Listenbrainz - src-hidyn-listenbrainz] No new tracks discovered
[2024-07-23 15:21:10.407 +0100] DEBUG  : [App] [Sources] [Listenbrainz - src-hidyn-listenbrainz] Last activity 2024-07-23T15:15:24+01:00 is a minute outside of polling period (last activity + 300s) | Next check interval: (15 + 20)s
[2024-07-23 15:21:13.848 +0100] DEBUG  : [App] [Sources] [Lastfm - src-hidyn-lastfm] Refreshing recently played
[2024-07-23 15:21:14.169 +0100] DEBUG  : [App] [Sources] [Lastfm - src-hidyn-lastfm] No new tracks discovered
[2024-07-23 15:21:14.169 +0100] DEBUG  : [App] [Sources] [Lastfm - src-hidyn-lastfm] Last activity was at 2024-07-23T15:21:14+01:00 | Next check interval: 15.00s
[2024-07-23 15:21:28.427 +0100] DEBUG  : [App] [Sources] [Lastfm - src-visyn-lastfm] Refreshing recently played
[2024-07-23 15:21:28.743 +0100] DEBUG  : [App] [Sources] [Lastfm - src-visyn-lastfm] No new tracks discovered
[2024-07-23 15:21:28.744 +0100] DEBUG  : [App] [Sources] [Lastfm - src-visyn-lastfm] Last activity 2024-07-23T14:28:59+01:00 is an hour outside of polling period (last activity + 300s) | Next check interval: (15 + 45)s
[2024-07-23 15:21:29.182 +0100] DEBUG  : [App] [Sources] [Lastfm - src-hidyn-lastfm] Refreshing recently played
[2024-07-23 15:21:31.058 +0100] DEBUG  : [App] [Sources] [Lastfm - src-hidyn-lastfm] No new tracks discovered
[2024-07-23 15:21:31.059 +0100] DEBUG  : [App] [Sources] [Lastfm - src-hidyn-lastfm] Last activity was at 2024-07-23T15:21:14+01:00 | Next check interval: 15.00s
[2024-07-23 15:21:44.564 +0100] DEBUG  : [App] [Sources] [Lastfm - src-hidyn-lastfm] Refreshing recently played
[2024-07-23 15:21:44.832 +0100] DEBUG  : [App] [Sources] [Lastfm - src-hidyn-lastfm] No new tracks discovered
[2024-07-23 15:21:44.832 +0100] DEBUG  : [App] [Sources] [Lastfm - src-hidyn-lastfm] Last activity was at 2024-07-23T15:21:44+01:00 | Next check interval: 15.00s
[2024-07-23 15:21:44.918 +0100] DEBUG  : [App] [Sources] [Listenbrainz - src-hidyn-listenbrainz] Refreshing recently played
[2024-07-23 15:21:45.567 +0100] DEBUG  : [App] [Sources] [Listenbrainz - src-hidyn-listenbrainz] No new tracks discovered
[2024-07-23 15:21:45.567 +0100] DEBUG  : [App] [Sources] [Listenbrainz - src-hidyn-listenbrainz] Last activity 2024-07-23T15:15:24+01:00 is a minute outside of polling period (last activity + 300s) | Next check interval: (15 + 35)s
[2024-07-23 15:21:59.839 +0100] DEBUG  : [App] [Sources] [Lastfm - src-hidyn-lastfm] Refreshing recently played
[2024-07-23 15:22:00.211 +0100] DEBUG  : [App] [Sources] [Lastfm - src-hidyn-lastfm] [Player NoDevice-SingleUser] Incoming play state (Blur - Barbaric) does not match existing state, removing existing: Queens of the Stone Age - Feel Good Hit of the Summer (Album Version)
[2024-07-23 15:22:00.212 +0100] DEBUG  : [App] [Sources] [Lastfm - src-hidyn-lastfm] [Player NoDevice-SingleUser] Ended current Player listen range.
[2024-07-23 15:22:00.213 +0100] DEBUG  : [App] [Sources] [Lastfm - src-hidyn-lastfm] [Player NoDevice-SingleUser] Generating play object with playDateCompleted
[2024-07-23 15:22:00.213 +0100] DEBUG  : [App] [Sources] [Lastfm - src-hidyn-lastfm] [Player NoDevice-SingleUser] New Play: Blur - Barbaric
[2024-07-23 15:22:00.213 +0100] DEBUG  : [App] [Sources] [Lastfm - src-hidyn-lastfm] [Player NoDevice-SingleUser] Started new Player listen range.
[2024-07-23 15:22:00.216 +0100] INFO   : [App] [Sources] [Lastfm - src-hidyn-lastfm] Discovered => Queens of the Stone Age - Feel Good Hit of the Summer (Album Version) @ 2024-07-23T15:19:06+01:00 (S)
[2024-07-23 15:22:00.216 +0100] DEBUG  : [App] [Scrobblers] [Maloja - cli-hidyn-maloja] Client was filtered out by Source 'Source - Lastfm - src-hidyn-lastfm'
[2024-07-23 15:22:00.217 +0100] DEBUG  : [App] [Scrobblers] [Lastfm - cli-hidyn-lastfm] Client was filtered out by Source 'Source - Lastfm - src-hidyn-lastfm'
[2024-07-23 15:22:00.217 +0100] DEBUG  : [App] [Scrobblers] [Listenbrainz - cli-visyn-listenbrainz] Client was filtered out by Source 'Source - Lastfm - src-hidyn-lastfm'
[2024-07-23 15:22:00.217 +0100] DEBUG  : [App] [Sources] [Lastfm - src-hidyn-lastfm] Last activity was at 2024-07-23T15:22:00+01:00 | Next check interval: 15.00s
[2024-07-23 15:22:00.791 +0100] DEBUG  : [App] [Scrobblers] [Listenbrainz - cli-hidyn-listenbrainz] Refreshing recent scrobbles
[2024-07-23 15:22:01.397 +0100] DEBUG  : [App] [Scrobblers] [Listenbrainz - cli-hidyn-listenbrainz] Found 40 recent scrobbles
[2024-07-23 15:22:01.409 +0100] DEBUG  : [App] [Scrobblers] [Listenbrainz - cli-hidyn-listenbrainz] Lastfm: Queens of the Stone Age - Feel Good Hit of the Summer... @ 2024-07-23T15:19:06+01:00 (S) => Closest Scrobble: Queens of the Stone Age - What the Peephole Say @ 2024-07-23T14:00:13+01:00 (S) => Score 0.35 => No Match
[2024-07-23 15:22:01.409 +0100] DEBUG  : [App] [Scrobblers] [Listenbrainz - cli-hidyn-listenbrainz] Breakdown:
Artist: 1.00 * 0.3 = 0.30
Title: 0.12 * 0.4 = 0.05
Time: (No correlation) 0 * 0.5 = 0.00
Time Detail => Existing: 14:00:13+01:00 - Candidate: 15:19:06+01:00 | Temporal Sameness: No correlation | Play Diff: 4,733s (Needed <10s) | Range Comparison N/A
Score 0.35 => No Match
[2024-07-23 15:22:01.521 +0100] INFO   : [App] [Scrobblers] [Listenbrainz - cli-hidyn-listenbrainz] Scrobbled (Backlog) => (Lastfm) Queens of the Stone Age - Feel Good Hit of the Summer (Album Version) @ 2024-07-23T15:19:06+01:00 (S)
[2024-07-23 15:22:01.522 +0100] DEBUG  : [App] [Scrobblers] [Listenbrainz - cli-hidyn-listenbrainz] Raw Payload:
[2024-07-23 15:22:15.224 +0100] DEBUG  : [App] [Sources] [Lastfm - src-hidyn-lastfm] Refreshing recently played
[2024-07-23 15:22:15.518 +0100] DEBUG  : [App] [Sources] [Lastfm - src-hidyn-lastfm] No new tracks discovered
[2024-07-23 15:22:15.519 +0100] DEBUG  : [App] [Sources] [Lastfm - src-hidyn-lastfm] Last activity was at 2024-07-23T15:22:15+01:00 | Next check interval: 15.00s
[2024-07-23 15:22:28.779 +0100] DEBUG  : [App] [Sources] [Lastfm - src-visyn-lastfm] Refreshing recently played
[2024-07-23 15:22:29.068 +0100] DEBUG  : [App] [Sources] [Lastfm - src-visyn-lastfm] No new tracks discovered
[2024-07-23 15:22:29.068 +0100] DEBUG  : [App] [Sources] [Lastfm - src-visyn-lastfm] Last activity 2024-07-23T14:28:59+01:00 is an hour outside of polling period (last activity + 300s) | Next check interval: (15 + 45)s
[2024-07-23 15:22:30.533 +0100] DEBUG  : [App] [Sources] [Lastfm - src-hidyn-lastfm] Refreshing recently played
[2024-07-23 15:22:30.967 +0100] DEBUG  : [App] [Sources] [Lastfm - src-hidyn-lastfm] No new tracks discovered
[2024-07-23 15:22:30.968 +0100] DEBUG  : [App] [Sources] [Lastfm - src-hidyn-lastfm] Last activity was at 2024-07-23T15:22:30+01:00 | Next check interval: 15.00s
[2024-07-23 15:22:35.096 +0100] DEBUG  : [App] [Sources] [Listenbrainz - src-hidyn-listenbrainz] Refreshing recently played
[2024-07-23 15:22:35.753 +0100] INFO   : [App] [Sources] [Listenbrainz - src-hidyn-listenbrainz] Discovered => Queens of the Stone Age - Feel Good Hit of the Summer @ 2024-07-23T15:19:06+01:00 (S)
[2024-07-23 15:22:35.759 +0100] DEBUG  : [App] [Scrobblers] [Listenbrainz - cli-hidyn-listenbrainz] Client was filtered out by Source 'Source - Listenbrainz - src-hidyn-listenbrainz'
[2024-07-23 15:22:35.759 +0100] DEBUG  : [App] [Scrobblers] [Listenbrainz - cli-visyn-listenbrainz] Client was filtered out by Source 'Source - Listenbrainz - src-hidyn-listenbrainz'
[2024-07-23 15:22:35.759 +0100] DEBUG  : [App] [Sources] [Listenbrainz - src-hidyn-listenbrainz] Last activity was at 2024-07-23T15:19:06+01:00 | Next check interval: 15.00s
[2024-07-23 15:22:36.495 +0100] INFO   : [App] [Scrobblers] [Maloja - cli-hidyn-maloja] Scrobbled (Backlog)     => (listenbrainz) Queens of the Stone Age - Feel Good Hit of the Summer @ 2024-07-23T15:19:06+01:00 (S)
[2024-07-23 15:22:36.495 +0100] DEBUG  : [App] [Scrobblers] [Maloja - cli-hidyn-maloja] Raw Payload:
[2024-07-23 15:22:36.779 +0100] INFO   : [App] [Scrobblers] [Lastfm - cli-hidyn-lastfm] Scrobbled (Backlog) => (listenbrainz) Queens of the Stone Age - Feel Good Hit of the Summer @ 2024-07-23T15:19:06+01:00 (S)
[2024-07-23 15:22:36.780 +0100] DEBUG  : [App] [Scrobblers] [Lastfm - cli-hidyn-lastfm] Raw Payload: 
[2024-07-23 15:22:45.975 +0100] DEBUG  : [App] [Sources] [Lastfm - src-hidyn-lastfm] Refreshing recently played
[2024-07-23 15:22:46.293 +0100] INFO   : [App] [Sources] [Lastfm - src-hidyn-lastfm] Discovered => Queens of the Stone Age - Feel Good Hit of the Summer @ 2024-07-23T15:19:06+01:00 (S)
[2024-07-23 15:22:46.294 +0100] DEBUG  : [App] [Scrobblers] [Maloja - cli-hidyn-maloja] Client was filtered out by Source 'Source - Lastfm - src-hidyn-lastfm'
[2024-07-23 15:22:46.294 +0100] DEBUG  : [App] [Scrobblers] [Lastfm - cli-hidyn-lastfm] Client was filtered out by Source 'Source - Lastfm - src-hidyn-lastfm'
[2024-07-23 15:22:46.294 +0100] DEBUG  : [App] [Scrobblers] [Listenbrainz - cli-visyn-listenbrainz] Client was filtered out by Source 'Source - Lastfm - src-hidyn-lastfm'
[2024-07-23 15:22:46.294 +0100] DEBUG  : [App] [Sources] [Lastfm - src-hidyn-lastfm] Last activity was at 2024-07-23T15:22:46+01:00 | Next check interval: 15.00s
[2024-07-23 15:22:47.540 +0100] DEBUG  : [App] [Scrobblers] [Listenbrainz - cli-hidyn-listenbrainz] Lastfm: Queens of the Stone Age - Feel Good Hit of the Summer @ 2024-07-23T15:19:06+01:00 (S) => Closest Scrobble: Queens of the Stone Age - What the Peephole Say @ 2024-07-23T14:00:13+01:00 (S) => Score 0.41 => No Match
[2024-07-23 15:22:47.541 +0100] DEBUG  : [App] [Scrobblers] [Listenbrainz - cli-hidyn-listenbrainz] Breakdown:
Artist: 1.00 * 0.3 = 0.30
Title: 0.27 * 0.4 = 0.11
Time: (No correlation) 0 * 0.5 = 0.00
Time Detail => Existing: 14:00:13+01:00 - Candidate: 15:19:06+01:00 | Temporal Sameness: No correlation | Play Diff: 4,733s (Needed <10s) | Range Comparison N/A
Score 0.41 => No Match
[2024-07-23 15:22:47.651 +0100] INFO   : [App] [Scrobblers] [Listenbrainz - cli-hidyn-listenbrainz] Scrobbled (Backlog) => (Lastfm) Queens of the Stone Age - Feel Good Hit of the Summer @ 2024-07-23T15:19:06+01:00 (S)
[2024-07-23 15:22:47.652 +0100] DEBUG  : [App] [Scrobblers] [Listenbrainz - cli-hidyn-listenbrainz] Raw Payload:
[2024-07-23 15:22:50.274 +0100] DEBUG  : [App] [Sources] [Listenbrainz - src-hidyn-listenbrainz] Refreshing recently played
[2024-07-23 15:22:50.914 +0100] DEBUG  : [App] [Sources] [Listenbrainz - src-hidyn-listenbrainz] No new tracks discovered
[2024-07-23 15:22:50.914 +0100] DEBUG  : [App] [Sources] [Listenbrainz - src-hidyn-listenbrainz] Last activity was at 2024-07-23T15:19:06+01:00 | Next check interval: 15.00s
[2024-07-23 15:23:01.302 +0100] DEBUG  : [App] [Sources] [Lastfm - src-hidyn-lastfm] Refreshing recently played
[2024-07-23 15:23:01.619 +0100] DEBUG  : [App] [Sources] [Lastfm - src-hidyn-lastfm] No new tracks discovered
[2024-07-23 15:23:01.620 +0100] DEBUG  : [App] [Sources] [Lastfm - src-hidyn-lastfm] Last activity was at 2024-07-23T15:23:01+01:00 | Next check interval: 15.00s
[2024-07-23 15:23:05.421 +0100] DEBUG  : [App] [Sources] [Listenbrainz - src-hidyn-listenbrainz] Refreshing recently played
[2024-07-23 15:23:06.040 +0100] DEBUG  : [App] [Sources] [Listenbrainz - src-hidyn-listenbrainz] No new tracks discovered
[2024-07-23 15:23:06.041 +0100] DEBUG  : [App] [Sources] [Listenbrainz - src-hidyn-listenbrainz] Last activity was at 2024-07-23T15:19:06+01:00 | Next check interval: 15.00s
[2024-07-23 15:23:16.630 +0100] DEBUG  : [App] [Sources] [Lastfm - src-hidyn-lastfm] Refreshing recently played
[2024-07-23 15:23:16.931 +0100] DEBUG  : [App] [Sources] [Lastfm - src-hidyn-lastfm] No new tracks discovered
[2024-07-23 15:23:16.931 +0100] DEBUG  : [App] [Sources] [Lastfm - src-hidyn-lastfm] Last activity was at 2024-07-23T15:23:16+01:00 | Next check interval: 15.00s
[2024-07-23 15:23:20.557 +0100] DEBUG  : [App] [Sources] [Listenbrainz - src-hidyn-listenbrainz] Refreshing recently played
[2024-07-23 15:23:21.221 +0100] DEBUG  : [App] [Sources] [Listenbrainz - src-hidyn-listenbrainz] No new tracks discovered
[2024-07-23 15:23:21.221 +0100] DEBUG  : [App] [Sources] [Listenbrainz - src-hidyn-listenbrainz] Last activity was at 2024-07-23T15:19:06+01:00 | Next check interval: 15.00s

If you think the feedback loop is the cause I'll ditch it and setup how you suggest. As poor as Last.fm is now compared to ListenBrainz and Maloja it's hard to let go of an old friend isn't it ha but if this is the cause I'll bite the bullet.

P.S. You know Roon does a 14 day trial? Granted not a great amount of time to work in but maybe you can use multiple different e-mails to sign up.

@FoxxMD
Copy link
Owner

FoxxMD commented Jul 23, 2024

You know Roon does a 14 day trial?

Yeah...and it's probably enough time to implement a Source but then I need to be able to support users going forward which may require me to reproduce behavior from Roon as well as provide fixes and update the api when they cut new releases. I'd be paying them $15/mo so that I can provide free software to make their product better. It doesn't sit well with me.

Here's a more expanded log from MS

Ok so here's what I'm parsing from the log (putting here for you but more for future me):


LFM source discovers track from history

[2024-07-23 15:22:00.216 +0100] INFO   : [App] [Sources] [Lastfm - src-hidyn-lastfm] Discovered => Queens of the Stone Age - Feel Good Hit of the Summer (Album Version) @ 2024-07-23T15:19:06+01:00 (S)

LZ client refreshes existing scrobbles (history)

[2024-07-23 15:22:00.791 +0100] DEBUG  : [App] [Scrobblers] [Listenbrainz - cli-hidyn-listenbrainz] Refreshing recent scrobbles
[2024-07-23 15:22:01.397 +0100] DEBUG  : [App] [Scrobblers] [Listenbrainz - cli-hidyn-listenbrainz] Found 40 recent scrobbles

LZ client existing scrobbles does not have track, scrobbles (correctly)

[2024-07-23 15:22:01.409 +0100] DEBUG  : [App] [Scrobblers] [Listenbrainz - cli-hidyn-listenbrainz] Lastfm: Queens of the Stone Age - Feel Good Hit of the Summer... @ 2024-07-23T15:19:06+01:00 (S) => Closest Scrobble: Queens of the Stone Age - What the Peephole Say @ 2024-07-23T14:00:13+01:00 (S) => Score 0.35 => No Match
[2024-07-23 15:22:01.521 +0100] INFO   : [App] [Scrobblers] [Listenbrainz - cli-hidyn-listenbrainz] Scrobbled (Backlog) => (Lastfm) Queens of the Stone Age - Feel Good Hit of the Summer (Album Version) @ 2024-07-23T15:19:06+01:00 (S)
^^^^ Should be storing sent scrobble

LZ source discovers track from history

[2024-07-23 15:22:35.096 +0100] DEBUG  : [App] [Sources] [Listenbrainz - src-hidyn-listenbrainz] Refreshing recently played
[2024-07-23 15:22:35.753 +0100] INFO   : [App] [Sources] [Listenbrainz - src-hidyn-listenbrainz] Discovered => Queens of the Stone Age - Feel Good Hit of the Summer @ 2024-07-23T15:19:06+01:00 (S)

Maloja client existing scrobbles does not have track, scrobbles

[2024-07-23 15:22:36.495 +0100] INFO   : [App] [Scrobblers] [Maloja - cli-hidyn-maloja] Scrobbled (Backlog)     => (listenbrainz) Queens of the Stone Age - Feel Good Hit of the Summer @ 2024-07-23T15:19:06+01:00 (S)

LFM client existing scrobbles (incorrectly) does not have track, scrobbles (May be fixed by forced history refresh)

[2024-07-23 15:22:36.779 +0100] INFO   : [App] [Scrobblers] [Lastfm - cli-hidyn-lastfm] Scrobbled (Backlog) => (listenbrainz) Queens of the Stone Age - Feel Good Hit of the Summer @ 2024-07-23T15:19:06+01:00 (S)

LFM source discovers duplicate track

[2024-07-23 15:22:45.975 +0100] DEBUG  : [App] [Sources] [Lastfm - src-hidyn-lastfm] Refreshing recently played
[2024-07-23 15:22:46.293 +0100] INFO   : [App] [Sources] [Lastfm - src-hidyn-lastfm] Discovered => Queens of the Stone Age - Feel Good Hit of the Summer @ 2024-07-23T15:19:06+01:00 (S)

LZ client (incorrectly) does not find duplicate in history (May be fixed by forced history refresh)

[2024-07-23 15:22:47.540 +0100] DEBUG  : [App] [Scrobblers] [Listenbrainz - cli-hidyn-listenbrainz] Lastfm: Queens of the Stone Age - Feel Good Hit of the Summer @ 2024-07-23T15:19:06+01:00 (S) => Closest Scrobble: Queens of the Stone Age - What the Peephole Say @ 2024-07-23T14:00:13+01:00 (S) => Score 0.41 => No Match
^^^ Should be checking sent scrobbles, is it not?

LZ client (incorrectly) scrobbles dup track

[2024-07-23 15:22:47.651 +0100] INFO   : [App] [Scrobblers] [Listenbrainz - cli-hidyn-listenbrainz] Scrobbled (Backlog) => (Lastfm) Queens of the Stone Age - Feel Good Hit of the Summer @ 2024-07-23T15:19:06+01:00 (S)

So there's two things going wrong here, other than the underlying feedback loop:

  • scrobble clients should refresh history if track to-be-scrobbled has a timestamp newer than than last history check -- but they are not for some reason
  • MS scrobble clients store their own sent scrobbles as well as upstream service scrobbles and (should be) checking both for duplicates -- but this sent scrobbles list isn't triggering dup detection. (This should be compensating for stale upstream scrobble history but isn't)

If you think the feedback loop is the cause I'll ditch it

This would definitely fix the issue but I don't think your scenario is unfixable. The mechanisms listed above should be working to preventing dups even with your set up. I will try to see if I can reproduce in a test suite and determine if these are actually bugs.

In the meantime you can brute-force the refresh history bug by using docker image foxxmd/multi-scrobbler:pr-174 with the config options mentioned in this comment to see if this resolves anything for you.

Additionally, you should add verbose.match options to cli-hidyn-lastfm so we can see if/how close the dup match logic is getting.

@HidYn
Copy link
Author

HidYn commented Jul 23, 2024

I've added both to help test the PR in the hope it's helpful for others. I'll be taking your advice and removing the loopback altogether afterwards though. What you suggested makes more sense.

Just to confirm where is best to place "refreshForce": true in my instance. On the source or client side? Currently have it added to the LB client and LFM client.

@FoxxMD
Copy link
Owner

FoxxMD commented Jul 23, 2024

Added to clients in the same options property as verbose.match

@HidYn
Copy link
Author

HidYn commented Jul 23, 2024

Great testing as we speak. This is what I have. Hopefully it's correct.

    "options": {
     "refreshForce": true,
     "verbose": {
        "match": {
          "onNoMatch": true,
          "confidenceBreakdown": true
        }
      }
    }

@FoxxMD
Copy link
Owner

FoxxMD commented Jul 23, 2024

Yes that is correct.

P.S. I've made a post on the roon forums as a final effort to try to get an account for dev.

@FoxxMD FoxxMD added the bug Something isn't working label Jul 23, 2024
@HidYn
Copy link
Author

HidYn commented Jul 23, 2024

Okay got another duplicate in Last.fm but it didn't get submitted to ListenBrainz.

Screenshot_20240723_195409

Screenshot_20240723_195433

[2024-07-23 19:43:06.551 +0100] DEBUG  : [App] [Sources] [Lastfm - src-hidyn-lastfm] No new tracks discovered
[2024-07-23 19:43:06.551 +0100] DEBUG  : [App] [Sources] [Lastfm - src-hidyn-lastfm] Last activity was at 2024-07-23T19:43:06+01:00 | Next check interval: 15.00s
[2024-07-23 19:43:21.559 +0100] DEBUG  : [App] [Sources] [Lastfm - src-hidyn-lastfm] Refreshing recently played
[2024-07-23 19:43:22.227 +0100] DEBUG  : [App] [Sources] [Lastfm - src-hidyn-lastfm] No new tracks discovered
[2024-07-23 19:43:22.228 +0100] DEBUG  : [App] [Sources] [Lastfm - src-hidyn-lastfm] Last activity was at 2024-07-23T19:43:22+01:00 | Next check interval: 15.00s
[2024-07-23 19:43:25.281 +0100] DEBUG  : [App] [Sources] [Listenbrainz - src-hidyn-listenbrainz] Refreshing recently played
[2024-07-23 19:43:25.946 +0100] DEBUG  : [App] [Sources] [Listenbrainz - src-hidyn-listenbrainz] No new tracks discovered
[2024-07-23 19:43:25.946 +0100] DEBUG  : [App] [Sources] [Listenbrainz - src-hidyn-listenbrainz] Last activity 2024-07-23T19:35:07+01:00 is 3 minutes outside of polling period (last activity + 300s) | Next check interval: (15 + 45)s
[2024-07-23 19:43:30.031 +0100] DEBUG  : [App] [Sources] [Lastfm - src-visyn-lastfm] Refreshing recently played
[2024-07-23 19:43:30.496 +0100] DEBUG  : [App] [Sources] [Lastfm - src-visyn-lastfm] No new tracks discovered
[2024-07-23 19:43:30.496 +0100] DEBUG  : [App] [Sources] [Lastfm - src-visyn-lastfm] Last activity 2024-07-23T16:58:26+01:00 is 3 hours outside of polling period (last activity + 300s) | Next check interval: (15 + 45)s
[2024-07-23 19:43:36.734 +0100] DEBUG  : [App] [Sources] [Lastfm - src-hidyn-lastfm] Refreshing recently played
[2024-07-23 19:43:37.123 +0100] DEBUG  : [App] [Sources] [Lastfm - src-hidyn-lastfm] [Player NoDevice-SingleUser] Incoming play state (Motion City Soundtrack - A-OK) does not match existing state, removing existing: The Starting Line - The B-List (Album Version)
[2024-07-23 19:43:37.123 +0100] DEBUG  : [App] [Sources] [Lastfm - src-hidyn-lastfm] [Player NoDevice-SingleUser] Ended current Player listen range.
[2024-07-23 19:43:37.123 +0100] DEBUG  : [App] [Sources] [Lastfm - src-hidyn-lastfm] [Player NoDevice-SingleUser] Generating play object with playDateCompleted
[2024-07-23 19:43:37.124 +0100] DEBUG  : [App] [Sources] [Lastfm - src-hidyn-lastfm] [Player NoDevice-SingleUser] New Play: Motion City Soundtrack - A-OK
[2024-07-23 19:43:37.124 +0100] DEBUG  : [App] [Sources] [Lastfm - src-hidyn-lastfm] [Player NoDevice-SingleUser] Started new Player listen range.
[2024-07-23 19:43:37.127 +0100] INFO   : [App] [Sources] [Lastfm - src-hidyn-lastfm] Discovered => The Starting Line - The B-List (Album Version) @ 2024-07-23T19:38:54+01:00 (S)
[2024-07-23 19:43:37.127 +0100] DEBUG  : [App] [Scrobblers] [Maloja - cli-hidyn-maloja] Client was filtered out by Source 'Source - Lastfm - src-hidyn-lastfm'
[2024-07-23 19:43:37.127 +0100] DEBUG  : [App] [Scrobblers] [Lastfm - cli-hidyn-lastfm] Client was filtered out by Source 'Source - Lastfm - src-hidyn-lastfm'
[2024-07-23 19:43:37.128 +0100] DEBUG  : [App] [Scrobblers] [Listenbrainz - cli-visyn-listenbrainz] Client was filtered out by Source 'Source - Lastfm - src-hidyn-lastfm'
[2024-07-23 19:43:37.128 +0100] DEBUG  : [App] [Sources] [Lastfm - src-hidyn-lastfm] Last activity was at 2024-07-23T19:43:37+01:00 | Next check interval: 15.00s
[2024-07-23 19:43:37.235 +0100] DEBUG  : [App] [Scrobblers] [Listenbrainz - cli-hidyn-listenbrainz] Refreshing recent scrobbles
[2024-07-23 19:43:37.759 +0100] DEBUG  : [App] [Scrobblers] [Listenbrainz - cli-hidyn-listenbrainz] Found 40 recent scrobbles
[2024-07-23 19:43:37.772 +0100] DEBUG  : [App] [Scrobblers] [Listenbrainz - cli-hidyn-listenbrainz] Lastfm: The Starting Line - The B-List (Album Version) @ 2024-07-23T19:38:54+01:00 (S) => Closest Scrobble: The Lillingtons - Invasion Of The Saucermen @ 2024-07-23T18:21:01+01:00 (S) => Score 0.23 => No Match
[2024-07-23 19:43:37.773 +0100] DEBUG  : [App] [Scrobblers] [Listenbrainz - cli-hidyn-listenbrainz] Breakdown:
Artist: 0.43 * 0.3 = 0.13
Title: 0.26 * 0.4 = 0.10
Time: (No correlation) 0 * 0.5 = 0.00
Time Detail => Existing: 18:21:01+01:00 - Candidate: 19:38:54+01:00 | Temporal Sameness: No correlation | Play Diff: 4,673s (Needed <10s) | Range Comparison N/A
Score 0.23 => No Match
[2024-07-23 19:43:37.885 +0100] INFO   : [App] [Scrobblers] [Listenbrainz - cli-hidyn-listenbrainz] Scrobbled (Backlog) => (Lastfm) The Starting Line - The B-List (Album Version) @ 2024-07-23T19:38:54+01:00 (S)
[2024-07-23 19:43:37.886 +0100] DEBUG  : [App] [Scrobblers] [Listenbrainz - cli-hidyn-listenbrainz] Raw Payload:
[2024-07-23 19:43:52.144 +0100] DEBUG  : [App] [Sources] [Lastfm - src-hidyn-lastfm] Refreshing recently played
[2024-07-23 19:43:52.495 +0100] DEBUG  : [App] [Sources] [Lastfm - src-hidyn-lastfm] No new tracks discovered
[2024-07-23 19:43:52.495 +0100] DEBUG  : [App] [Sources] [Lastfm - src-hidyn-lastfm] Last activity was at 2024-07-23T19:43:52+01:00 | Next check interval: 15.00s
[2024-07-23 19:44:07.498 +0100] DEBUG  : [App] [Sources] [Lastfm - src-hidyn-lastfm] Refreshing recently played
[2024-07-23 19:44:07.958 +0100] DEBUG  : [App] [Sources] [Lastfm - src-hidyn-lastfm] No new tracks discovered
[2024-07-23 19:44:07.959 +0100] DEBUG  : [App] [Sources] [Lastfm - src-hidyn-lastfm] Last activity was at 2024-07-23T19:44:07+01:00 | Next check interval: 15.00s
[2024-07-23 19:44:22.975 +0100] DEBUG  : [App] [Sources] [Lastfm - src-hidyn-lastfm] Refreshing recently played
[2024-07-23 19:44:23.405 +0100] DEBUG  : [App] [Sources] [Lastfm - src-hidyn-lastfm] No new tracks discovered
[2024-07-23 19:44:23.406 +0100] DEBUG  : [App] [Sources] [Lastfm - src-hidyn-lastfm] Last activity was at 2024-07-23T19:44:23+01:00 | Next check interval: 15.00s
[2024-07-23 19:44:25.480 +0100] DEBUG  : [App] [Sources] [Listenbrainz - src-hidyn-listenbrainz] Refreshing recently played
[2024-07-23 19:44:26.127 +0100] INFO   : [App] [Sources] [Listenbrainz - src-hidyn-listenbrainz] Discovered => The Starting Line - The B-List @ 2024-07-23T19:38:54+01:00 (S)
[2024-07-23 19:44:26.132 +0100] DEBUG  : [App] [Scrobblers] [Listenbrainz - cli-hidyn-listenbrainz] Client was filtered out by Source 'Source - Listenbrainz - src-hidyn-listenbrainz'
[2024-07-23 19:44:26.132 +0100] DEBUG  : [App] [Scrobblers] [Listenbrainz - cli-visyn-listenbrainz] Client was filtered out by Source 'Source - Listenbrainz - src-hidyn-listenbrainz'
[2024-07-23 19:44:26.132 +0100] DEBUG  : [App] [Sources] [Listenbrainz - src-hidyn-listenbrainz] Last activity 2024-07-23T19:38:54+01:00 is a few seconds outside of polling period (last activity + 300s) | Next check interval: (15 + 5)s
[2024-07-23 19:44:27.717 +0100] INFO   : [App] [Scrobblers] [Maloja - cli-hidyn-maloja] Scrobbled (Backlog)     => (listenbrainz) The Starting Line - The B-List @ 2024-07-23T19:38:54+01:00 (S)
[2024-07-23 19:44:27.718 +0100] DEBUG  : [App] [Scrobblers] [Maloja - cli-hidyn-maloja] Raw Payload:
[2024-07-23 19:44:28.085 +0100] DEBUG  : [App] [Scrobblers] [Lastfm - cli-hidyn-lastfm] Refreshing recent scrobbles
[2024-07-23 19:44:28.962 +0100] DEBUG  : [App] [Scrobblers] [Lastfm - cli-hidyn-lastfm] Ignoring 'now playing' track returned from Last.fm client
[2024-07-23 19:44:28.963 +0100] DEBUG  : [App] [Scrobblers] [Lastfm - cli-hidyn-lastfm] Found 40 recent scrobbles
[2024-07-23 19:44:28.972 +0100] DEBUG  : [App] [Scrobblers] [Lastfm - cli-hidyn-lastfm] Listenbrainz: The Starting Line - The B-List @ 2024-07-23T19:38:54+01:00 (S) => Closest Scrobble: The Starting Line - The B-List (Album Version) @ 2024-07-23T19:38:54+01:00 (S) => Score 0.91 => No Match
[2024-07-23 19:44:28.973 +0100] DEBUG  : [App] [Scrobblers] [Lastfm - cli-hidyn-lastfm] Breakdown:
Artist: 1.00 * 0.3 = 0.30
Title: 0.27 * 0.4 = 0.11
Time: (Exact) 1 * 0.5 = 0.50
Time Detail => Existing: 19:38:54+01:00 - Candidate: 19:38:54+01:00 | Temporal Sameness: Exact | Play Diff: 0s (Needed <10s) | Range Comparison N/A
Score 0.91 => No Match
[2024-07-23 19:44:29.370 +0100] INFO   : [App] [Scrobblers] [Lastfm - cli-hidyn-lastfm] Scrobbled (Backlog) => (listenbrainz) The Starting Line - The B-List @ 2024-07-23T19:38:54+01:00 (S)
[2024-07-23 19:44:29.372 +0100] DEBUG  : [App] [Scrobblers] [Lastfm - cli-hidyn-lastfm] Raw Payload: 
[2024-07-23 19:44:30.517 +0100] DEBUG  : [App] [Sources] [Lastfm - src-visyn-lastfm] Refreshing recently played
[2024-07-23 19:44:30.858 +0100] DEBUG  : [App] [Sources] [Lastfm - src-visyn-lastfm] No new tracks discovered
[2024-07-23 19:44:30.858 +0100] DEBUG  : [App] [Sources] [Lastfm - src-visyn-lastfm] Last activity 2024-07-23T16:58:26+01:00 is 3 hours outside of polling period (last activity + 300s) | Next check interval: (15 + 45)s
[2024-07-23 19:44:38.412 +0100] DEBUG  : [App] [Sources] [Lastfm - src-hidyn-lastfm] Refreshing recently played
[2024-07-23 19:44:38.808 +0100] INFO   : [App] [Sources] [Lastfm - src-hidyn-lastfm] Discovered => The Starting Line - The B-List @ 2024-07-23T19:38:54+01:00 (S)
[2024-07-23 19:44:38.808 +0100] DEBUG  : [App] [Scrobblers] [Maloja - cli-hidyn-maloja] Client was filtered out by Source 'Source - Lastfm - src-hidyn-lastfm'
[2024-07-23 19:44:38.809 +0100] DEBUG  : [App] [Scrobblers] [Lastfm - cli-hidyn-lastfm] Client was filtered out by Source 'Source - Lastfm - src-hidyn-lastfm'
[2024-07-23 19:44:38.809 +0100] DEBUG  : [App] [Scrobblers] [Listenbrainz - cli-visyn-listenbrainz] Client was filtered out by Source 'Source - Lastfm - src-hidyn-lastfm'

@FoxxMD
Copy link
Owner

FoxxMD commented Jul 23, 2024

Great! So forcing a refresh of the client's upstream scrobbles is preventing dup scrobbles, as it should, when the existing scrobble is in the history. Just need to make sure that refresh happens in time for the comparison without the need for force refresh...


We can see the reason the LFM duplicate happened is because MS didn't think the track title's were similar enough:

[2024-07-23 19:44:28.972 +0100] DEBUG  : [App] [Scrobblers] [Lastfm - cli-hidyn-lastfm] Listenbrainz: The Starting Line - The B-List @ 2024-07-23T19:38:54+01:00 (S) => Closest Scrobble: The Starting Line - The B-List (Album Version) @ 2024-07-23T19:38:54+01:00 (S) => Score 0.91 => No Match
[2024-07-23 19:44:28.973 +0100] DEBUG  : [App] [Scrobblers] [Lastfm - cli-hidyn-lastfm] Breakdown:
Artist: 1.00 * 0.3 = 0.30
Title: 0.27 * 0.4 = 0.11
Time: (Exact) 1 * 0.5 = 0.50
Time Detail => Existing: 19:38:54+01:00 - Candidate: 19:38:54+01:00 | Temporal Sameness: Exact | Play Diff: 0s (Needed <10s) | Range Comparison N/A
Score 0.91 => No Match
Candidate           => The Starting Line - The B-List                 @ 2024-07-23T19:38:54+01:00
Closest existing    => The Starting Line - The B-List (Album Version) @ 2024-07-23T19:38:54+01:00
  • Artist similarity 1.00 = 100%
  • Time similarity 1 = 100%
  • Title similarity 0.27 = 27%

With a weighted score of 0.91 it almost considered it a dupe (needs to be >= 1) but the general heuristic for finding dupes isn't wrong here. The title is definitely dissimilar enough that, generally, it shouldn't count this as dups (even though we we know it is).

Ironically, LFM actually also provides metabrainz IDs for historic scrobbles but only for artist and album -- no release id. So it's not possible to programmatically determine it's the same track without using the track title at face value.

The score weights are pretty well balanced from my testing so I'm reluctant to change those. I also don't want to hardcode an exception for (Album Version) as this may very well be a legitimately different track in another scenario.

My first impression for fixing this, then, would be to allow user-configrable terms to be removed from a play so that edge cases like this can be taken care of by the user in listenbrainz.json (or maybe the source config?) I'll need to think on how to best go about this that doesn't introduce too much complexity.

@FoxxMD
Copy link
Owner

FoxxMD commented Jul 24, 2024

@HidYn please update to the latest foxxmd/multi-scrobbler:pr-174 image when you can. The refreshForce option is gone but some new code I added may fix the stale refresh data without it.

If you find it is still doing duplicates that aren't related to the track title being different you can use the new option refreshStaleAfter instead of refreshForce like this:

    "options": {
     "refreshStaleAfter": 3,
     "verbose": {
        "match": {
          "onNoMatch": true,
          "confidenceBreakdown": true
        }
      }
    }

refreshStaleAfter forces the client to refresh scrobbled plays from upstream service if last refresh was at least X seconds ago. Setting it to 0 would effectively be refreshForce: true

@HidYn
Copy link
Author

HidYn commented Jul 24, 2024

I took your advice and just removed the loopback due to the sightly different titles causing an issue. More than happy to put my Last.fm source config back in place if you'd like me to help test though and report back the results?

@FoxxMD
Copy link
Owner

FoxxMD commented Jul 25, 2024

Nah it's all good I've got a test written for it already anyways. Thanks again for the detailed writeup, logging, and testing.

@FoxxMD
Copy link
Owner

FoxxMD commented Jul 25, 2024

@HidYn if you'd like to try this out and go back to your original setup I have a way to modify scrobble data using configs. Switch to foxxmd/multi-scrobbler:develop image.

The docs are here until it's cut for a release and for your particular scenario the config would look like this for lastfm.json:

[
  {
    "name": "myLastFm",
    "configureAs": "client"
    // ...
    "options": {
      "refreshStaleAfter": 3,
      // ...
      "playTransform": {
        "compare": {
          "existing": {
            "title": [
              "(Album Version)" // ignore '(Album Version)' in existing scrobble titles during duplicate comparison
            ]
          },
        },
      }
    }
  }
]

@FoxxMD
Copy link
Owner

FoxxMD commented Aug 20, 2024

Scrobble modification and refresh forcing configuration (refreshStaleAfter) have been released in v0.8.2.

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

No branches or pull requests

2 participants