FoxxMD / multi-scrobbler

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

YouTube Music -> Last.FM scrobbling same songs multiple times #156

Open roos-robert opened 3 weeks ago

roos-robert commented 3 weeks ago

Describe the bug Hi and thank you for your work on this great scrobbler! I'm running into an issue using YouTube Music and scrobbling to Last.FM. It seems to be fetching the played history over and over, scrobbling the same songs to Last.FM, for example:

image

I played this song once, and it keeps being scrobbled over and over (same with other songs).

As an example: image

Songs found here (just turned the listening history on) should be maybe 20% of that amount.

To Reproduce Steps to reproduce the behavior:

  1. Install locally (nodejs)
  2. Setup YouTube Music with local file
  3. Setup Last.FM with local file
  4. Play music from iOS device

Expected behavior To only scrobble a song once, not fetch the play history over and over and scrobble songs multiple times.

Logs A piece of the logs, all of the songs saying they are being scrobbled to Last.FM here was listened to an hour ago.

[2024-06-11 10:29:05.586 +0200] DEBUG  : [App] [Sources] [Ytmusic - MyYTMusic] Last activity was at 2024-06-11T10:27:00+02:00 | Next check interval: 10.00s
[2024-06-11 10:29:05.585 +0200] DEBUG  : [App] [Sources] [Ytmusic - MyYTMusic] No new tracks discovered
[2024-06-11 10:29:05.365 +0200] DEBUG  : [App] [Sources] [Ytmusic - MyYTMusic] Refreshing recently played
[2024-06-11 10:28:55.353 +0200] DEBUG  : [App] [Sources] [Ytmusic - MyYTMusic] Last activity was at 2024-06-11T10:27:00+02:00 | Next check interval: 10.00s
[2024-06-11 10:28:55.352 +0200] DEBUG  : [App] [Sources] [Ytmusic - MyYTMusic] No new tracks discovered
[2024-06-11 10:28:55.162 +0200] DEBUG  : [App] [Sources] [Ytmusic - MyYTMusic] Refreshing recently played
[2024-06-11 10:28:45.151 +0200] DEBUG  : [App] [Sources] [Ytmusic - MyYTMusic] Last activity was at 2024-06-11T10:27:00+02:00 | Next check interval: 10.00s
[2024-06-11 10:28:45.149 +0200] DEBUG  : [App] [Sources] [Ytmusic - MyYTMusic] No new tracks discovered
[2024-06-11 10:28:44.946 +0200] DEBUG  : [App] [Sources] [Ytmusic - MyYTMusic] Refreshing recently played
[2024-06-11 10:28:34.934 +0200] DEBUG  : [App] [Sources] [Ytmusic - MyYTMusic] Last activity was at 2024-06-11T10:27:00+02:00 | Next check interval: 10.00s
[2024-06-11 10:28:34.933 +0200] DEBUG  : [App] [Sources] [Ytmusic - MyYTMusic] No new tracks discovered
[2024-06-11 10:28:34.746 +0200] DEBUG  : [App] [Sources] [Ytmusic - MyYTMusic] Refreshing recently played
[2024-06-11 10:28:24.735 +0200] DEBUG  : [App] [Sources] [Ytmusic - MyYTMusic] Last activity was at 2024-06-11T10:27:00+02:00 | Next check interval: 10.00s
[2024-06-11 10:28:24.734 +0200] DEBUG  : [App] [Sources] [Ytmusic - MyYTMusic] No new tracks discovered
[2024-06-11 10:28:24.519 +0200] DEBUG  : [App] [Sources] [Ytmusic - MyYTMusic] Refreshing recently played
[2024-06-11 10:28:14.504 +0200] DEBUG  : [App] [Sources] [Ytmusic - MyYTMusic] Last activity was at 2024-06-11T10:27:00+02:00 | Next check interval: 10.00s
[2024-06-11 10:28:14.503 +0200] DEBUG  : [App] [Sources] [Ytmusic - MyYTMusic] No new tracks discovered
[2024-06-11 10:28:14.302 +0200] DEBUG  : [App] [Sources] [Ytmusic - MyYTMusic] Refreshing recently played
[2024-06-11 10:28:04.288 +0200] DEBUG  : [App] [Sources] [Ytmusic - MyYTMusic] Last activity was at 2024-06-11T10:27:00+02:00 | Next check interval: 10.00s
[2024-06-11 10:28:04.288 +0200] DEBUG  : [App] [Sources] [Ytmusic - MyYTMusic] No new tracks discovered
[2024-06-11 10:28:04.086 +0200] DEBUG  : [App] [Sources] [Ytmusic - MyYTMusic] Refreshing recently played
[2024-06-11 10:27:54.078 +0200] DEBUG  : [App] [Sources] [Ytmusic - MyYTMusic] Last activity was at 2024-06-11T10:27:00+02:00 | Next check interval: 10.00s
[2024-06-11 10:27:54.077 +0200] DEBUG  : [App] [Sources] [Ytmusic - MyYTMusic] No new tracks discovered
[2024-06-11 10:27:53.879 +0200] DEBUG  : [App] [Sources] [Ytmusic - MyYTMusic] Refreshing recently played
[2024-06-11 10:27:45.267 +0200] DEBUG  : [App] [Scrobblers] [Lastfm - myLastFm] Raw Payload: 
[2024-06-11 10:27:45.266 +0200] INFO   : [App] [Scrobblers] [Lastfm - myLastFm] Scrobbled (New)     => (YTMusic) Artemas - i like the way you kiss me @ 2024-06-11T10:27:00+02:00 (S)
[2024-06-11 10:27:44.115 +0200] DEBUG  : [App] [Scrobblers] [Lastfm - myLastFm] Waiting 776ms to scrobble so time passed since previous scrobble is at least 1000ms
[2024-06-11 10:27:44.091 +0200] DEBUG  : [App] [Scrobblers] [Lastfm - myLastFm] Raw Payload: 
[2024-06-11 10:27:44.090 +0200] INFO   : [App] [Scrobblers] [Lastfm - myLastFm] Scrobbled (New)     => (YTMusic) Dua Lipa - Training Season @ 2024-06-11T10:27:00+02:00 (S)
[2024-06-11 10:27:43.868 +0200] DEBUG  : [App] [Sources] [Ytmusic - MyYTMusic] Last activity was at 2024-06-11T10:27:00+02:00 | Next check interval: 10.00s
[2024-06-11 10:27:43.867 +0200] DEBUG  : [App] [Sources] [Ytmusic - MyYTMusic] No new tracks discovered
[2024-06-11 10:27:43.684 +0200] DEBUG  : [App] [Sources] [Ytmusic - MyYTMusic] Refreshing recently played
[2024-06-11 10:27:42.889 +0200] DEBUG  : [App] [Scrobblers] [Lastfm - myLastFm] Waiting 700ms to scrobble so time passed since previous scrobble is at least 1000ms
[2024-06-11 10:27:42.858 +0200] DEBUG  : [App] [Scrobblers] [Lastfm - myLastFm] Raw Payload: 
[2024-06-11 10:27:42.857 +0200] INFO   : [App] [Scrobblers] [Lastfm - myLastFm] Scrobbled (New)     => (YTMusic) Elley Duhé - MIDDLE OF THE NIGHT @ 2024-06-11T10:27:00+02:00 (S)
[2024-06-11 10:27:41.588 +0200] DEBUG  : [App] [Scrobblers] [Lastfm - myLastFm] Waiting 840ms to scrobble so time passed since previous scrobble is at least 1000ms
[2024-06-11 10:27:41.569 +0200] DEBUG  : [App] [Scrobblers] [Lastfm - myLastFm] Raw Payload: 
[2024-06-11 10:27:41.568 +0200] INFO   : [App] [Scrobblers] [Lastfm - myLastFm] Scrobbled (New)     => (YTMusic) (G)I-DLE - Fate (나는 아픈 건 딱 질색이니까) @ 2024-06-11T10:27:00+02:00 (S)
[2024-06-11 10:27:40.428 +0200] DEBUG  : [App] [Scrobblers] [Lastfm - myLastFm] Waiting 737ms to scrobble so time passed since previous scrobble is at least 1000ms
[2024-06-11 10:27:40.401 +0200] DEBUG  : [App] [Scrobblers] [Lastfm - myLastFm] Raw Payload: 
[2024-06-11 10:27:40.400 +0200] INFO   : [App] [Scrobblers] [Lastfm - myLastFm] Scrobbled (New)     => (YTMusic) CHUNG HA - I’m Ready (I’m Ready) @ 2024-06-11T10:27:00+02:00 (S)
[2024-06-11 10:27:39.164 +0200] DEBUG  : [App] [Scrobblers] [Lastfm - myLastFm] Waiting 579ms to scrobble so time passed since previous scrobble is at least 1000ms
[2024-06-11 10:27:39.134 +0200] DEBUG  : [App] [Scrobblers] [Lastfm - myLastFm] Raw Payload: 
[2024-06-11 10:27:39.133 +0200] INFO   : [App] [Scrobblers] [Lastfm - myLastFm] Scrobbled (New)     => (YTMusic) KISS OF LIFE - Midas Touch (Midas Touch) @ 2024-06-11T10:27:00+02:00 (S)
[2024-06-11 10:27:37.743 +0200] DEBUG  : [App] [Scrobblers] [Lastfm - myLastFm] Waiting 839ms to scrobble so time passed since previous scrobble is at least 1000ms
[2024-06-11 10:27:37.724 +0200] DEBUG  : [App] [Scrobblers] [Lastfm - myLastFm] Raw Payload: 
[2024-06-11 10:27:37.724 +0200] INFO   : [App] [Scrobblers] [Lastfm - myLastFm] Scrobbled (New)     => (YTMusic) Aden Foyer - The Ballet Girl @ 2024-06-11T10:27:00+02:00 (S)
[2024-06-11 10:27:36.581 +0200] DEBUG  : [App] [Scrobblers] [Lastfm - myLastFm] Waiting 840ms to scrobble so time passed since previous scrobble is at least 1000ms
[2024-06-11 10:27:36.567 +0200] DEBUG  : [App] [Scrobblers] [Lastfm - myLastFm] Raw Payload: 
[2024-06-11 10:27:36.566 +0200] INFO   : [App] [Scrobblers] [Lastfm - myLastFm] Scrobbled (New)     => (YTMusic) Ed Sheeran - Shivers @ 2024-06-11T10:27:00+02:00 (S)

Versions (please complete the following information): Provide version information for any related sources/clients.

Additional context Running latest release (cloned master of this repo)

SomeAspy commented 3 weeks ago

I had this issue too, but it was difficult for me to reliably replicate, seemingly happening at random, so without any reliable data I didn't bother opening an issue. I've just been watching the entire repo.

roos-robert commented 3 weeks ago

I had this issue too, but it was difficult for me to reliably replicate, seemingly happening at random, so without any reliable data I didn't bother opening an issue. I've just been watching the entire repo.

Haha you know what? You're the reason I found this repo! Googled for a YouTube Music scrobbler and found your blog. 😁

Hopefully the dev have some insight to what might be going on.

So I'm guessing then (reading your blog) that the dev branch didn't solve this issue either?

SomeAspy commented 3 weeks ago

At the time of writing the dev branch didn't make a difference. I think the only difference here is I used the docker images (I tried stable, develop, and develop-debian) but yeah, I had the exact same issue. Since I've been watching the commit history, I haven't noticed anything that might be related to this.

FoxxMD commented 2 weeks ago

Thanks for the writeup.

There haven't been any changes to the YT Music code in MS because I don't personally use YT Music so if something breaks I depend on any users who use it to report an issue.

I can't currently reproduce your issue but I'm fairly confident it's due to how YTM "organizes" your listens in its recent history -- it does not surface any actual "listened at" datetime info. Instead:

