mirror of
https://github.com/librespot-org/librespot.git
synced 2026-04-27 08:15:50 +03:00
[GH-ISSUE #267] librespot/raspotify crashes frequently #180
Labels
No labels
A-Alsa
SpotifyAPI
Tokio 1.0
audio
bug
can't reproduce
compilation
dependencies
duplicate
enhancement
good first issue
help wanted
high priority
imported
imported
invalid
new api
pull-request
question
reverse engineering
wiki
wontfix
No milestone
No project
No assignees
1 participant
Notifications
Due date
No due date set.
Dependencies
No dependencies set.
Reference
starred/librespot#180
Loading…
Add table
Add a link
Reference in a new issue
No description provided.
Delete branch "%!s()"
Deleting a branch is permanent. Although the deleted branch may continue to exist for a short time before it actually gets removed, it CANNOT be undone in most cases. Continue?
Originally created by @karvec on GitHub (Nov 18, 2018).
Original GitHub issue: https://github.com/librespot-org/librespot/issues/267
Sometimes will play a few songs, sometimes doesn't play any songs. Not sure I can provide any more useful information other than log.
Also, using a cache on an external hard drive. Previous versions did crash occasionally but not as often.
librespotlog.txt
@ashthespy commented on GitHub (Nov 19, 2018):
Can you provide the specific track from your playlist that makes it crash?
Is it a local track by any chance?
Relevant log lines:
@karvec commented on GitHub (Nov 19, 2018):
All of the tracks are local, I have about 14 GB cached and it happens on
various playlists.
On Mon, Nov 19, 2018, 4:37 AM Ash notifications@github.com wrote:
@ashthespy commented on GitHub (Nov 19, 2018):
@karvec I meant if it's non Spotify local track - but if you can provide more steps to replicate, people here can test with the same tracks to see if we can reproduce the issue.
@karvec commented on GitHub (Nov 20, 2018):
It was Spotify locally cached tracks. They are dumped into a directory on an external drive I have that is partitioned to ext4. I have since cleared my cache (was increasing bitrate) and will pursue this further if the issue manages to reproduce itself. So far playing non-local Spotify tracks (before they hit cache) does not seem to be causing issues. I am inclined to believe it was a permissions issue as the files had different owner and rwx permissions from when I was attempting to configure another piece of software.
@karvec commented on GitHub (Nov 23, 2018):
Still random crashes, usually cached tracks.
@kingosticks commented on GitHub (Nov 23, 2018):
Usually? So if you disable the cache you still get this?
@karvec commented on GitHub (Nov 27, 2018):
I don't know, how can I tell if it is a cached track. It fails before showing me track name/cached information, i.e. last log "Infinite" played fine and then it failed moving to next song. I would prefer not disabling cache due to bandwidth constraints.
@kingosticks commented on GitHub (Nov 27, 2018):
Move/delete your existing cache and then run librespot without caching enabled. Then nothing will be cached.
@karvec commented on GitHub (Nov 29, 2018):
Does not seem to crash on uncached tracks. However, have not listened to music as much the last 2 days.
What does this mean for me? I will be unable to cache tracks & consume more bandwidth?
@kingosticks commented on GitHub (Nov 29, 2018):
I'm purely trying to narrow down the problem so that we might fix it.
@ashthespy commented on GitHub (Nov 29, 2018):
@karvec your stack trace seems to indicate the playlist list contains a track that doesn't have a valid
gidfor some reason:github.com/librespot-org/librespot@d2cadec419/connect/src/spirc.rs (L696-L697)If you can add a few debug lines and recompile - it might help track down the issue. Could be as simple as:
@karvec commented on GitHub (Nov 30, 2018):
I am getting "invalid backend" after compiling and running. I am running it on a raspberry pi. Do I need different dependencies or compile instructions? I have tried using both alsa and leaving the line commented out in /etc/default/raspotify
@ashthespy commented on GitHub (Nov 30, 2018):
Haven't used raspotify - but for librespot on the pi - https://github.com/librespot-org/librespot/wiki/Cross-compiling
@sashahilton00 commented on GitHub (Jan 4, 2019):
Assuming this has been resolved or OP moved on. Leaving for a few days, then will close.
@meiseGit commented on GitHub (Feb 23, 2019):
Hi, I'm having the same problem.
This is my journalctl:
Feb 23 10:12:54 raspberrypi librespot[3560]: 29: 0x76d5c677 - __libc_start_main Feb 23 10:12:54 raspberrypi librespot[3560]: 28: 0x4a2e03 - main Feb 23 10:12:54 raspberrypi librespot[3560]: at src/libstd/rt.rs:58 Feb 23 10:12:54 raspberrypi librespot[3560]: at src/libstd/panic.rs:398 Feb 23 10:12:54 raspberrypi librespot[3560]: at src/libstd/panicking.rs:289 Feb 23 10:12:54 raspberrypi librespot[3560]: 27: 0x8f85db - std::rt::lang_start_internal::h7b3bd8c78881c37d Feb 23 10:12:54 raspberrypi librespot[3560]: at src/libpanic_unwind/lib.rs:102 Feb 23 10:12:54 raspberrypi librespot[3560]: 26: 0x906ed3 - __rust_maybe_catch_panic Feb 23 10:12:54 raspberrypi librespot[3560]: at src/libstd/panicking.rs:310 Feb 23 10:12:54 raspberrypi librespot[3560]: at src/libstd/rt.rs:59 Feb 23 10:12:54 raspberrypi librespot[3560]: 25: 0x8f7c37 - std::panicking::try::do_call::hf93a787b72e1d226 Feb 23 10:12:54 raspberrypi librespot[3560]: 24: 0x4a34c7 - std::rt::lang_start::{{closure}}::h917dfa7921b791c5 Feb 23 10:12:54 raspberrypi librespot[3560]: 23: 0x4a217b - librespot::main::hc31f7002e8482814 Feb 23 10:12:54 raspberrypi librespot[3560]: 22: 0x494fe3 - tokio_core::reactor::Core::run::h99194d5dbb8bd9d4 Feb 23 10:12:54 raspberrypi librespot[3560]: 21: 0x487213 - <scoped_tls::ScopedKey<T>>::set::h73d4acd45c44520c Feb 23 10:12:54 raspberrypi librespot[3560]: 20: 0x487c6b - <std::thread::local::LocalKey<T>>::with::hc5f23be319d4df2a Feb 23 10:12:54 raspberrypi librespot[3560]: 19: 0x4876d3 - <std::thread::local::LocalKey<T>>::with::h29c22fa99619602e Feb 23 10:12:54 raspberrypi librespot[3560]: 18: 0x4879eb - <std::thread::local::LocalKey<T>>::with::h609051ccff55f1aa Feb 23 10:12:54 raspberrypi librespot[3560]: 17: 0x48d3ef - <tokio::executor::current_thread::Entered<'a, P>>::block_on::h24fda3b0e84ce8d3 Feb 23 10:12:54 raspberrypi librespot[3560]: 16: 0x4875ab - <std::thread::local::LocalKey<T>>::with::h01c83e94e15802ce Feb 23 10:12:54 raspberrypi librespot[3560]: 15: 0x4a72df - futures::task_impl::std::set::hfe2c0ccaf2bdb22f Feb 23 10:12:54 raspberrypi librespot[3560]: 14: 0x499f8b - <futures::future::lazy::Lazy<F, R> as futures::future::Future>::poll::ha7405d9bf44f5c6b Feb 23 10:12:54 raspberrypi librespot[3560]: 13: 0x4a6fd3 - futures::task_impl::std::set::h6d2c5274ed4002a1 Feb 23 10:12:54 raspberrypi librespot[3560]: 12: 0x4a008f - <librespot::Main as futures::future::Future>::poll::h41a629a680b23a16 Feb 23 10:12:54 raspberrypi librespot[3560]: 11: 0x4d503f - <librespot_connect::spirc::SpircTask as futures::future::Future>::poll::habae05c016ad016f Feb 23 10:12:54 raspberrypi librespot[3560]: 10: 0x4d561b - librespot_connect::spirc::SpircTask::handle_next::h88581de249cd0191 Feb 23 10:12:54 raspberrypi librespot[3560]: 9: 0x4d63b7 - librespot_connect::spirc::SpircTask::load_track::he684bac6d018d8a5 Feb 23 10:12:54 raspberrypi librespot[3560]: 8: 0x4f1cc3 - core::result::unwrap_failed::h35855d27012b6ce1 Feb 23 10:12:54 raspberrypi librespot[3560]: at src/libcore/panicking.rs:95 Feb 23 10:12:54 raspberrypi librespot[3560]: 7: 0x90d03f - core::panicking::panic_fmt::h4d67173bc68f6d5a Feb 23 10:12:54 raspberrypi librespot[3560]: at src/libstd/panicking.rs:325 Feb 23 10:12:54 raspberrypi librespot[3560]: 6: 0x8f7cbf - rust_begin_unwind Feb 23 10:12:54 raspberrypi librespot[3560]: at src/libstd/panicking.rs:398 Feb 23 10:12:54 raspberrypi librespot[3560]: 5: 0x8f7dd3 - std::panicking::continue_panic_fmt::h4c221b9431554bc2 Feb 23 10:12:54 raspberrypi librespot[3560]: at src/libstd/panicking.rs:491 Feb 23 10:12:54 raspberrypi librespot[3560]: 4: 0x8f8253 - std::panicking::rust_panic_with_hook::h28b9ce6fa7a5033b Feb 23 10:12:54 raspberrypi librespot[3560]: at src/libstd/panicking.rs:227 Feb 23 10:12:54 raspberrypi librespot[3560]: 3: 0x8f7727 - std::panicking::default_hook::h54bc90cfc6073aee Feb 23 10:12:54 raspberrypi librespot[3560]: at src/libstd/panicking.rs:211 Feb 23 10:12:54 raspberrypi librespot[3560]: at src/libstd/sys_common/backtrace.rs:59 Feb 23 10:12:54 raspberrypi librespot[3560]: 2: 0x8f7ae3 - std::panicking::default_hook::{{closure}}::h9d3b4aa9777cceab Feb 23 10:12:54 raspberrypi librespot[3560]: at src/libstd/sys_common/backtrace.rs:71 Feb 23 10:12:54 raspberrypi librespot[3560]: 1: 0x8f371b - std::sys_common::backtrace::_print::h0654a4145b8e108e Feb 23 10:12:54 raspberrypi librespot[3560]: at src/libstd/sys/unix/backtrace/tracing/gcc_s.rs:49 Feb 23 10:12:54 raspberrypi librespot[3560]: 0: 0x8f91e7 - std::sys::unix::backtrace::tracing::imp::unwind_backtrace::h508e385542e74f0f Feb 23 10:12:54 raspberrypi librespot[3560]: stack backtrace: Feb 23 10:12:54 raspberrypi librespot[3560]: thread 'main' panicked at 'calledResult::unwrap()on anErrvalue: SpotifyIdError', src/libcore/result.rs:1009:5 Feb 23 10:08:23 raspberrypi librespot[3560]: INFO:librespot_playback::player: Track "BGSTRNG" loaded Feb 23 10:08:22 raspberrypi librespot[3560]: INFO:librespot_playback::player: Loading track "BGSTRNG" with Spotify URI "spotify:track:6FEsAVPmN3VRQmDQQTwD86" Feb 23 10:08:21 raspberrypi librespot[3560]: INFO:librespot_playback::audio_backend::alsa: Using alsa sink Feb 23 10:08:21 raspberrypi librespot[3560]: INFO:librespot_core::session: Country: "DE" Feb 23 10:08:21 raspberrypi librespot[3560]: INFO:librespot_core::session: Authenticated as "XXXXXXX" ! Feb 23 10:08:21 raspberrypi librespot[3560]: INFO:librespot_core::session: Connecting to AP "gew1-accesspoint-b-2ksj.ap.spotify.com:4070" Feb 23 10:05:34 raspberrypi librespot[3560]: INFO:librespot: librespot (raspotify v0.12.0) daeeeaa (2019-02-22). Built on 2019-02-23. Build ID: Jf7YtzTXThe error happens after every song. The first song plays fine, but it is not possible to hear a second song in a row.
This is my command to start librespot (with raspotify)
/usr/bin/librespot --name raspotify (raspberrypi) --backend alsa --bitrate 320 --disable-audio-cache --enable-volume-normalisation --linear-volume --initial-volume=100Has anybody an idea what's wrong?
@FlipEverything commented on GitHub (Mar 5, 2019):
I have the same problem on my Raspberry Pi. After a little bit of time it randomly crashes. I am using Spotify Connect on my pimusicbox. I compiled the latest librespot from this repo.
I am listening to a playlist radio started from the desktop/Android Spotify client.
What should I do?
@aykevl commented on GitHub (Mar 13, 2019):
Same error here. For me this happens in Spotifyd after it is paused for a while (a few days). I had to patch Spotifyd to not hide the error to get a backtrace.
This is the relevant section from the crash log:
I'll try again with the patch from @ashthespy and report back when I get something useful.
@ashthespy commented on GitHub (Mar 13, 2019):
Also been seeing more of this error of late (past hour or so?)
The issue is sometimes the frame contains an empty gid. To figure out if it's track specific try patching it to:
@aykevl commented on GitHub (Mar 13, 2019):
For me it does not seem to be track specific as it only occurs after a long time of inactivity, and happens very often then. I think the real bug is not handling a connection timeout correctly. In fact, I have seen connection related errors before (before I enabled full backtrace printing) so maybe this assert I'm hitting is just a side effect of a connection timeout. Nonetheless, I have added the relevant patch to check for invalid
gids just to be sure. But is there any code I can patch to figure out whether this is indeed the case? I have little experience with Rust but want to help improve the stability of librespot.@kingosticks commented on GitHub (Mar 14, 2019):
There's possibly more than one issue here. @aykevl 's sounds different to the other two if it requires inactivity to trigger.
But all these stack traces are very similar and all coming through
handle_next(). I am a little confused how they are getting there straight frompoll.... Is that due to rust inlining the caller or something? Is that a consequence of being relese builds rather than debug builds? EDIT: Yes, I checked this and that seems to be a difference.Chances are they are being called from
handle_end_of_track()but it'd be nice to know. Either way, I think we'll need more context to debug this. I'd change that extra debug logging to dump the entire state and see exactly why the gid (and maybe the whole track entry) is invalid. It would also be helpful if people could run the debug binary.@aykevl commented on GitHub (Mar 14, 2019):
I am running an unoptimized build so it's not the optimizer that gets in the way.
Here is the full backtrace, if that helps: https://gist.github.com/aykevl/73bf2998b5c28d2e33654155a4d39b3d
Oh and if that's important: I am running spotifyd on a Raspberry Pi 3 with the PulseAudio backend.
I can open a new bug report if needed if it's a different bug after all.
@kingosticks can you perhaps tell me what to insert to debug this further? I'm a Go/Python/C programmer, not a Rust programmer.
Adding
debug!("self: {:?}", self);toload_trackresulted in the compiler suggesting to add#[derive(Debug)]toSpircTrack. But when I do that, many more errors are produced and I'm not sure whether it's possible to properly fix it. Maybe I can print some specific fields?Unfortunately, every debug attempt takes a few days of not listening Spotify over my speakers so it's a rather slow process.
@kingosticks commented on GitHub (Mar 14, 2019):
Hard to tell if it's the same as the other reports. Another difference is they are using ALSA. If you could try to describe in more detail the steps you are doing to reproduce it would help.
@aykevl commented on GitHub (Mar 14, 2019):
I've added it locally, let's see what happens at the next crash.
My "steps to reproduce" would be:
At that point, it either has crashed or it just hangs with no indication that it has crashed. Hitting Ctrl-C shows a vague error. Hitting Ctrl-C again aborts the process. However, last time it crashed directly with a backtrace after I removed the spotifyd panic handler.
@kingosticks commented on GitHub (Mar 14, 2019):
I just hit the crash after leaving a radio station playing (I never normally use those). It shows the issue is the last "track" - which it's trying to switch to - isn't actually a track at all and hence doesn't have a
gid.@ashthespy commented on GitHub (Mar 14, 2019):
I have been encountering this quite frequently albeit not with a build from master, but a tweaked version with support for context stuff.
What I have found is somewhere along the road in the sent frame's state, there is track that isn't a track -
track {uri: "spotify:meta:page:1"}Just skipping this this track (or looping back to 0) works for me.
EDIT: Ah, you beat me to it! ;-)
@sashahilton00 commented on GitHub (Mar 20, 2019):
This should be resolved with the merging of #305, thus closing. If the issue persists, one of the members can reopen this, or create a new issue.