Songs are scrobbled too often a lot

[BratPfanneTV]

I have a jellyfin -> last.fm setup and it works great except that sometimes it scrobbles songs too often. I have an 800 song playlist that I shuffle, so the same song coming on twice back to back is very unlikely, yet I often see this: in my last.fm library, and rarely I even encounter strange situations like this: (this song was, also, only played once) The logs in the web interface seem to be reflecting this:

[FoxxMD]

I have not been able to reproduce your issue (using Jellyfin 10.8.9) but I have added additional logging for jellyfin in the develop branch/image.

To track this down:

• add LOG_LEVEL=debug to your docker run command or node environmental variables
• Update to the develop image, switch to debug level in the UI (or turn on file logging), and watch for this issue again

Then post the logs if it occurs, thanks.

[BratPfanneTV]

I have set the multi-scrobbler up like you described, during that I noticed that when I had two jellyfin clients open, both having tracks selected, one paused, one playing, the multi-scrobbler ends up doing this weird back-and-forth thing while not scrobbling at all:

2023-02-08T19:23:46+01:00 debug : [Source - Jellyfin - default] New play found that does not match existing candidates will be added: (4848db870ba0e4cae5b006f8b763da87) LukHash - INSIDE OF ME 2023-02-08T19:23:45+01:00 debug : [Source - Jellyfin - default] Existing candidate not found in locked plays will be removed: (4848db870ba0e4cae5b006f8b763da87) LukHash - INSIDE OF ME 2023-02-08T19:23:45+01:00 debug : [Source - Jellyfin - default] New play found that does not match existing candidates will be added: (0ac236350d2846fceb8a12132c7db9da) Flay - In The Sky 2023-02-08T19:23:36+01:00 debug : [Source - Jellyfin - default] Existing candidate not found in locked plays will be removed: (0ac236350d2846fceb8a12132c7db9da) Flay - In The Sky 2023-02-08T19:23:36+01:00 debug : [Source - Jellyfin - default] New play found that does not match existing candidates will be added: (4848db870ba0e4cae5b006f8b763da87) LukHash - INSIDE OF ME 2023-02-08T19:23:35+01:00 debug : [Source - Jellyfin - default] Existing candidate not found in locked plays will be removed: (4848db870ba0e4cae5b006f8b763da87) LukHash - INSIDE OF ME 2023-02-08T19:23:35+01:00 debug : [Source - Jellyfin - default] New play found that does not match existing candidates will be added: (0ac236350d2846fceb8a12132c7db9da) Flay - In The Sky 2023-02-08T19:23:26+01:00 debug : [Source - Jellyfin - default] Existing candidate not found in locked plays will be removed: (0ac236350d2846fceb8a12132c7db9da) Flay - In The Sky 2023-02-08T19:23:26+01:00 debug : [Source - Jellyfin - default] New play found that does not match existing candidates will be added: (4848db870ba0e4cae5b006f8b763da87) LukHash - INSIDE OF ME 2023-02-08T19:23:25+01:00 debug : [Source - Jellyfin - default] Existing candidate not found in locked plays will be removed: (4848db870ba0e4cae5b006f8b763da87) LukHash - INSIDE OF ME 2023-02-08T19:23:25+01:00 debug : [Source - Jellyfin - default] New play found that does not match existing candidates will be added: (0ac236350d2846fceb8a12132c7db9da) Flay - In The Sky 2023-02-08T19:23:16+01:00 debug : [Source - Jellyfin - default] Existing candidate not found in locked plays will be removed: (0ac236350d2846fceb8a12132c7db9da) Flay - In The Sky 2023-02-08T19:23:16+01:00 debug : [Source - Jellyfin - default] New play found that does not match existing candidates will be added: (4848db870ba0e4cae5b006f8b763da87) LukHash - INSIDE OF ME 2023-02-08T19:23:15+01:00 debug : [Source - Jellyfin - default] Existing candidate not found in locked plays will be removed: (4848db870ba0e4cae5b006f8b763da87) LukHash - INSIDE OF ME 2023-02-08T19:23:15+01:00 debug : [Source - Jellyfin - default] New play found that does not match existing candidates will be added: (0ac236350d2846fceb8a12132c7db9da) Flay - In The Sky 2023-02-08T19:23:06+01:00 debug : [Source - Jellyfin - default] Existing candidate not found in locked plays will be removed: (0ac236350d2846fceb8a12132c7db9da) Flay - In The Sky

