raspotify stops being available on the network (presumably after crashing) #571
Comments
|
That's a panic (un-handled error that leads to a hard and nasty crash in Rust speak) in libmdns caused by an index being out of range in a mdns packet. That's upstream of even librespot let alone Raspotify. Nothing can be done about that here or even at librespot. That would need to be fixed in libmdns (if it hasn't already?). mDNS is a strange beast in that A LOT of hardware vendors don't implement it correctly in network devices. My old wifi router (now turn wireless AP, a TPLINK) for example would do similar things. Judging from the weird mDNS errors before the crash you may have the same problem? A shit implementation. In any case this is beyond what can be done here. |
|
This is an upstream issue. You should file an issue with librespot. |
|
The fix in libmdns would be for them to check the length of the packet before they try to access an index that is potentially out of range, and if the index they want is > length to return an error that librespot can handle and exit cleanly so it can restart. The reason that systemd does not restart on a panic is that by default rust programs just hang on a panic thus systemd thinks librespot is still running. I'm pretty sure I can make it so a panic makes librespot abort? At least then systemd can restart the service. |
|
I'm hoping this commit will at least prevent librespot from hanging on a panic and allow systemd to restart the Raspotify service. I pushed an update to the repo, it should be live shortly, give it a try and see if that elevates the need to manually restart the service when you hit a libmdns panic. |
|
I'm getting a ghostly 'Playback Restricted' under traspotify in the device selection list for spotify on my iPad. |
|
Thanks for the quick response @JasonLG1979 . Making systemd restart the service at panic is indeed good enough; my initial plan was to set up a cron job checking some logs and deciding upon that whether to restart or not, but this is way better imo. Will update and let it run for a while. |
That is not a Librespot/Raspotify specific issue: It's also off topic. Don't hijack issues with unrelated bugs. |
No problem. Hopefully it works as intended. To be clear though aborting on panic means we give up tracebacks so you should only see the warning log messages and maybe something from systemd about librespot aborting. |
I didn’t believe I was hijkacking. I honestly thought it may have been a missed diagnostic. My deployment has been running for years, and kept up to date. Failed today at roughly the time this issue was reported. It’s not a big deal for me to report a new issue. Try to be friendly. I’ve looked at the linked issue, and all I can see is noise about branded devices - which I don’t own. I only have raspotify. Which I did a full apt upgrade and a reboot of, before my comment was posted. I may have missed something. |
It's not about being friendly or not. You haven't done your due diligence. You provided no info at all about your issue and you are in fact trying to hijack an issue even if you realize it or not. It's non-productive to comment "It's not working." and provide nothing that can even connect your issue to this one. No one here is a psychic technomancer to my knowledge. We can't see into your computer and read your logs. |
|
@pjgoodall: @blubbafett provided an excellent bug report. They provided all of their package and system info, They clearly stated the issue and the expected desired behavior, and they provided logs. You did none of those things well or at all. |
😍 |
I'm not sure what that means but if you're not going to be productive you're going to catch a ban. |
|
@JasonLG1979 I can confirm that the patch works for restarting raspotify when lbrespot crashes due to the mDNS issue. Seems like it crashed again last night, but up and running again directly after, so all good. Sep 17 19:09:27 raspberrypi librespot[888]: thread 'main' panicked at 'range end index 9 out of range for slice of length 5', library/core/src/slice/index.rs:73:5
Sep 17 19:09:27 raspberrypi librespot[888]: stack backtrace:
Sep 17 19:09:27 raspberrypi librespot[888]: 0: 0x557deeaef4 - <unknown>
Sep 17 19:09:27 raspberrypi librespot[888]: 1: 0x557df0c9e0 - <unknown>
Sep 17 19:09:27 raspberrypi librespot[888]: 2: 0x557dee58d4 - <unknown>
Sep 17 19:09:27 raspberrypi librespot[888]: 3: 0x557deec56c - <unknown>
Sep 17 19:09:27 raspberrypi librespot[888]: 4: 0x557deec2c0 - <unknown>
Sep 17 19:09:27 raspberrypi librespot[888]: 5: 0x557deecab8 - <unknown>
Sep 17 19:09:27 raspberrypi librespot[888]: 6: 0x557deec9a0 - <unknown>
Sep 17 19:09:27 raspberrypi librespot[888]: 7: 0x557deeb39c - <unknown>
Sep 17 19:09:27 raspberrypi librespot[888]: 8: 0x557deec6ec - <unknown>
Sep 17 19:09:27 raspberrypi librespot[888]: 9: 0x557dbb6990 - <unknown>
Sep 17 19:09:27 raspberrypi librespot[888]: 10: 0x557df0e300 - <unknown>
Sep 17 19:09:27 raspberrypi librespot[888]: 11: 0x557df0603c - <unknown>
Sep 17 19:09:27 raspberrypi librespot[888]: 12: 0x557df09d98 - <unknown>
Sep 17 19:09:27 raspberrypi librespot[888]: 13: 0x557dbb6a4c - <unknown>
Sep 17 19:09:27 raspberrypi librespot[888]: 14: 0x557dc7309c - <unknown>
Sep 17 19:09:27 raspberrypi librespot[888]: 15: 0x557dc7ad08 - <unknown>
Sep 17 19:09:27 raspberrypi librespot[888]: 16: 0x557dc74de8 - <unknown>
Sep 17 19:09:27 raspberrypi librespot[888]: 17: 0x557dc6e688 - <unknown>
Sep 17 19:09:27 raspberrypi librespot[888]: 18: 0x557dc700c8 - <unknown>
Sep 17 19:09:27 raspberrypi librespot[888]: 19: 0x557dc7a908 - <unknown>
Sep 17 19:09:27 raspberrypi librespot[888]: 20: 0x557dc778fc - <unknown>
Sep 17 19:09:27 raspberrypi librespot[888]: 21: 0x557dc14db4 - <unknown>
Sep 17 19:09:27 raspberrypi librespot[888]: 22: 0x557dbe6dac - <unknown>
Sep 17 19:09:27 raspberrypi librespot[888]: 23: 0x557dc14998 - <unknown>
Sep 17 19:09:27 raspberrypi librespot[888]: 24: 0x557dbe7c0c - <unknown>
Sep 17 19:09:27 raspberrypi librespot[888]: 25: 0x557dc05034 - <unknown>
Sep 17 19:09:27 raspberrypi librespot[888]: 26: 0x557dc25704 - <unknown>
Sep 17 19:09:27 raspberrypi librespot[888]: 27: 0x557dc18730 - <unknown>
Sep 17 19:09:27 raspberrypi systemd[1]: raspotify.service: Main process exited, code=killed, status=6/ABRT
Sep 17 19:09:27 raspberrypi systemd[1]: raspotify.service: Failed with result 'signal'.
Sep 17 19:09:27 raspberrypi systemd[1]: raspotify.service: Consumed 29min 6.773s CPU time.
Sep 17 19:09:38 raspberrypi systemd[1]: raspotify.service: Scheduled restart job, restart counter is at 1.
Sep 17 19:09:38 raspberrypi systemd[1]: Stopped Raspotify (Spotify Connect Client).
Sep 17 19:09:38 raspberrypi systemd[1]: raspotify.service: Consumed 29min 6.773s CPU time.
Sep 17 19:09:38 raspberrypi systemd[1]: Started Raspotify (Spotify Connect Client).
Sep 17 19:14:09 raspberrypi librespot[1300]: [2022-09-17T17:14:09Z WARN librespot_core::apresolve] Ignoring blacklisted access point ap-gew4.spotify.com:4070
Sep 17 19:14:09 raspberrypi librespot[1300]: [2022-09-17T17:14:09Z WARN librespot_core::apresolve] Ignoring blacklisted access point ap-gew4.spotify.com:443
Sep 17 19:14:09 raspberrypi librespot[1300]: [2022-09-17T17:14:09Z WARN librespot_core::apresolve] Ignoring blacklisted access point ap-gew4.spotify.com:80
Sep 17 19:14:09 raspberrypi librespot[1300]: [2022-09-17T17:14:09Z WARN librespot_core::apresolve] Ignoring blacklisted access point ap-gue1.spotify.com:443
Sep 17 19:14:10 raspberrypi librespot[1300]: [2022-09-17T17:14:10Z ERROR librespot] Connection failed: Authentication failed: bytes remaining on stream
Sep 17 19:14:10 raspberrypi systemd[1]: raspotify.service: Main process exited, code=exited, status=1/FAILURE
Sep 17 19:14:10 raspberrypi systemd[1]: raspotify.service: Failed with result 'exit-code'.
Sep 17 19:14:20 raspberrypi systemd[1]: raspotify.service: Scheduled restart job, restart counter is at 2.
Sep 17 19:14:20 raspberrypi systemd[1]: Stopped Raspotify (Spotify Connect Client).
Sep 17 19:14:20 raspberrypi systemd[1]: Started Raspotify (Spotify Connect Client).
Sep 17 19:14:25 raspberrypi librespot[1311]: [2022-09-17T17:14:25Z WARN librespot_core::apresolve] Ignoring blacklisted access point ap-gew4.spotify.com:4070
Sep 17 19:14:25 raspberrypi librespot[1311]: [2022-09-17T17:14:25Z WARN librespot_core::apresolve] Ignoring blacklisted access point ap-gew4.spotify.com:443
Sep 17 19:14:25 raspberrypi librespot[1311]: [2022-09-17T17:14:25Z WARN librespot_core::apresolve] Ignoring blacklisted access point ap-gew4.spotify.com:80
Sep 17 19:14:25 raspberrypi librespot[1311]: [2022-09-17T17:14:25Z WARN librespot_core::apresolve] Ignoring blacklisted access point ap-gue1.spotify.com:4070
Sep 18 05:38:20 raspberrypi librespot[1311]: [2022-09-18T03:38:20Z WARN libmdns::fsm] couldn't parse packet from <removed from log>.168.30.1:5353: packet has non-zero reserved bits
Sep 18 09:53:43 raspberrypi librespot[1311]: [2022-09-18T07:53:43Z WARN librespot_core::apresolve] Ignoring blacklisted access point ap-gew4.spotify.com:4070
Sep 18 09:53:43 raspberrypi librespot[1311]: [2022-09-18T07:53:43Z WARN librespot_core::apresolve] Ignoring blacklisted access point ap-gew4.spotify.com:443
Sep 18 09:53:43 raspberrypi librespot[1311]: [2022-09-18T07:53:43Z WARN librespot_core::apresolve] Ignoring blacklisted access point ap-gew4.spotify.com:80
Sep 18 09:53:43 raspberrypi librespot[1311]: [2022-09-18T07:53:43Z WARN librespot_core::apresolve] Ignoring blacklisted access point ap-gue1.spotify.com:4070
Sep 18 12:47:00 raspberrypi librespot[1311]: [2022-09-18T10:47:00Z WARN libmdns::fsm] couldn't parse packet from <removed from log>.168.30.1:5353: packet has non-zero reserved bits
Sep 18 13:10:42 raspberrypi librespot[1311]: [2022-09-18T11:10:42Z WARN libmdns::fsm] couldn't parse packet from <removed from log>.168.30.1:5353: packet has non-zero reserved bits
Sep 18 17:41:25 raspberrypi librespot[1311]: [2022-09-18T15:41:25Z WARN libmdns::fsm] couldn't parse packet from <removed from log>.168.30.1:5353: packet is smaller than header sizeSo I guess that this issue can be closed now. Thanks again for resolving it so quickly. Hopefully this maybe won't be an issue at all once I switch over to OpnSense/pfSense at some point. |
|
Well it looks like we do get tracebacks from dependencies so I might not strip the binary after all. Thanks for your help and I'm glad it worked out for you. |
If you use it as a router It'll work better I'd imagine. I ended up getting a cheap little Ubiquity EdgeRouter X specifically because it runs Debian, and I haven't had an issue since. |
|
I released 0.42.6 which basically just adds those sweet, sweet traceback back in (it will still abort). I love me some tracebacks for debugging. |
This is how you respond without being abusive. No accusations of hijacking here: |
Stating facts is not abusive. It seems that you just are incapable of understanding how bug reports work? Your profile says you have many years in software development. You should know better |
|
I would have been nicer too a noob. You are not a noob. |
|
Please enjoy your own company
…On Wed, 28 Sep 2022 at 07:10, Jason Gray ***@***.***> wrote:
I would have been nicer too a noob. You are not a noob.
—
Reply to this email directly, view it on GitHub
<#571 (comment)>,
or unsubscribe
<https://github.com/notifications/unsubscribe-auth/AAFPYWUN24OK3ZIHKXDRFXDWANPFPANCNFSM6AAAAAAQOWI5QA>
.
You are receiving this because you were mentioned.Message ID:
***@***.***>
|
|
That is fine you are not welcome here. |
|
@blubbafett if you have any further issues please file another bug report even if it's a duplicate or closely related to this issue. I'm going to lock this issue for obvious reasons. |
Compatible Device
Are you sure?
Compatible OS
Compatible Configuration
Latest Version
Are you sure?
Due Diligence
What happened?
Experiencing that raspotify stops being available on the network, to both my and my better half's frustration, (who isn't tech-savy and know how to restart the service through ssh'ing into the rpi. :p)
She complained about not finding the device under devices in her Spotify app. When I ssh'ed into the rpi and checked the status for the systemd service this was the output:
Although it said
Active: active (running)it wasn't possible to connect to the device, neither from my own mobile nor my gf's. It reporting "active" is the reason I usedpresumablyin the title,.Doing a restart of the service fixed the issue, however, it'd be nice to not having to face these errors in the future, as it's not always I'm around to do a restart whenver my gf wants to use the device.
I guess it'll be a librespot issue in the end, but it's affecting raspotify, at least on my device..
Running latest raspotify version on a rpi 3b+ (
Raspberry Pi 3 Model B Plus Rev 1.3fromcat /proc/cpuinfo). The device is connected to the network with an ethernet cable, wifi and on-board bluetooth are both disabled, if that should matter for this issue.Not sure what other logs you might need except the output from journalctl, which I've pasted in the relevant log output. If anything more is needed / etc, just yell out and I'll do my best to provide it. NB; I've edited out the ip address of the device from the logs.
Relevant log output
The text was updated successfully, but these errors were encountered: