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

Songs are scrobbled too often a lot #67

Closed
BratPfanneTV opened this issue Feb 8, 2023 · 13 comments
Closed

Songs are scrobbled too often a lot #67

BratPfanneTV opened this issue Feb 8, 2023 · 13 comments
Labels
bug Something isn't working

Comments

@BratPfanneTV
Copy link

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:
image
in my last.fm library, and rarely I even encounter strange situations like this:
image
(this song was, also, only played once)
The logs in the web interface seem to be reflecting this:
image

@FoxxMD
Copy link
Owner

FoxxMD commented Feb 8, 2023

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

BratPfanneTV commented Feb 8, 2023

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

FoxxMD commented Feb 8, 2023

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

@BratPfanneTV
Copy link
Author

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

FoxxMD commented Feb 9, 2023

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 FoxxMD added the bug Something isn't working label Feb 10, 2023
@FoxxMD
Copy link
Owner

FoxxMD commented Feb 28, 2023

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

BratPfanneTV commented Mar 1, 2023

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

FoxxMD commented Mar 10, 2023

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

@FoxxMD FoxxMD closed this as completed in e0ae621 Mar 10, 2023
@FoxxMD FoxxMD reopened this Mar 10, 2023
@juergenbr
Copy link

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.
image

@FoxxMD
Copy link
Owner

FoxxMD commented Apr 3, 2023

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

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

@FoxxMD
Copy link
Owner

FoxxMD commented Apr 20, 2023

@BratPfanneTV any updates?

@FoxxMD
Copy link
Owner

FoxxMD commented Jun 7, 2023

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

@FoxxMD FoxxMD closed this as completed Jun 7, 2023
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

3 participants