Not sure if that's related but I thought it'd be interesting to point out. This exact situation is one I encounter a lot, since I often leave my home PC on when going to work and vice-versa.

That said, I have not yet been able to reproduce the original issue. I will keep trying and keep you updated.

[FoxxMD]

Thanks for the logs. This is a good hint towards what might be happening.

[BratPfanneTV]

I can't seem to reproduce the issue anymore. Is it conceivable that it's related to memory usage? I saw that before I restarted multiscrobbler to set it up the way you described, it was using 10+ GB of RAM. That would explain why it's not happening anymore and might not until it's been running for a few weeks again like it was before.

[FoxxMD]

Wow!! That is definitely not normal ram usage for MS.

Despite that your logs do hint that MS is not handling multiple "clients" for the same source well. For Jellyfin MS uses the MemorySource implementation where it has to independently keep track of when a track is considered playing and when it allow it to be scrobbled, because Jellyfin doesn't report that kind of information itself. It works decently in a "single user on a single client" scenario but is not handling your scenario well due to assumptions I made when coding it. Im working on refactoring it to handle that better.

So the TLDR is that it may have been a memory leak causing weird issues or it could be these underlying problems I am refactoring for now,

[FoxxMD]

@BratPfanneTV I've implemented a fix so MS now tracks plays across users/platforms/devices separately. This should fix your issue. You can test this out on the foxxmd/mutli-scrobbler:develop image/branch.

[BratPfanneTV]

@FoxxMD Hi! Just as I was about to download and run the new version, I noticed that the issue has finally re-appeared, so I'm concluding that it really must've had to do with the amount of time that the program ran for. This song "Overdose" by "Simbai" has been scrobbled multiple times and the logs for it look like this:

2023-03-01T13:50:55+01:00 info : [Source - Jellyfin - default] New Track => Simbai - Overdose @ 2023-03-01T13:50:08+01:00 2023-03-01T13:50:56+01:00 debug : [Source - Jellyfin - default] (Stateful Play) (ca402b5c42cf5ad5b5fa4310bd08d1b4) Simbai - Overdose added after being seen for 30 seconds and having a different timestamp than a prior play 2023-03-01T13:50:56+01:00 info : [Source - Jellyfin - default] New Track => Simbai - Overdose @ 2023-03-01T13:50:08+01:00 2023-03-01T13:50:56+01:00 debug : [Source - Jellyfin - default] (Stateful Play) (ca402b5c42cf5ad5b5fa4310bd08d1b4) Simbai - Overdose added after being seen for 30 seconds and having a different timestamp than a prior play 2023-03-01T13:50:56+01:00 info : [Source - Jellyfin - default] New Track => Simbai - Overdose @ 2023-03-01T13:50:08+01:00 2023-03-01T13:50:57+01:00 debug : [Source - Jellyfin - default] New play found that does not match existing candidates will be added: (00343435c5625b4a858f76c1da7efb3a) Patricia Taxxon - Kitty 2023-03-01T13:50:57+01:00 debug : [Source - Jellyfin - default] Existing candidate not found in locked plays will be removed: (ca402b5c42cf5ad5b5fa4310bd08d1b4) Simbai - Overdose 2023-03-01T13:50:57+01:00 debug : [Source - Jellyfin - default] New play found that does not match existing candidates will be added: (ca402b5c42cf5ad5b5fa4310bd08d1b4) Simbai - Overdose 2023-03-01T13:50:57+01:00 debug : [Source - Jellyfin - default] Existing candidate not found in locked plays will be removed: (00343435c5625b4a858f76c1da7efb3a) Patricia Taxxon - Kitty 2023-03-01T13:51:27+01:00 debug : [Source - Jellyfin - default] (Stateful Play) (ca402b5c42cf5ad5b5fa4310bd08d1b4) Simbai - Overdose added after being seen for 30 seconds and having a different timestamp than a prior play 2023-03-01T13:51:27+01:00 info : [Source - Jellyfin - default] New Track => Simbai - Overdose @ 2023-03-01T13:50:57+01:00 2023-03-01T13:51:27+01:00 debug : [Client Lastfm - myLastFm ] Refreshing recent scrobbles 2023-03-01T13:51:28+01:00 info : [Client Lastfm - myLastFm ] Scrobbled (New) => (Jellyfin) Simbai - Overdose @ 2023-03-01T13:50:57+01:00 2023-03-01T13:51:28+01:00 debug : [Source - Jellyfin - default] (Stateful Play) (ca402b5c42cf5ad5b5fa4310bd08d1b4) Simbai - Overdose added after being seen for 30 seconds and having a different timestamp than a prior play 2023-03-01T13:51:28+01:00 info : [Source - Jellyfin - default] New Track => Simbai - Overdose @ 2023-03-01T13:50:57+01:00 2023-03-01T13:51:28+01:00 debug : [Source - Jellyfin - default] (Stateful Play) (ca402b5c42cf5ad5b5fa4310bd08d1b4) Simbai - Overdose added after being seen for 30 seconds and having a different timestamp than a prior play 2023-03-01T13:51:28+01:00 info : [Source - Jellyfin - default] New Track => Simbai - Overdose @ 2023-03-01T13:50:57+01:00 1677675057 debug : [Client Lastfm - myLastFm ] Raw Payload: [{"artist":"Simbai","duration":203,"timestamp":1677675057,"track":"Overdose"}] 2023-03-01T13:51:29+01:00 debug : [Source - Jellyfin - default] (Stateful Play) (ca402b5c42cf5ad5b5fa4310bd08d1b4) Simbai - Overdose added after being seen for 30 seconds and having a different timestamp than a prior play 2023-03-01T13:51:29+01:00 info : [Source - Jellyfin - default] New Track => Simbai - Overdose @ 2023-03-01T13:50:57+01:00 2023-03-01T13:51:29+01:00 debug : [Source - Jellyfin - default] (Stateful Play) (ca402b5c42cf5ad5b5fa4310bd08d1b4) Simbai - Overdose added after being seen for 30 seconds and having a different timestamp than a prior play 2023-03-01T13:51:29+01:00 info : [Source - Jellyfin - default] New Track => Simbai - Overdose @ 2023-03-01T13:50:57+01:00

[This section: 2023-03-01T13:51:29+01:00 debug : [Source - Jellyfin - default] (Stateful Play) (ca402b5c42cf5ad5b5fa4310bd08d1b4) Simbai - Overdose added after being seen for 30 seconds and having a different timestamp than a prior play 2023-03-01T13:51:29+01:00 info : [Source - Jellyfin - default] New Track => Simbai - Overdose @ 2023-03-01T13:50:57+01:00 is repeated around 50 times here]