EX:

You can see more in the PR I made to try to compensate for this in the underying YTM library MS uses.

MS tries to be clever about how it determines if YTM has returned a new track. When it first starts up (polling) it stores all tracks returned from YTM history in a flat list. Then it polls that history API regularly and if it finds a track at the beginning of the list (assumed most recent) that does not match the last-seen first track it determines that is a new track and scrobbles it.

Likely what is happening with the duplicate scrobbles is that YTM is either not returning tracks in reverse chronological order or it is not returning the playlists in reverse chronological order. Or maybe something else entirely...its pretty opaque.

MS also can't do duplicate checking, which it does for all other music sources, because there are no datetimes so it just has to assume the list is in the correct order. :shrug:


Having said all that, I've added some code to help surface information about those playlists to a feature branch in MS. Please use the ytMusicDebug branch if running locally or foxxmd/multi-scrobbler:ytdebug docker image.

You'll find on the dashboard the YTM card has a new link, See Recent from Source API. Navigating to this link will open a page that lists the tracks returned from YTM without modification. This is the exact order YTM returns them to MS. You'll also see the "playlist bucket" YTM puts these tracks in at the end of each track.

image

If everything is working normally this list should be essentially the same order as Tracks Discovered page for your YTM source.

If you see duplicate scrobbles occurring please:

This will help me isolate if its a list order issue or if I need to dig further into this. thanks

roos-robert commented 2 weeks ago

@FoxxMD thank you for the explanation and insights into why scrobbling from YouTube Music is such a pain, to be honest if it wasn't for multi-scrobbler I would stick with Spotify. Your work is much appreciated!

To give a brief update since it's been almost a day since your reply, these are the steps I've taken to test this out:

So far everything has been scrobbling perfectly correct! The only change from when I ran the release version of 0.7.1 is:

I'll leave this issue open and get back to you once I've tested things out some more, hopefully @SomeAspy have time to try it out as well.

Thanks again for all your work!

FoxxMD commented 2 weeks ago

Off topic but I read your blog post @SomeAspy (thanks for the kind words!) and wanted to let you know you do not need CF Access.

The next problem I ran into is the fact that (in my case) this is a publicly accessible URL. I couldn't just close it, because Last.FM needs to callback URL to authenticate with Multi Scrobbler.

Last.fm uses a slightly modified authorization code flow but the relevant part is that its redirect behavior is the same as the normal oauth2.0 spec -- the redirect URI is is where the authorization service redirects the users browser after its side of the authorization flow is complete. This means the URI used only needs to be accessible from the users browser, not that is needs to be publicly accessible:

LFM's servers never initiate a connection with your MS instance so your instance does not need to be public in order to complete the auth flow. This is usually true for any oauth2.0 compliant authorization flow and auth code flows in general.

SomeAspy commented 2 weeks ago

I love to see people reading it! I was surprised to see the author found this from my silly blog. I have updated the post to add what you just said. I will be giving your YTM branch a try soon, right now I don't listen to a lot of music from mobile.

I also can't help but comment on your swiftness of responding to any and all issues on this repository, so kudos!

FoxxMD commented 1 week ago

@roos-robert @SomeAspy have either of ya'll had a chance to test this? Any results?

SomeAspy commented 1 week ago

I'm actually gonna begin tomorrow, the circumstances where I scrobble a lot from mobile have started today.

SomeAspy commented 1 week ago

Something I've almost immediately noticed within the first few hours of using is my YouTube music cookie seems to get invalidated more than it previously was. I originally set this up last night, and pulled a cookie using the post request before going to sleep. Later, today in the afternoon, the cookie has been invalidated. I chock it up to whatever, and pull it again. I listen to music for about an hour, and things work fine. I take a nap for 2 hours and come back to find my cookie invalidated again. @roos-robert have you been having similar issues? image

FoxxMD commented 1 week ago

@SomeAspy can you try enabling the option mentioned here? This should be included in the latest commits on the ytdebug docker image.

SomeAspy commented 1 week ago

Ah yes I missed that. I haven't actually tested this exactly yet but it seems to drop on restart. I can test it when I get home.

SomeAspy commented 1 week ago

Another smaller detail I've noticed: if you play a song several times over only one play will be detected. I assume this is because of the way you make sure not to scrobble multiple times and am not sure if this is avoidable.

FoxxMD commented 1 week ago

As long as there is a different track played between the two it should be detecting them just fine (assuming MS was running and monitoring the entire time). I'll try to use YTM today and see if I can get api dumps to use for testing.

SomeAspy commented 1 week ago

There was no track between, and I just noticed that the YouTube history itself only shows once. I've been using https://github.com/th-ch/youtube-music (the difference being it's a client and can actively watch what you are doing to scrobble so) on desktop and it will scrobble plays if you play it over several times. I guess not much can be done about this if YouTube music itself doesn't list it as played multiple times. image

