Deployed and configured the container, can't seem to get any output or logs

[neonatus1]

Hello,

I deployed the docker container, added the relevant variables, docker is running, scrobbler.py is running but nothing gets scrobbled and nothing gets logged on the docker log side. Is there a way to somehow enable some debug/logging to see what the script is doing and if there are any issues encountered?

[GioF71]

Hello @neonatus1, I have just tried and in fact it does not work anymore. They must have changed something, it fails when trying to convert the duration of the song. I need to try and see if I can fix it.

But, while typing I see that while it failed when WiiM was playing from a media server, it seems to be working when playing from Tidal (used from the WiiM app itself).

Can you please:

1) post your docker-compose.yml file 2) post the result of the command

docker-compose logs

Thank you

[GioF71]

It looks like an easy fix, sometimes there are milliseconds, sometimes they are not there. Expect a new release maybe tomorrow or friday, hopefully. With this changes I might improve stability and avoid errors when the WiiM is simply not accessible.

[neonatus1]

Perfect, thank you - I am using your docker image from docker hub (did not compose it myself).

[GioF71]

compose

I was not referring to building the image. Just wanted to know how you run it. Are you using the compose file that is suggested in the README of the repository? Github or Docker does not matter, they are synchronized.

[neonatus1]

What I ment, I don'tuse the compose file, I am using the synology container manager and I enter the settings via the GUI. I get docker image from the docker hub, then set up the image parameters and environment variables required (use same parameters you have in the dockerfile example, with the two additional values - as per defaults you mention: { "key" : "DURATION_THRESHOLD", "value" : "240" }, { "key" : "ENABLE_NOW_PLAYING", "value" : "Yes" },

