Skip to content
New issue

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

Sign up for GitHub

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

Already on GitHub? Sign in to your account

Jump to bottom

Sometimes does not scrobble/update as "now playing" #26

Open
keeganjk opened this issue Oct 18, 2020 · 7 comments
Open

Sometimes does not scrobble/update as "now playing" #26

keeganjk opened this issue Oct 18, 2020 · 7 comments

Comments

@keeganjk
Copy link

It seems that sometimes mpdscribble will simply not update scrobbles or indicate that a track is being played. I am not sure if this is an issue with the servers themselves or with mpdscribble, but it seems to be related to mpdscribble.
@o0Rh0mbus0o
Copy link

I've encountered issues where mpdscribble fails to update when key metadata is expected, such as a file having no artist. This might be the same problem.

@MaxKellermann
Copy link
Member

such as a file having no artist.

This is just following the protocol specification which disallows submitting songs without an artist. Not a bug.

@triplem
Copy link

triplem commented Jun 4, 2021

When streaming (eg via UPNP) the field "duration" is set slightly later, then the notification, that the song is starting. I do experience this on streaming Tidal to a upmpdcli-Renderer. This is rather annoying.

@triplem
Copy link

triplem commented Jun 4, 2021

All the following songs are played via UPNP on an upmpdcli-Renderer, which streams onto a MPD-Instance. This is not streamed from Tidal but from my local network. By looking on the timestamps, it seems like (just a first quick glance) that the durations of the not scrobbled songs are below the 4m time necessary for scrobbling. Could this be it?