In this case it was house of cards for about 7 replays.

FoxxMD commented 1 week ago

Yeah, unfortunately MS can't do any thing about that since YTM doesn't report any kind of player status or listening statistics. All it reports is the history, in order (hopefully), without any timestamps. It's the least data-rich platform MS supports.

SomeAspy commented 1 week ago

Yet again I feel like I shot myself in the foot using YouTube Music. Since this is the best we can get regarding mobile scrobbling on iOS, I've been trying to think of the best way to keep using my desktop scrobbler without interfering with multi-scrobbler, which will be running in the background.

In short, I want to use MS for mobile, and the desktop client for desktop. I have a feeling these will naturally interfere with each other. I haven't really tried it yet though.

In better news, scrobbling via mobile seems to be going great, to the best it can given the limitations of YTM. I will list the problems I have with it just for record, but I cannot think of a way to actually fix these.

Cross examining YTM history with last.fm scrobbles seems to be more reliable (???) but there are still some oddities and duplications.

image

Duplicates are often scrobbled in bunches, for what it is worth, with exact same times (which would not be possible since each song is at least 3 minutes) image

Strangely, these duplications and order errors don't seem to appear in the MS debug image

FoxxMD commented 1 week ago

Thank you for the detailed writeup and track matching, this is very helpful!

Skipped songs seem to still scrobble (YTM shows in history, so not much to be done)

Yes, unfortunately YTM records a song to the history playlist if it even loads in the player. It has no threshold for "this has been played for X seconds" before adding it.

Duplicates are often scrobbled...with the exact same times (which would not be possible since each song is at least 3 minutes)

This is a limitation of how MS tries to detect plays in "real-time" in the way I described in the earlier comment. It should be polling fast enough that when the history updates there is only one new track -- IE polling every 60 seconds, tracks are played for longer than 60 seconds so only one shows up between each poll -- BUT the code does not enforce this assumption: if multiple tracks show up between two polls it'll scrobble all the newly seen tracks with the same timestamp. It's erring on the side of caution in the event polling temporarily fails or YTM doesn't update history for an extended period.

Strangely, these duplications and order errors don't seem to appear in the MS debug

This is good to see, I think. It at least tells us that the data scraped by yt-music-api library is the same as what you actually see in YTM, at least in a spontaneous context.


During this window do you know if MS restarted polling or had any errors? Even temporary ones like it failed to contact api but restarted successfully before polling was stopped -- or had a reauthentication event for YTM? Any logs at all might be insightful.

Based on what you've presented so far though it seems like either

I'll see about improving the history checking code and storing previous state so i can detect if/when this consistency occurs so it can drop the "stale" list or try to recover somehow.

SomeAspy commented 1 week ago

I should have included logs, you are right. It looks like the web UI logs have rolled over, so I have attached the log file. Skimming over it, I don't see anything erroneous. scrobble-2024-06-25.1.log image

FoxxMD commented 1 week ago

@SomeAspy @roos-robert I've pushed changes to the ytdebug image and associated branch that overhauls how MS checks YTM history. It now validates the sort order against the previous list and only scrobbles new plays if they are only new (aka prepended to returned history) and there are no other changes to the list. In the event of a non-prepend scenario it'll now log to WARN with a list of changes and replace the in-memory list its validating against.

Please try these changes and let me know if you get any logs about non-prepend events.

SomeAspy commented 6 days ago

I should link this in here as well. https://github.com/FoxxMD/multi-scrobbler/issues/158#issuecomment-2192448181 Perhaps it might make more sense to merge these issues into one issue, as the difference between the 2 problems is starting to blur.

FoxxMD commented 6 days ago

Both issues are related to YTM but I don't think they are casual in nature, at least not yet. I'd prefer to keep them separate for now.

RE your comment in 158:

That's pretty eye-popping! There may be an issue with MS still but there are definitely inconsistencies in there that can't be accounted for by the way MS handles the history. I've added a few more changes. Please try testing with foxxmd/multi-scrobbler:pr-163.

SomeAspy commented 6 days ago

Alright, I just started it up (with the debug env variable) and your new PR. I guess I'll let you know how it goes sometime soon (most likely tomorrow)