This is the current output I get in the log: TransportState = [PAUSED_PLAYBACK] [CurrentTrackMetaData] => Setting current_song with [Just Pretend] from [THE DEATH OF PEACE OF MIND] by [Bad Omens] Updating [now playing] [yes] for new song [Just Pretend] from [THE DEATH OF PEACE OF MIND] by [Bad Omens] Error handling request Traceback (most recent call last): File "/usr/local/lib/python3.9/site-packages/aiohttp/web_protocol.py", line 452, in _handle_request resp = await request_handler(request) File "/usr/local/lib/python3.9/site-packages/async_upnp_client/aiohttp.py", line 335, in _handle_request status = await self.event_handler.handle_notify(headers, body) File "/usr/local/lib/python3.9/site-packages/async_upnp_client/event_handler.py", line 160, in handle_notify service.notify_changed_state_variables(changes) File "/usr/local/lib/python3.9/site-packages/async_upnp_client/client.py", line 457, in notify_changed_state_variables self.on_event(self, changed_state_variables) File "/code/scrobbler.py", line 275, in on_event dlna_handle_notify_last_change(last_change) File "/usr/local/lib/python3.9/site-packages/async_upnp_client/profiles/dlna.py", line 215, in dlna_handle_notify_last_change service.notify_changed_state_variables(changes_0) File "/usr/local/lib/python3.9/site-packages/async_upnp_client/client.py", line 457, in notify_changed_state_variables self.on_event(self, changed_state_variables) File "/code/scrobbler.py", line 326, in on_event if update_now_playing: last_fm_update_now_playing(current_song) File "/code/scrobbler.py", line 241, in last_fm_update_now_playing network: pylast.LastFMNetwork = create_last_fm_network() File "/code/scrobbler.py", line 232, in create_last_fm_network network: pylast.LastFMNetwork = pylast.LastFMNetwork( File "/usr/local/lib/python3.9/site-packages/pylast/init.py", line 661, in init super().init( File "/usr/local/lib/python3.9/site-packages/pylast/init.py", line 210, in init self.session_key = sk_gen.get_session_key(self.username, self.password_hash) File "/usr/local/lib/python3.9/site-packages/pylast/init.py", line 1062, in get_session_key doc = request.execute() File "/usr/local/lib/python3.9/site-packages/pylast/init.py", line 937, in execute response = self._download_response() File "/usr/local/lib/python3.9/site-packages/pylast/init.py", line 926, in _download_response self._check_response_for_errors(response_text) File "/usr/local/lib/python3.9/site-packages/pylast/init.py", line 955, in _check_response_for_errors raise WSError(self.network, status, details) pylast.WSError: Authentication Failed - You do not have permissions to access the service

[GioF71]

Looks like an authentication error. How did you configure LAST_FM_API_KEY, LAST_FM_SHARED_SECRET, LAST_FM_USERNAME, LAST_FM_PASSWORD_HASH and/or LAST_FM_PASSWORD? The hashed version of the password should be created using an md5 encoder (which you can find online)

[neonatus1]

I used the md5 command on linux to convert the md5 hash of the password. And you are right, I used an online converter, got a different hash - and IT WORKS! I have it scrobbling now, thank you so much!

[GioF71]

Excellent. Anyway there will be a new release fixing some corner cases with track duration. About last.fm, one nice thing to do is to only require the api key and secret, and letting the app get a session token via web browser. This would avoid the issue you experienced. I will do this soon, hopefully. Please star the repo if you like the work.

[neonatus1]

perfect, thank you, and will do.

[neonatus1]

I think you pushed a new update out? I see the logging changed, but I encountered a new error on scrobbling: ransportState = [STOPPED] Scrobbling because: [STOPPED] Song has no duration, cannot scrobble We want to scrobble because the song changed: [CurrentTrackMetaData] Song has no duration, cannot scrobble [CurrentTrackMetaData] => Setting current_song with [a bulleT w- my namE On] from [POST HUMAN: NeX GEn] by [Bring Me the Horizon] No duration available, won't be able to scrobble! Sticking with the same current_song [AVTransportURIMetaData] TransportState = [TRANSITIONING] We want to scrobble because the song changed: [CurrentTrackMetaData] Song has no duration, cannot scrobble Sticking with the same current_song [AVTransportURIMetaData]

This seems to be happening for all songs in this specific album - they are all in flac format 16bit/44.1 kHz

Before this I was listening to mp3s and those all scrobbled better, but also there I got 3 out of about 7 songs scrobbled: example log below:

maybe_scrobble we can scrobble [If These Are Good Times] from [All Boro Kings] by [Dog Eat Dog] We want to scrobble because the song changed: [CurrentTrackMetaData] Requesting a new scrobble for the same song again too early, not scrobbling duration_str_to_sec duration=[187003] ... duration_str_to_sec duration=[187003] -> by_dot:[['187003']] ... duration_str_to_sec duration=[187003] -> left:[187003] millis:[0]... duration_str_to_sec duration=[187003] -> h:[0] m:[0] s:[187003] millis:[0] ... [CurrentTrackMetaData] => Setting current_song with [Think] from [All Boro Kings] by [Dog Eat Dog] Updating [now playing] [yes] for new song [Think] from [All Boro Kings] by [Dog Eat Dog] duration_str_to_sec duration=[187003] ... duration_str_to_sec duration=[187003] -> by_dot:[['187003']] ... duration_str_to_sec duration=[187003] -> left:[187003] millis:[0]... duration_str_to_sec duration=[187003] -> h:[0] m:[0] s:[187003] millis:[0] ... Sticking with the same current_song [AVTransportURIMetaData] TransportState = [TRANSITIONING] We want to scrobble because the song changed: [CurrentTrackMetaData] maybe_scrobble cannot scrobble [Think] from [All Boro Kings] by [Dog Eat Dog], elapsed: [0.5656859874725342] duration: [187003.0] duration_str_to_sec duration=[187003] ... duration_str_to_sec duration=[187003] -> by_dot:[['187003']] ... duration_str_to_sec duration=[187003] -> left:[187003] millis:[0]... duration_str_to_sec duration=[187003] -> h:[0] m:[0] s:[187003] millis:[0] ... Sticking with the same current_song [CurrentTrackMetaData] duration_str_to_sec duration=[187003] ... duration_str_to_sec duration=[187003] -> by_dot:[['187003']] ... duration_str_to_sec duration=[187003] -> left:[187003] millis:[0]... duration_str_to_sec duration=[187003] -> h:[0] m:[0] s:[187003] millis:[0] ... Sticking with the same current_song [AVTransportURIMetaData] TransportState = [PLAYING] TransportState = [STOPPED] Scrobbling because: [STOPPED] maybe_scrobble cannot scrobble [Think] from [All Boro Kings] by [Dog Eat Dog], elapsed: [186.48706674575806] duration: [187003.0] We want to scrobble because the song changed: [CurrentTrackMetaData] maybe_scrobble cannot scrobble [Think] from [All Boro Kings] by [Dog Eat Dog], elapsed: [186.49507236480713] duration: [187003.0] duration_str_to_sec duration=[276133] ... duration_str_to_sec duration=[276133] -> by_dot:[['276133']] ... duration_str_to_sec duration=[276133] -> left:[276133] millis:[0]... duration_str_to_sec duration=[276133] -> h:[0] m:[0] s:[276133] millis:[0] ...

[GioF71]

Hello, the problem is here:

duration_str_to_sec duration=[187003] -> by_dot:[['187003']] ... duration_str_to_sec duration=[187003] -> left:[187003] millis:[0]...

the time is in millis, not in seconds as I though. But I have to understand how to correctly parse this value. Maybe when there are not symbols like "." and/or ":", it's milliseconds?

What is your source? Is that a media server or a streaming service? Thank you, this is helpful anyway. Maybe use this version in the meantime.

[neonatus1]

The data I got is from the plex app from the wiim iphone app. So player is wiim home app with plex (beta) (using my local plex service on lan).

And as for no data in flac files - it seems only some of them report no duration. Not sure how this is done, perhaps we can compare individual files?

Is there any way I can pull individual playing file info with curl or something so I can deduce any difference in those files metadata as it is reported?

[neonatus1]

I have tried the version of the image you suggested too stable-2024-03-26 and it seems to behave the same - flac files don't find any duration.

It actually produces crash when playing certain files (this was Perfect Day by Lou Reed), that plays fine on latest version - but does not scrobble: We want to scrobble because the song changed: [CurrentTrackMetaData] Song has no duration, cannot scrobble Error handling request Traceback (most recent call last): File "/usr/local/lib/python3.9/site-packages/aiohttp/web_protocol.py", line 452, in _handle_request resp = await request_handler(request) File "/usr/local/lib/python3.9/site-packages/async_upnp_client/aiohttp.py", line 335, in _handle_request status = await self.event_handler.handle_notify(headers, body) File "/usr/local/lib/python3.9/site-packages/async_upnp_client/event_handler.py", line 160, in handle_notify service.notify_changed_state_variables(changes) File "/usr/local/lib/python3.9/site-packages/async_upnp_client/client.py", line 457, in notify_changed_state_variables self.on_event(self, changed_state_variables) File "/code/scrobbler.py", line 275, in on_event dlna_handle_notify_last_change(last_change) File "/usr/local/lib/python3.9/site-packages/async_upnp_client/profiles/dlna.py", line 215, in dlna_handle_notify_last_change service.notify_changed_state_variables(changes_0) File "/usr/local/lib/python3.9/site-packages/async_upnp_client/client.py", line 457, in notify_changed_state_variables self.on_event(self, changed_state_variables) File "/code/scrobbler.py", line 309, in on_event if duration_str: current_song.duration = duration_str_to_sec(duration_str) File "/code/scrobbler.py", line 64, in duration_str_to_sec

• float(int(seconds)) ValueError: invalid literal for int() with base 10: ''

This happens with multiple files it seems, but not all...

[GioF71]

Yes some media servers just don't provide a duration. In this case, I should simply scrobble after 4 minutes, and maybe when the track changes if it has been played for a minimum time (maybe 2 minutes?). There are generally two thresholds, the first that happens triggers the scrobbler: you played at least half of the track (hard to understand if you don't have a duration) or you play for at least 4 minutes. The second condition if what I should take into account.

[neonatus1]

Hmm yes, those songs were longer than 4 minutes I would say, bu still no track is scrobbled for now, currently I am playing from bluetooth input, I see song titles are caught, but no song is being scrobbled - this is now again on the latest image.

ong has no duration, cannot scrobble [CurrentTrackMetaData] => Setting current_song with [You Wanna Love Everybody] from [You Got the Luck] by [Sidibe] No duration available, won't be able to scrobble! Sticking with the same current_song [AVTransportURIMetaData] TransportState = [PLAYING] We want to scrobble because the song changed: [CurrentTrackMetaData] Song has no duration, cannot scrobble [CurrentTrackMetaData] => Setting current_song with [Streets of Philadelphia (Single Edit)] from [Greatest Hits] by [Bruce Springsteen] No duration available, won't be able to scrobble! Sticking with the same current_song [AVTransportURIMetaData] TransportState = [PLAYING] We want to scrobble because the song changed: [CurrentTrackMetaData] Song has no duration, cannot scrobble [CurrentTrackMetaData] => Setting current_song with [Breeze] from [Funky Stuff] by [Jiro Inagaki and His Soul Media] No duration available, won't be able to scrobble! Sticking with the same current_song [AVTransportURIMetaData] TransportState = [PLAYING] We want to scrobble because the song changed: [CurrentTrackMetaData] Song has no duration, cannot scrobble [CurrentTrackMetaData] => Setting current_song with [Under the Pressure] from [Lost In the Dream] by [The War on Drugs] No duration available, won't be able to scrobble! Sticking with the same current_song [AVTransportURIMetaData] TransportState = [PLAYING] We want to scrobble because the song changed: [CurrentTrackMetaData] Song has no duration, cannot scrobble Sticking with the same current_song [CurrentTrackMetaData] Sticking with the same current_song [AVTransportURIMetaData] TransportState = [PLAYING]

is the DURATION_TRESHOLD the limit? is this in seconds - and is this the minimum time required? or some other variable? Currently I have that set to 240 so if seconds - yes 4 minutes min, but songs are longer in most cases than 4m.

[GioF71]

The problem is that the app currently does nothing when there is a duration, see the logging:

No duration available, won't be able to scrobble!

I have to intercept and handle this situation. Currently you will probably never see a scrobble in this situation. Let me see if I can do something about this issue and the others with milliseconds.

Ah, which was the source from which you were playing mp3, where the duration was in milliseconds? Plex also?

[neonatus1]

Yes, everything before my last log output was using Plex as source

[GioF71]

Can you try adding:

• DUMP_UPNP_DATA=yes

[neonatus1]

First output - song played via bluetooth:

"@id": "0",
"song:subid": "(null)",
"song:id": "0",
"song:like": "0",
"song:singerid": "0",
"song:albumid": "0",
"res": {
    "@protocolInfo": "http-get:*:audio/mpeg:DLNA.ORG_PN=MP3;DLNA.ORG_OP=01;",
    "@duration": ""
},
"dc:title": "Come Together",
"dc:creator": "The Beatles",
"upnp:artist": "The Beatles",
"upnp:album": "1",
"upnp:albumArtURI": null

} We want to scrobble because the song changed: [CurrentTrackMetaData] Song has no duration, cannot scrobble [CurrentTrackMetaData] => Setting current_song with [Come Together] from [1] by [The Beatles] No duration available, won't be able to scrobble!