Jun 04 21:42:08 alarm mpdscribble[10580]: 2021-06-04T21:42:08+0200 1622835728, songchange: Depeche Mode - A Question of Lust (263)
Jun 04 21:42:08 alarm mpdscribble[10580]: 2021-06-04T21:42:08+0200 new song detected (Depeche Mode - Sometimes), id: 2137, pos: 3
Jun 04 21:42:09 alarm mpdscribble[10580]: 2021-06-04T21:42:09+0200 [last.fm] submitting 1 song
Jun 04 21:42:09 alarm mpdscribble[10580]: 2021-06-04T21:42:09+0200 [last.fm] post data: s=8L8HVbXtK3ROwgI5YnWYH4wXHvxejbLx&a[0]=Depeche%20Mode&t[0]=A%20Question%20of%20Lust&l[0]=263&i[0]=1622835728&o[0]=R&r[0]=&b[0]=Black%20Celebration%>
Jun 04 21:42:09 alarm mpdscribble[10580]: 2021-06-04T21:42:09+0200 [last.fm] url: http://138.201.169.196/protocol_1.2
Jun 04 21:42:09 alarm mpdscribble[10580]: 2021-06-04T21:42:09+0200 [last.fm] OK
Jun 04 21:42:09 alarm mpdscribble[10580]: 2021-06-04T21:42:09+0200 [last.fm] sending 'now playing' notification
Jun 04 21:42:09 alarm mpdscribble[10580]: 2021-06-04T21:42:09+0200 [last.fm] OK
Jun 04 21:44:02 alarm mpdscribble[10580]: 2021-06-04T21:44:02+0200 new song detected (Depeche Mode - It Doesn't Matter Two), id: 2138, pos: 4
Jun 04 21:44:03 alarm mpdscribble[10580]: 2021-06-04T21:44:03+0200 [last.fm] sending 'now playing' notification
Jun 04 21:44:03 alarm mpdscribble[10580]: 2021-06-04T21:44:03+0200 [last.fm] OK
Jun 04 21:46:53 alarm mpdscribble[10580]: 2021-06-04T21:46:53+0200 new song detected (Depeche Mode - A Question of Time), id: 2139, pos: 5
Jun 04 21:46:54 alarm mpdscribble[10580]: 2021-06-04T21:46:54+0200 [last.fm] sending 'now playing' notification
Jun 04 21:46:54 alarm mpdscribble[10580]: 2021-06-04T21:46:54+0200 [last.fm] OK
Jun 04 21:51:02 alarm mpdscribble[10580]: 2021-06-04T21:51:02+0200 1622836262, songchange: Depeche Mode - A Question of Time (249)
Jun 04 21:51:02 alarm mpdscribble[10580]: 2021-06-04T21:51:02+0200 new song detected (Depeche Mode - Stripped), id: 2140, pos: 6
Jun 04 21:51:03 alarm mpdscribble[10580]: 2021-06-04T21:51:03+0200 [last.fm] submitting 1 song
Jun 04 21:51:03 alarm mpdscribble[10580]: 2021-06-04T21:51:03+0200 [last.fm] post data: s=8L8HVbXtK3ROwgI5YnWYH4wXHvxejbLx&a[0]=Depeche%20Mode&t[0]=A%20Question%20of%20Time&l[0]=249&i[0]=1622836262&o[0]=R&r[0]=&b[0]=Black%20Celebration%>
Jun 04 21:51:03 alarm mpdscribble[10580]: 2021-06-04T21:51:03+0200 [last.fm] url: http://138.201.169.196/protocol_1.2
Jun 04 21:51:03 alarm mpdscribble[10580]: 2021-06-04T21:51:03+0200 [last.fm] OK
Jun 04 21:51:03 alarm mpdscribble[10580]: 2021-06-04T21:51:03+0200 [last.fm] sending 'now playing' notification
Jun 04 21:51:03 alarm mpdscribble[10580]: 2021-06-04T21:51:03+0200 [last.fm] OK
Jun 04 21:55:19 alarm mpdscribble[10580]: 2021-06-04T21:55:19+0200 1622836519, songchange: Depeche Mode - Stripped (256)
Jun 04 21:55:19 alarm mpdscribble[10580]: 2021-06-04T21:55:19+0200 new song detected (Depeche Mode - Here Is the House), id: 2141, pos: 7
Jun 04 21:55:20 alarm mpdscribble[10580]: 2021-06-04T21:55:20+0200 [last.fm] submitting 1 song
Jun 04 21:55:20 alarm mpdscribble[10580]: 2021-06-04T21:55:20+0200 [last.fm] post data: s=8L8HVbXtK3ROwgI5YnWYH4wXHvxejbLx&a[0]=Depeche%20Mode&t[0]=Stripped&l[0]=256&i[0]=1622836519&o[0]=R&r[0]=&b[0]=Black%20Celebration%20%28Deluxe%29&n>
Jun 04 21:55:20 alarm mpdscribble[10580]: 2021-06-04T21:55:20+0200 [last.fm] url: http://138.201.169.196/protocol_1.2
Jun 04 21:55:20 alarm mpdscribble[10580]: 2021-06-04T21:55:20+0200 [last.fm] OK
Jun 04 21:55:20 alarm mpdscribble[10580]: 2021-06-04T21:55:20+0200 [last.fm] sending 'now playing' notification
Jun 04 21:55:20 alarm mpdscribble[10580]: 2021-06-04T21:55:20+0200 [last.fm] OK

And another one:

Jun 03 21:54:46 alarm mpdscribble[5194]: 2021-06-03T21:54:46+0200 1622750086, songchange: Diana Krall - Departure Bay (339)
Jun 03 21:54:47 alarm mpdscribble[5194]: 2021-06-03T21:54:47+0200 [last.fm] submitting 1 song
Jun 03 21:54:47 alarm mpdscribble[5194]: 2021-06-03T21:54:47+0200 [last.fm] post data: s=g50iKd5MDMfTCvCez7knc7vvrSQVvLd0&a[0]=Diana%20Krall&t[0]=Departure%20Bay&l[0]=339&i[0]=1622750086&o[0]=R&r[0]=&b[0]=The%20Girl%20In%20The%20Other%2>
Jun 03 21:54:47 alarm mpdscribble[5194]: 2021-06-03T21:54:47+0200 [last.fm] url: http://138.201.169.196/protocol_1.2
Jun 03 21:54:47 alarm mpdscribble[5194]: 2021-06-03T21:54:47+0200 [last.fm] OK
Jun 03 21:56:04 alarm mpdscribble[5194]: 2021-06-03T21:56:04+0200 new song detected (Amy Winehouse - Rehab), id: 2088, pos: 0
Jun 03 21:56:05 alarm mpdscribble[5194]: 2021-06-03T21:56:05+0200 [last.fm] sending 'now playing' notification
Jun 03 21:56:05 alarm mpdscribble[5194]: 2021-06-03T21:56:05+0200 [last.fm] OK
Jun 03 21:59:38 alarm mpdscribble[5194]: 2021-06-03T21:59:38+0200 new song detected (Amy Winehouse - You Know I'm No Good), id: 2089, pos: 1
Jun 03 21:59:39 alarm mpdscribble[5194]: 2021-06-03T21:59:39+0200 [last.fm] sending 'now playing' notification
Jun 03 21:59:39 alarm mpdscribble[5194]: 2021-06-03T21:59:39+0200 [last.fm] OK
Jun 03 22:03:56 alarm mpdscribble[5194]: 2021-06-03T22:03:56+0200 1622750636, songchange: Amy Winehouse - You Know I'm No Good (257)
Jun 03 22:03:56 alarm mpdscribble[5194]: 2021-06-03T22:03:56+0200 new song detected (Amy Winehouse - Me And Mr Jones), id: 2090, pos: 2
Jun 03 22:03:57 alarm mpdscribble[5194]: 2021-06-03T22:03:57+0200 [last.fm] submitting 1 song
Jun 03 22:03:57 alarm mpdscribble[5194]: 2021-06-03T22:03:57+0200 [last.fm] post data: s=g50iKd5MDMfTCvCez7knc7vvrSQVvLd0&a[0]=Amy%20Winehouse&t[0]=You%20Know%20I%27m%20No%20Good&l[0]=257&i[0]=1622750636&o[0]=R&r[0]=&b[0]=Back%20To%20Bl>
Jun 03 22:03:57 alarm mpdscribble[5194]: 2021-06-03T22:03:57+0200 [last.fm] url: http://138.201.169.196/protocol_1.2

@triplem
Copy link

triplem commented Jun 4, 2021

Just another idea, based on the Issue #23. Could it be, that if the duration of a song is "empty"/"not retrievable" the song is only scrobbled if the song is played for more then a specific time?

@triplem
Copy link

triplem commented Jun 5, 2021

I have modified the log message, which shows the current playing song (Main.cxx - Line 75) to also contain the duration of the current song, this is (with UPnP) always 0. This seems to be the cause for the trouble, except the song is longer then 4m (that is a guess).

Jun 05 00:15:57 alarm mpdscribble[29908]: 2021-06-05T00:15:57+0200 new song detected (Goldfrapp - Anymore (Joe Goddard Remix)), id: 2169, pos: 13, dur: 0
Jun 05 00:15:58 alarm mpdscribble[29908]: 2021-06-05T00:15:58+0200 [last.fm] sending 'now playing' notification
Jun 05 00:15:58 alarm mpdscribble[29908]: 2021-06-05T00:15:58+0200 [last.fm] OK
Jun 05 00:22:11 alarm mpdscribble[29908]: 2021-06-05T00:22:11+0200 1622845331, songchange: Goldfrapp - Anymore (Joe Goddard Remix) (373)
Jun 05 00:22:11 alarm mpdscribble[29908]: 2021-06-05T00:22:11+0200 new song detected (Goldfrapp - Systemagic (Ralphi Rosario Lunar Eclipse Mix)), id: 2170, pos: 14, dur: 0
Jun 05 00:22:12 alarm mpdscribble[29908]: 2021-06-05T00:22:12+0200 [last.fm] submitting 1 song
Jun 05 00:22:12 alarm mpdscribble[29908]: 2021-06-05T00:22:12+0200 [last.fm] post data: s=dt0MJHamZmMUVrVN1rykM7xhny630kXT&a[0]=Goldfrapp&t[0]=Anymore%20%28Joe%20Goddard%20Remix%29&l[0]=373&i[0]=1622845331&o[0]=R&r[0]=&b[0]=Silver%20Eye>
Jun 05 00:22:12 alarm mpdscribble[29908]: 2021-06-05T00:22:12+0200 [last.fm] url: http://138.201.169.196/protocol_1.2
Jun 05 00:22:12 alarm mpdscribble[29908]: 2021-06-05T00:22:12+0200 [last.fm] OK
Jun 05 00:22:12 alarm mpdscribble[29908]: 2021-06-05T00:22:12+0200 [last.fm] sending 'now playing' notification
Jun 05 00:22:12 alarm mpdscribble[29908]: 2021-06-05T00:22:12+0200 [last.fm] OK
Jun 05 00:29:09 alarm mpdscribble[29908]: 2021-06-05T00:29:09+0200 1622845749, songchange: Goldfrapp - Systemagic (Ralphi Rosario Lunar Eclipse Mix) (418)
Jun 05 00:29:09 alarm mpdscribble[29908]: 2021-06-05T00:29:09+0200 new song detected (Goldfrapp - Anymore (Whatever/Whatever Remix by Justin Strauss & Bryan Mette)), id: 2171, pos: 15, dur: 0
Jun 05 00:29:10 alarm mpdscribble[29908]: 2021-06-05T00:29:10+0200 [last.fm] submitting 1 song
Jun 05 00:29:10 alarm mpdscribble[29908]: 2021-06-05T00:29:10+0200 [last.fm] post data: s=dt0MJHamZmMUVrVN1rykM7xhny630kXT&a[0]=Goldfrapp&t[0]=Systemagic%20%28Ralphi%20Rosario%20Lunar%20Eclipse%20Mix%29&l[0]=418&i[0]=1622845749&o[0]=R&r>
Jun 05 00:29:10 alarm mpdscribble[29908]: 2021-06-05T00:29:10+0200 [last.fm] url: http://138.201.169.196/protocol_1.2
Jun 05 00:29:11 alarm mpdscribble[29908]: 2021-06-05T00:29:11+0200 [last.fm] OK
Jun 05 00:29:11 alarm mpdscribble[29908]: 2021-06-05T00:29:11+0200 [last.fm] sending 'now playing' notification
Jun 05 00:29:11 alarm mpdscribble[29908]: 2021-06-05T00:29:11+0200 [last.fm] OK
Jun 05 00:37:04 alarm mpdscribble[29908]: 2021-06-05T00:37:04+0200 1622846224, songchange: Goldfrapp - Anymore (Whatever/Whatever Remix by Justin Strauss & Bryan Mette) (474)
Jun 05 00:37:05 alarm mpdscribble[29908]: 2021-06-05T00:37:05+0200 [last.fm] submitting 1 song
Jun 05 00:37:05 alarm mpdscribble[29908]: 2021-06-05T00:37:05+0200 [last.fm] post data: s=dt0MJHamZmMUVrVN1rykM7xhny630kXT&a[0]=Goldfrapp&t[0]=Anymore%20%28Whatever%2FWhatever%20Remix%20by%20Justin%20Strauss%20%26%20Bryan%20Mette%29&l[0>
Jun 05 00:37:05 alarm mpdscribble[29908]: 2021-06-05T00:37:05+0200 [last.fm] url: http://138.201.169.196/protocol_1.2
Jun 05 00:37:05 alarm mpdscribble[29908]: 2021-06-05T00:37:05+0200 [last.fm] OK
Jun 05 11:28:05 alarm mpdscribble[29908]: 2021-06-05T11:28:05+0200 new song detected (Die Drei ??? - 183 - und der letzte Song (Teil 01)), id: 2174, pos: 0, dur: 0
Jun 05 11:28:06 alarm mpdscribble[29908]: 2021-06-05T11:28:06+0200 [last.fm] sending 'now playing' notification
Jun 05 11:28:06 alarm mpdscribble[29908]: 2021-06-05T11:28:06+0200 [last.fm] OK

An alternative would be to use the mpd_status_get_total_time(status), which returns valid values, even though I was unable to really figure out the difference between the mpd_status_get_total_time and mpd_song_get_duration_ms.
Unfortunately in the GetSongDuration-Function, I do not have access to the status. I modified MpdObserver in line 209, to contain both of those values:

	FormatInfo("total_time(status)/duration(song): %u/%u",
			mpd_status_get_total_time(status) * 1000, 
			mpd_song_get_duration_ms(song));

The result is:

Jun 05 13:16:02 alarm mpdscribble[8285]: 2021-06-05T13:16:02+0200 total_time(status)/duration(song): 1260153240/0
Jun 05 13:16:02 alarm mpdscribble[8285]: 2021-06-05T13:16:02+0200 new song detected (Stratus, Kid Loco (Composer) - Uplink), id: 2227, pos: 4, dur: 0
Jun 05 13:16:02 alarm mpdscribble[8285]: 2021-06-05T13:16:02+0200 another new song detected (Stratus, Kid Loco (Composer) - Uplink), id: 2227, pos: 4, dur: 0
Jun 05 13:16:02 alarm mpdscribble[8285]: 2021-06-05T13:16:02+0200 total_time(status)/duration(song): 1260153240/0
Jun 05 13:16:03 alarm mpdscribble[8285]: 2021-06-05T13:16:03+0200 [last.fm] sending 'now playing' notification
Jun 05 13:16:03 alarm mpdscribble[8285]: 2021-06-05T13:16:03+0200 [last.fm] OK
Jun 05 13:16:30 alarm mpdscribble[8285]: 2021-06-05T13:16:30+0200 total_time(status)/duration(song): 107000/0
Jun 05 13:16:30 alarm mpdscribble[8285]: 2021-06-05T13:16:30+0200 new song detected (Tommy Hools, Kid Loco (Composer) - Barcelone), id: 2228, pos: 5, dur: 0
Jun 05 13:16:30 alarm mpdscribble[8285]: 2021-06-05T13:16:30+0200 another new song detected (Tommy Hools, Kid Loco (Composer) - Barcelone), id: 2228, pos: 5, dur: 0
Jun 05 13:16:30 alarm mpdscribble[8285]: 2021-06-05T13:16:30+0200 total_time(status)/duration(song): 107000/0
Jun 05 13:16:31 alarm mpdscribble[8285]: 2021-06-05T13:16:31+0200 [last.fm] sending 'now playing' notification
Jun 05 13:16:31 alarm mpdscribble[8285]: 2021-06-05T13:16:31+0200 [last.fm] OK
Jun 05 13:18:16 alarm mpdscribble[8285]: 2021-06-05T13:18:16+0200 total_time(status)/duration(song): 118000/0
Jun 05 13:18:16 alarm mpdscribble[8285]: 2021-06-05T13:18:16+0200 new song detected (Zero Theory - Cold Spin), id: 2229, pos: 6, dur: 0
Jun 05 13:18:16 alarm mpdscribble[8285]: 2021-06-05T13:18:16+0200 another new song detected (Zero Theory - Cold Spin), id: 2229, pos: 6, dur: 0
Jun 05 13:18:17 alarm mpdscribble[8285]: 2021-06-05T13:18:17+0200 [last.fm] sending 'now playing' notification
Jun 05 13:18:17 alarm mpdscribble[8285]: 2021-06-05T13:18:17+0200 [last.fm] OK
Jun 05 13:19:23 alarm mpdscribble[8285]: 2021-06-05T13:19:23+0200 total_time(status)/duration(song): 269000/0
Jun 05 13:19:23 alarm mpdscribble[8285]: 2021-06-05T13:19:23+0200 new song detected (Waldeck - Defenceless), id: 2246, pos: 0, dur: 0
Jun 05 13:19:23 alarm mpdscribble[8285]: 2021-06-05T13:19:23+0200 another new song detected (Waldeck - Defenceless), id: 2246, pos: 0, dur: 0
Jun 05 13:19:23 alarm mpdscribble[8285]: 2021-06-05T13:19:23+0200 total_time(status)/duration(song): 269000/0
Jun 05 13:19:23 alarm mpdscribble[8285]: 2021-06-05T13:19:23+0200 total_time(status)/duration(song): 269000/0
Jun 05 13:19:24 alarm mpdscribble[8285]: 2021-06-05T13:19:24+0200 [last.fm] sending 'now playing' notification
Jun 05 13:19:24 alarm mpdscribble[8285]: 2021-06-05T13:19:24+0200 [last.fm] OK
Jun 05 13:23:51 alarm mpdscribble[8285]: 2021-06-05T13:23:51+0200 total_time(status)/duration(song): 319000/0
Jun 05 13:23:51 alarm mpdscribble[8285]: 2021-06-05T13:23:51+0200 1622892231, songchange: Waldeck - Defenceless (268)
Jun 05 13:23:51 alarm mpdscribble[8285]: 2021-06-05T13:23:51+0200 new song detected (Waldeck - Spy Like An Angel), id: 2247, pos: 1, dur: 0
Jun 05 13:23:51 alarm mpdscribble[8285]: 2021-06-05T13:23:51+0200 another new song detected (Waldeck - Spy Like An Angel), id: 2247, pos: 1, dur: 0
Jun 05 13:23:52 alarm mpdscribble[8285]: 2021-06-05T13:23:52+0200 [last.fm] submitting 1 song
Jun 05 13:23:52 alarm mpdscribble[8285]: 2021-06-05T13:23:52+0200 [last.fm] post data: s=PvPvH72PtWe0t71Mr6ryljxKgyNhTpLi&a[0]=Waldeck&t[0]=Defenceless&l[0]=268&i[0]=1622892231&o[0]=R&r[0]=&b[0]=Balance%20Of%20The%20Force&n[0]=1&m[0]=
Jun 05 13:23:52 alarm mpdscribble[8285]: 2021-06-05T13:23:52+0200 [last.fm] url: http://138.201.169.196/protocol_1.2
Jun 05 13:23:52 alarm mpdscribble[8285]: 2021-06-05T13:23:52+0200 [last.fm] OK
Jun 05 13:23:52 alarm mpdscribble[8285]: 2021-06-05T13:23:52+0200 [last.fm] sending 'now playing' notification
Jun 05 13:23:52 alarm mpdscribble[8285]: 2021-06-05T13:23:52+0200 [last.fm] OK
Jun 05 13:29:10 alarm mpdscribble[8285]: 2021-06-05T13:29:10+0200 total_time(status)/duration(song): 250000/0
Jun 05 13:29:10 alarm mpdscribble[8285]: 2021-06-05T13:29:10+0200 1622892550, songchange: Waldeck - Spy Like An Angel (319)
Jun 05 13:29:10 alarm mpdscribble[8285]: 2021-06-05T13:29:10+0200 new song detected (Waldeck - Children Of The Ghetto), id: 2248, pos: 2, dur: 0
Jun 05 13:29:10 alarm mpdscribble[8285]: 2021-06-05T13:29:10+0200 another new song detected (Waldeck - Children Of The Ghetto), id: 2248, pos: 2, dur: 0
Jun 05 13:29:11 alarm mpdscribble[8285]: 2021-06-05T13:29:11+0200 [last.fm] submitting 1 song
Jun 05 13:29:11 alarm mpdscribble[8285]: 2021-06-05T13:29:11+0200 [last.fm] post data: s=PvPvH72PtWe0t71Mr6ryljxKgyNhTpLi&a[0]=Waldeck&t[0]=Spy%20Like%20An%20Angel&l[0]=319&i[0]=1622892550&o[0]=R&r[0]=&b[0]=Balance%20Of%20The%20Force&n[>
Jun 05 13:29:11 alarm mpdscribble[8285]: 2021-06-05T13:29:11+0200 [last.fm] url: http://138.201.169.196/protocol_1.2
Jun 05 13:29:11 alarm mpdscribble[8285]: 2021-06-05T13:29:11+0200 [last.fm] OK
Jun 05 13:29:11 alarm mpdscribble[8285]: 2021-06-05T13:29:11+0200 [last.fm] sending 'now playing' notification

Any help on fixing this is greatly appreciated. Me is not a C++ Expert, but just a music lover :-)

@X-dark
Copy link

X-dark commented Apr 3, 2023

@MaxKellermann this is one of the issue I was referencing in MusicPlayerDaemon/MPD#1774
I am clueless to understand how to alter this behavior if there is no way to set or get the song duration in those cases.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
5 participants
@triplem @X-dark @MaxKellermann @o0Rh0mbus0o @keeganjk