2023-03-01T13:51:56+01:00 debug : [Source - Jellyfin - default] (Stateful Play) (ca402b5c42cf5ad5b5fa4310bd08d1b4) Simbai - Overdose added after being seen for 30 seconds and having a different timestamp than a prior play 2023-03-01T13:51:56+01:00 info : [Source - Jellyfin - default] New Track => Simbai - Overdose @ 2023-03-01T13:50:57+01:00 2023-03-01T13:51:56+01:00 debug : [Source - Jellyfin - default] (Stateful Play) (ca402b5c42cf5ad5b5fa4310bd08d1b4) Simbai - Overdose added after being seen for 30 seconds and having a different timestamp than a prior play 2023-03-01T13:51:56+01:00 info : [Source - Jellyfin - default] New Track => Simbai - Overdose @ 2023-03-01T13:50:57+01:00 2023-03-01T13:51:57+01:00 debug : [Source - Jellyfin - default] New play found that does not match existing candidates will be added: (00343435c5625b4a858f76c1da7efb3a) Patricia Taxxon - Kitty 2023-03-01T13:51:57+01:00 debug : [Source - Jellyfin - default] Existing candidate not found in locked plays will be removed: (ca402b5c42cf5ad5b5fa4310bd08d1b4) Simbai - Overdose 2023-03-01T13:51:57+01:00 debug : [Source - Jellyfin - default] New play found that does not match existing candidates will be added: (ca402b5c42cf5ad5b5fa4310bd08d1b4) Simbai - Overdose 2023-03-01T13:51:57+01:00 debug : [Source - Jellyfin - default] Existing candidate not found in locked plays will be removed: (00343435c5625b4a858f76c1da7efb3a) Patricia Taxxon - Kitty 2023-03-01T13:52:28+01:00 debug : [Source - Jellyfin - default] (Stateful Play) (ca402b5c42cf5ad5b5fa4310bd08d1b4) Simbai - Overdose added after being seen for 30 seconds and having a different timestamp than a prior play 2023-03-01T13:52:28+01:00 info : [Source - Jellyfin - default] New Track => Simbai - Overdose @ 2023-03-01T13:51:57+01:00 2023-03-01T13:52:28+01:00 debug : [Client Lastfm - myLastFm ] Refreshing recent scrobbles 2023-03-01T13:52:28+01:00 info : [Client Lastfm - myLastFm ] Scrobbled (New) => (Jellyfin) Simbai - Overdose @ 2023-03-01T13:51:57+01:00 2023-03-01T13:52:29+01:00 debug : [Source - Jellyfin - default] (Stateful Play) (ca402b5c42cf5ad5b5fa4310bd08d1b4) Simbai - Overdose added after being seen for 30 seconds and having a different timestamp than a prior play 2023-03-01T13:52:29+01:00 info : [Source - Jellyfin - default] New Track => Simbai - Overdose @ 2023-03-01T13:51:57+01:00 2023-03-01T13:52:29+01:00 debug : [Source - Jellyfin - default] (Stateful Play) (ca402b5c42cf5ad5b5fa4310bd08d1b4) Simbai - Overdose added after being seen for 30 seconds and having a different timestamp than a prior play 2023-03-01T13:52:29+01:00 info : [Source - Jellyfin - default] New Track => Simbai - Overdose @ 2023-03-01T13:51:57+01:00 1677675117 debug : [Client Lastfm - myLastFm ] Raw Payload: [{"artist":"Simbai","duration":203,"timestamp":1677675117,"track":"Overdose"}] 2023-03-01T13:52:29+01:00 debug : [Source - Jellyfin - default] (Stateful Play) (ca402b5c42cf5ad5b5fa4310bd08d1b4) Simbai - Overdose added after being seen for 30 seconds and having a different timestamp than a prior play 2023-03-01T13:52:29+01:00 info : [Source - Jellyfin - default] New Track => Simbai - Overdose @ 2023-03-01T13:51:57+01:00 2023-03-01T13:52:30+01:00 debug : [Source - Jellyfin - default] (Stateful Play) (ca402b5c42cf5ad5b5fa4310bd08d1b4) Simbai - Overdose added after being seen for 30 seconds and having a different timestamp than a prior play 2023-03-01T13:52:30+01:00 info : [Source - Jellyfin - default] New Track => Simbai - Overdose @ 2023-03-01T13:51:57+01:00

It's worth noting that as far as I know, I was not connected on multiple clients at the time of this happening, though I could be wrong. I just wanted to mention it so that, in case this new version doesn't fix it, the logs are available to look at.

It's also worth noting that the node process for MS is once again on 10+ GB of RAM usage, according to htop.

[FoxxMD]

@BratPfanneTV how has it been behaving for you this week? I'd encourage you to update again as I've made lots of fixes and improvements this week :)

[juergenbr]

Not sure if this related to the same problem, but I'm also seeing a crazy amount of track discoveries for Deezer. If this is not related please let me know and I can create a separate issue.

[FoxxMD]

@juergenbr that's definitely not right! Unfortunately Deezer is not playing nice with me...my free account is not returning any play history (I can only listen to 30 seconds of a track?) so I'm not sure if this will work or not -- I've added a potential fix to the develop branch/image. Let me know if that fixes things for you.

[juergenbr]

@FoxxMD I updated my container to the latest develop image and the issue is gone. Thanks a lot for the quick fix!

[FoxxMD]

@BratPfanneTV any updates?

[FoxxMD]

In release 0.4.6. I'm closing this until/if Brat returns with an update.