Second output - mp3 song via plex that got scrobbled before (and successfully scrobbled now too): [CurrentTrackMetaData] => Setting current_song with [No Fronts] from [All Boro Kings] by [Dog Eat Dog] Updating [now playing] [yes] for new song [No Fronts] from [All Boro Kings] by [Dog Eat Dog] { "@id": "/library/metadata/11785", "song:id": "/library/metadata/11785", "song:albumid": "/library/metadata/11782/children", "song:singerid": "/library/metadata/11781/children", "dc:title": "No Fronts", "upnp:artist": "Dog Eat Dog", "upnp:album": "All Boro Kings", "res": { "@protocolInfo": "http-get::audio/mpeg:DLNA.ORG_PN=MP3;DLNA.ORG_OP=01;", "@duration": "276133" }, "upnp:albumArtURI": "https://192.168.5.3:32400/library/metadata/11782/thumb/1720054447?X-Plex-Token=3sn-x6ayAvrKbeBd8Wzg" } duration_str_to_sec duration=[276133] ... duration_str_to_sec duration=[276133] -> by_dot:[['276133']] ... duration_str_to_sec duration=[276133] -> left:[276133] millis:[0]... duration_str_to_sec duration=[276133] -> h:[0] m:[0] s:[276133] millis:[0] ... Sticking with the same current_song [AVTransportURIMetaData] TransportState = [TRANSITIONING] { "@id": "/library/metadata/11785", "song:id": "/library/metadata/11785", "song:albumid": "/library/metadata/11782/children", "song:singerid": "/library/metadata/11781/children", "dc:title": "No Fronts", "upnp:artist": "Dog Eat Dog", "upnp:album": "All Boro Kings", maybe_scrobble cannot scrobble [No Fronts] from [All Boro Kings] by [Dog Eat Dog], elapsed: [0.8063929080963135] duration: [276133.0] duration_str_to_sec duration=[276133] ... duration_str_to_sec duration=[276133] -> by_dot:[['276133']] ... duration_str_to_sec duration=[276133] -> left:[276133] millis:[0]... duration_str_to_sec duration=[276133] -> h:[0] m:[0] s:[276133] millis:[0] ... Sticking with the same current_song [CurrentTrackMetaData] { "@id": "/library/metadata/11785", "song:id": "/library/metadata/11785", "song:albumid": "/library/metadata/11782/children", "song:singerid": "/library/metadata/11781/children", "dc:title": "No Fronts", "upnp:artist": "Dog Eat Dog", "upnp:album": "All Boro Kings", "res": { "@protocolInfo": "http-get::audio/mpeg:DLNA.ORG_PN=MP3;DLNA.ORG_OP=01;", "@duration": "276133" }, "upnp:albumArtURI": "https://192.168.5.3:32400/library/metadata/11782/thumb/1720054447?X-Plex-Token=3sn-x6ayAvrKbeBd8Wzg", "song:rate_hz": "44100", "song:format_s": "16", "song:bitrate": "192" } duration_str_to_sec duration=[276133] ... duration_str_to_sec duration=[276133] -> by_dot:[['276133']] ... duration_str_to_sec duration=[276133] -> left:[276133] millis:[0]... duration_str_to_sec duration=[276133] -> h:[0] m:[0] s:[276133] millis:[0] ... Sticking with the same current_song [AVTransportURIMetaData] TransportState = [PLAYING]

TransportState = [STOPPED] Scrobbling because: [STOPPED] maybe_scrobble we can scrobble [No Fronts] from [All Boro Kings] by [Dog Eat Dog] { "@id": "/library/metadata/11785", { "@id": "/library/metadata/11785", { "@id": "/library/metadata/11785", "song:id": "/library/metadata/11786", "song:albumid": "/library/metadata/11782/children", "song:singerid": "/library/metadata/11781/children", "dc:title": "Pull My Finger", "upnp:artist": "Dog Eat Dog", "upnp:album": "All Boro Kings", "res": { "@protocolInfo": "http-get:*:audio/mpeg:DLNA.ORG_PN=MP3;DLNA.ORG_OP=01;", "@duration": "214275" }, "upnp:albumArtURI": "https://192.168.5.3:32400/library/metadata/11782/thumb/1720054447?X-Plex-Token=3sn-x6ayAvrKbeBd8Wzg", "song:rate_hz": "44100", "song:format_s": "16", "song:bitrate": "191" } We want to scrobble because the song changed: [CurrentTrackMetaData]

Third option - flac scrobbled through plex - now I can't find one that does not scroble it seems somehow now all scrobble, and I checked image was from yesterday evening my time (which is what I was testing with this morning...), except this song - I see duration of the song is under 4 minutes - did not seem to scrobble - is this due to the DURATION_THRESHOLD value? (240):

Scrobbling because: [STOPPED] maybe_scrobble cannot scrobble [Perfect Day] from [Transformer] by [Lou Reed], elapsed: [0.4097726345062256] duration: [226509.0] TransportState = [TRANSITIONING] { "@id": "/library/metadata/32281", "upnp:artist": "Lou Reed", "upnp:album": "Transformer", "res": { "@protocolInfo": "http-get:*:audio/mpeg:DLNA.ORG_PN=MP3;DLNA.ORG_OP=01;", "@duration": "226509" }, "upnp:albumArtURI": "https://192.168.5.3:32400/library/metadata/31003/thumb/1728810422?X-Plex-Token=3sn-x6ayAvrKbeBd8Wzg", "song:rate_hz": "96000", "song:format_s": "24", "song:bitrate": "2751" duration_str_to_sec duration=[226509] -> h:[0] m:[0] s:[226509] millis:[0] ... Sticking with the same current_song [CurrentTrackMetaData] { "@id": "/library/metadata/32281", "song:id": "/library/metadata/32281", "song:albumid": "/library/metadata/31003/children", "song:singerid": "/library/metadata/31002/children", TransportState = [PLAYING] TransportState = [STOPPED] Scrobbling because: [STOPPED] maybe_scrobble cannot scrobble [Perfect Day] from [Transformer] by [Lou Reed], elapsed: [228.406907081604] duration: [226509.0] {

[GioF71]

Hello, when there is not duration, the app does not scrobble. You can't currently do anything about this issue with the current version. For this, we need a newer version. I understand that when there is no "." and no ":", the duration should be interpreted as milliseconds. Let's hope this is always true. Thank you in the meantime... it has been very helpful.

[GioF71]

New image building... give it a few minutes to finish. Hopefully should scrobble even without a duration. The length is assumed as 4 minutes so we can scrobble at 2 or when track changes or stops. Let's see if there is an improvement.

[neonatus1]

Sorry, I will be out for almost 14 days, and can't really trigger playback remotely, will test as soon as I return.