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.

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

Random crash in result.rs #172

Closed
l3d00m opened this issue Feb 27, 2018 · 29 comments
Closed

Random crash in result.rs #172

l3d00m opened this issue Feb 27, 2018 · 29 comments
Labels

Comments

@l3d00m
Copy link

l3d00m commented Feb 27, 2018

The following crash happened randomly in the middle of playback. (If it helps, the raspotify service did not restart which usually happens after a crash, this is not the issue here though). There is no additionally information available.

Feb 27 16:29:30 raspberrypi librespot[19886]: INFO:librespot: librespot (raspotify) 685fb4e (2018-02-22). Built on 2018-02-23. Build ID: zwr5e2l3
Feb 27 16:29:46 raspberrypi librespot[19886]: INFO:librespot_core::session: Connecting to AP "gew1-accesspoint-b-jkm8.ap.spotify.com:4070"
Feb 27 16:29:46 raspberrypi librespot[19886]: INFO:librespot_core::session: Authenticated as "(USERID HERE)" !
Feb 27 16:29:46 raspberrypi librespot[19886]: INFO:librespot_playback::audio_backend::alsa: Using alsa sink
Feb 27 16:29:46 raspberrypi librespot[19886]: INFO:librespot_core::session: Country: "DE"

.... (shortened)

Feb 27 17:29:06 raspberrypi librespot[19886]: INFO:librespot_playback::player: Track "Qa bone" loaded
Feb 27 17:32:16 raspberrypi librespot[19886]: WARN:librespot_core::mercury: error 503 for uri hm://remote/3/user/(USERID HERE)/
Feb 27 17:32:16 raspberrypi librespot[19886]: thread 'main' panicked at 'called `Result::unwrap()` on an `Err` value: MercuryError', /checkout/src/libcore/result.rs:916:5
Feb 27 17:32:16 raspberrypi librespot[19886]: stack backtrace:
Feb 27 17:32:16 raspberrypi librespot[19886]:    0:   0x916e3b - <unknown>
Feb 27 17:32:16 raspberrypi librespot[19886]:    1:   0x920f93 - <unknown>
Feb 27 17:32:16 raspberrypi librespot[19886]:    2:   0x90f4f3 - <unknown>
Feb 27 17:32:16 raspberrypi librespot[19886]:    3:   0x90efcf - <unknown>
Feb 27 17:32:16 raspberrypi librespot[19886]:    4:   0x90f99f - <unknown>
Feb 27 17:32:16 raspberrypi librespot[19886]:    5:   0x90f7e7 - <unknown>
Feb 27 17:32:16 raspberrypi librespot[19886]:    6:   0x90f76f - <unknown>
Feb 27 17:32:16 raspberrypi librespot[19886]:    7:   0x90f717 - <unknown>
Feb 27 17:32:16 raspberrypi librespot[19886]:    8:   0x97817b - <unknown>
Feb 27 17:32:16 raspberrypi librespot[19886]:    9:   0x5821df - <unknown>
Feb 27 17:32:16 raspberrypi librespot[19886]:   10:   0x565a33 - <unknown>
Feb 27 17:32:16 raspberrypi librespot[19886]:   11:   0x50daff - <unknown>
Feb 27 17:32:16 raspberrypi librespot[19886]:   12:   0x4ff3e3 - <unknown>
Feb 27 17:32:16 raspberrypi librespot[19886]:   13:   0x4f875f - <unknown>
Feb 27 17:32:16 raspberrypi librespot[19886]:   14:   0x50f403 - <unknown>
Feb 27 17:32:16 raspberrypi librespot[19886]:   15:   0x4f89ab - <unknown>
Feb 27 17:32:16 raspberrypi librespot[19886]:   16:   0x90f647 - <unknown>
Feb 27 17:32:16 raspberrypi librespot[19886]:   17:   0x936317 - <unknown>
Feb 27 17:32:16 raspberrypi librespot[19886]:   18:   0x916ac7 - <unknown>
Feb 27 17:32:16 raspberrypi librespot[19886]:   19:   0x50fe5f - main
Feb 27 17:32:16 raspberrypi librespot[19886]:   20: 0x76d4c677 - __libc_start_main
@sashahilton00
Copy link
Member

Hmm, that binary is stripped, so the backtrace isn't of much use. Do you use a beta client by any chance?

@l3d00m
Copy link
Author

l3d00m commented Feb 27, 2018

I wondered why it looks like that. I'm using the raspotify deb packages provided by dtcooper. Is there any way I can provide you a mapping?

@sashahilton00
Copy link
Member

There is, but it requires that you build the package yourself. If you clone the raspotify repo, but before building, delete this line https://github.com/dtcooper/raspotify/blob/f354732ecc5196fbaf4d7af2662647aa83df76e1/build.sh#L49 and then follow the normal instructions and install the compiled result, it'll give a proper backtrace.

@l3d00m
Copy link
Author

l3d00m commented Feb 27, 2018

Yeah I'm building it rn to provide you a better stacktrace in the future. This crash happened pretty randomly though. There are a couple more crashes that occur for me from time to time, the stacktrace tip allows me to report them with a better stacktrace, thanks.

Also big thanks to you guys for maintaining the repo, I'm using librespot on a daily basis for half a year now.

You may close this issue and I'll reopen as soon as it reoccurs (with a better stack)

@sashahilton00
Copy link
Member

sashahilton00 commented Feb 27, 2018

No problem, thanks for making the effort to report them :) If you have trouble reproducing that MercuryError bug, it could well be that it was being caused by a new value Spotify added to the proto definitions, with a fix pushed a couple of days ago #167. I assume the crash occurs when connecting from a mobile device to librespot?

@l3d00m
Copy link
Author

l3d00m commented Feb 27, 2018

Ah that may be possible, building it provides me with the new version anyway 👍

@sashahilton00
Copy link
Member

Did you manage to recreate this bug? I'm fairly sure the enum fix was all you needed, if so, please close the issue :)

@plietar
Copy link
Contributor

plietar commented Feb 28, 2018

WARN:librespot_core::mercury: error 503 for uri hm://remote/3/user/(USERID HERE)/

Assuming Spotify use HTTP error codes for mercury (I'm pretty sure they do), 503 is "Service Unavailable", so I'd say this is just a one off server side error.

@l3d00m
Copy link
Author

l3d00m commented Feb 28, 2018

I'll just reopen if it should ever occur again, now with a better stack trace 👍

@l3d00m l3d00m closed this as completed Feb 28, 2018
@l3d00m
Copy link
Author

l3d00m commented Mar 6, 2018

It just rehappened, this time with a newer build (and with a proper stacktrace). It happened a few minutes after librespot had another crash and I reconnected to it (I'll open an issue for that later see #183).

Mar 06 17:14:20 raspberrypi librespot[1438]: INFO:librespot: librespot (raspotify) 593dfa0 (2018-02-27). Built on 2018-03-01. Build ID: tKkd5pOH
Mar 06 17:14:31 raspberrypi librespot[1438]: INFO:librespot_core::session: Connecting to AP "gew1-accesspoint-b-4ppp.ap.spotify.com:4070"
Mar 06 17:14:31 raspberrypi librespot[1438]: INFO:librespot_core::session: Authenticated as "[username here]" !
Mar 06 17:14:31 raspberrypi librespot[1438]: INFO:librespot_playback::audio_backend::alsa: Using alsa sink
Mar 06 17:14:31 raspberrypi librespot[1438]: INFO:librespot_core::session: Country: "DE"
Mar 06 17:14:32 raspberrypi librespot[1438]: INFO:librespot_playback::player: Loading track "Outta Here"
Mar 06 17:14:34 raspberrypi librespot[1438]: INFO:librespot_playback::player: Track "Outta Here" loaded
Mar 06 17:46:37 raspberrypi librespot[1438]: WARN:librespot_core::mercury: error 503 for uri hm://remote/3/user/[username here]/
Mar 06 17:46:38 raspberrypi librespot[1438]: thread 'main' panicked at 'called `Result::unwrap()` on an `Err` value: MercuryError', /checkout/src/libcore/result.rs:916:5
Mar 06 17:46:38 raspberrypi librespot[1438]: stack backtrace:
Mar 06 17:46:38 raspberrypi librespot[1438]:    0:   0x8d1057 - std::sys::unix::backtrace::tracing::imp::unwind_backtrace::hb6166e15fda1e065
Mar 06 17:46:38 raspberrypi librespot[1438]:                        at /checkout/src/libstd/sys/unix/backtrace/tracing/gcc_s.rs:49
Mar 06 17:46:38 raspberrypi librespot[1438]:    1:   0x8db2bb - std::sys_common::backtrace::print::hbb547a48d4d45c54
Mar 06 17:46:38 raspberrypi librespot[1438]:                        at /checkout/src/libstd/sys_common/backtrace.rs:68
Mar 06 17:46:38 raspberrypi librespot[1438]:                        at /checkout/src/libstd/sys_common/backtrace.rs:57
Mar 06 17:46:38 raspberrypi librespot[1438]:    2:   0x8c98d7 - std::panicking::default_hook::{{closure}}::hb3351df37d61d489
Mar 06 17:46:38 raspberrypi librespot[1438]:                        at /checkout/src/libstd/panicking.rs:381
Mar 06 17:46:38 raspberrypi librespot[1438]:    3:   0x8c93b3 - std::panicking::default_hook::ha118e44019160a5b
Mar 06 17:46:38 raspberrypi librespot[1438]:                        at /checkout/src/libstd/panicking.rs:397
Mar 06 17:46:38 raspberrypi librespot[1438]:    4:   0x8c9d83 - std::panicking::rust_panic_with_hook::h9cedc3dcc869a838
Mar 06 17:46:38 raspberrypi systemd[1]: raspotify.service: Main process exited, code=exited, status=101/n/a

@ComlOnline
Copy link
Contributor

As @plietar Said above you got WARN:librespot_core::mercury: error 503 for uri hm://remote/3/user/[username here]/ again here. I'm not sure there's much to fix here sadly, other than it happens.

@sashahilton00 Would there anything stopping us from retrying this 3 times, and then failing, or would that be best left in the relms of librespotd?

@l3d00m
Copy link
Author

l3d00m commented Mar 6, 2018

Ah sorry if I misunderstood you so far. I now assume that is just how librespot handles errors by throwing them like this?

@ComlOnline
Copy link
Contributor

So basically the server is sending this error to you, as you may seen on a website from time to time:

503 SERVICE UNAVAILABLE
The server is currently unable to handle the request due to a temporary overload or scheduled maintenance, which will likely be alleviated after some delay.

librespot doesn't handle this well and results in the above crash. So a bit of Spotify and librespot.

(I could be wrong but I'm pretty sure that's whats going on. The question is this is how we want handle this going forward)

@maufl
Copy link

maufl commented Mar 6, 2018

I have this error too. My problem is that librespot does not completely crash, i.e. the process does not exit, so it won't be restarted. By the way, librespotd does not yet have a description, is it supposed to replace the binary of librespot? Which one am I supposed to use?

@l3d00m
Copy link
Author

l3d00m commented Mar 6, 2018

Does it crash if you try to resume the playback on your client @maufl?

If so, it may be related to #183

@maufl
Copy link

maufl commented Mar 6, 2018

I don't think so. So far the only way to make it work again was to restart the librespot systemd service. Unfortunately this error is hard to reproduce :/ I'm currently running a debug build and wait for it to happen again.

@ComlOnline
Copy link
Contributor

@maufl that is a bug then if its not handling the error correctly. At the moment librespotd is still a work in progress.

@ComlOnline ComlOnline added the bug label Mar 6, 2018
@ComlOnline
Copy link
Contributor

Here is the if that throws an error if a response code 400 or higher is received.

@maufl
Copy link

maufl commented Mar 7, 2018

I think it might be this unwrap that causes the panic, I'll try to investigate. Unfortunately, the debug build is too slow to be usable, I'll try compiling the release build with debug symbols today.

@sashahilton00
Copy link
Member

@ComlOnline I think your solution of retrying it a few times is a good idea. Do you want to implement a runoff feature (retries with increasing intervals until success), or do you want to have it try a set number of times at a set interval, then panic if it fails? I agree, as it currently stands, our handling of this error is poor, since it basically locks up librespot until manually restarted.

@maufl librespotd is currently a placeholder, we're not working on it atm. Use librespot, we'll make it clear when development shifts to librespotd. Currently, we need to get librespot packaged up and published, and iron out some of the more pressing issues, such as this one, session reconnection (which is sort of related to this one), and precaching audio.

@maufl
Copy link

maufl commented Mar 9, 2018

As expected, I have a well running release build with debug symbols but the error has not occurred again yet :/

@ComlOnline
Copy link
Contributor

@sashahilton00 Its a tough call depending on the functionality we want. I think a set number of retries and then panic is the way we should go.

I like the idea of retying (in a runoff fashion) for ten minutes then failing. If you get that many errors for ten mins there must be a bigger problem with Spotify,

@sashahilton00
Copy link
Member

Agreed, a runoff for 10 mins or so should suffice. The problem I have is that I am uncertain as to where the request is called from; the complete_request function here just looks to process the mercuryresponse header, so I'm not too sure where the initial request is called from, without having to spend some time reading through the mercury part of the code to understand how it works. Thus, until I have some free time (exam season atm) to learn about it, either someone else can implement the runoff feature/provide some info on where it would need to be implemented, or as a stopgap, we could just change that warn! into a panic!. Would appreciate any input @plietar on whether changing that warn to a panic is going to have a serious impact on librespot usability (not sure how often it errors in normal usage).

@ComlOnline
Copy link
Contributor

I changed it to a panic and it seems to be running fine (so far) as it should only be triggered if that error comes up. Like @sashahilton00 this would be a temp fix until it can be sorted properly.

@sashahilton00
Copy link
Member

I've created #198 to catch 5xx errors and panic if it encounters them. It's lazy, but I don't have time to learn enough rust to implement the runoff functionality.

@ComlOnline
Copy link
Contributor

ComlOnline commented Apr 11, 2018

That works for me.

@l3d00m
Copy link
Author

l3d00m commented May 9, 2018

I am running librespot INFO:librespot: librespot (raspotify) deb240c (2018-05-01). Built on 2018-05-04. Build ID: GeKsU3jL on my pi in combination with snapcast.

As my wifi connection is quite unreliable, librespot crashes very often (5 times a day) with the above described ChannelError. The error is not catched immediately, exactly as described in the OP, so #198 had no effect for me.

Added the log again, but I think it's exactly the same, it even crashes with identical errors. It is a bit more unreadable thanks to the snapcast logger, but I think it's still okay-ish.

May 09 14:24:11 raspi-bad nice[556]: 2018-05-09 14-24-11 [Info] (Spotify) INFO:librespot_playback::player: Loading track "River (feat. Ed Sheeran)" with Spotify URI "spotify:track:5UEnHoDYpsxlfzWLZIc7LD"
May 09 14:24:12 raspi-bad nice[556]: 2018-05-09 14-24-12 [Info] (Spotify) ERROR:librespot_core::channel: channel error: 2 1
May 09 14:24:12 raspi-bad nice[556]: 2018-05-09 14-24-12 [Info] (Spotify) thread '<unnamed>' panicked at 'called `Result::unwrap()` on an `Err` value: ChannelError', libcore/result.rs:945:5
May 09 14:24:12 raspi-bad nice[556]: 2018-05-09 14-24-12 [Info] (Spotify) stack backtrace:
May 09 14:24:12 raspi-bad nice[556]: 2018-05-09 14-24-12 [Info] (Spotify) 0:   0x
May 09 14:24:12 raspi-bad nice[556]: 2018-05-09 14-24-12 [Info] (Spotify) 9fa05f - std::sys::unix::backtrace::tracing::imp::unwind_backtrace::h4ef6490c84cef3d0
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) at libstd/sys/unix/backtrace/tracing/gcc_s.rs:
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) 49
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info]    1:   0x9f3dbb - std::sys_common::backtrace::_print::hea150ee4f33bb5de
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info]                        at libstd/sys_common/backtrace.rs:71
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info]    2:   0x9f8acf - std::
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) panicking
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) default_hook
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) closure
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) h6c4396ff5bd61d89
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) libstd/sys_common/backtrace.rs
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) libstd/panicking.rs
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) 9f86b3
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) panicking
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) default_hook
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) h0f6cb16cf06a0198
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) libstd/panicking.rs
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) 9f8f73
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) panicking
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) rust_panic_with_hook
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) h2207195920ffa55f
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) libstd/panicking.rs
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) 9f8dd7
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) panicking
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) begin_panic
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) h8d43a09cf6d6e5f1
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) libstd/panicking.rs
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) 9f8d5b
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) panicking
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) begin_panic_fmt
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) hd9afc94159ee9735
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) libstd/panicking.rs
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) 9f8cf3
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) rust_begin_unwind
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) libstd/panicking.rs
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) a46b57
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) panicking
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) panic_fmt
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) h0bd854df201d1baf
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) libcore/panicking.rs
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) 59bcf7
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) result
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) unwrap_failed
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) hb871a2e167f8a266
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) 5979c3
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) librespot_playback
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) player
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) PlayerInternal
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) h716c64411ae5f020
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) 528b5f
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) sys_common
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) backtrace
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) __rust_begin_short_backtrace
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) he7ec4d93e04aa040
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) 50d8eb
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) panicking
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) do_call
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) h7d89514a01c5107f
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) a08373
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) __rust_maybe_catch_panic
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) libpanic_unwind/lib.rs
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) 50eb33
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) alloc
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) boxed
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) FnBox
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) call_box
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) h7d9ef2bdaa46d172
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) 9ff00b
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) thread
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) Thread
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) thread_start
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) hb1d1727b173caaf8
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) /checkout/src/liballoc/boxed.rs
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) libstd/sys_common/thread.rs
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) libstd/sys/unix/thread.rs
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] onStateChanged (Spotify): 1
May 09 14:33:30 raspi-bad nice[556]: 2018-05-09 14-33-30 [Info] (Spotify) thread 'main
May 09 14:33:30 raspi-bad nice[556]: 2018-05-09 14-33-30 [Info] (Spotify) ' panicked at 'called `Result::unwrap()` on an `Err` value: "SendError(..)"', libcore/result.rs:945:5
May 09 14:33:30 raspi-bad nice[556]: 2018-05-09 14-33-30 [Info] stack backtrace:
May 09 14:33:30 raspi-bad nice[556]: 2018-05-09 14-33-30 [Info]    0:   0x9fa05f - std::sys::unix::backtrace::tracing::imp::unwind_backtrace::h4ef6490c84cef3d0
May 09 14:33:30 raspi-bad nice[556]: 2018-05-09 14-33-30 [Info]                        at libstd/sys/unix/backtrace/tracing/gcc_s.rs:49
May 09 14:33:30 raspi-bad nice[556]: 2018-05-09 14-33-30 [Info]    1:   0x9f3dbb - std::sys_common::backtrace::_print::hea150ee4f33bb5de
May 09 14:33:30 raspi-bad nice[556]: 2018-05-09 14-33-30 [Info]                        at libstd/sys_common/backtrace.rs:71
May 09 14:33:30 raspi-bad nice[556]: 2018-05-09 14-33-30 [Info]    2:   0x9f8acf - std::panicking::default_hook::{{closure}}::h6c4396ff5bd61d89
May 09 14:33:30 raspi-bad nice[556]: 2018-05-09 14-33-30 [Info]                        at libstd/sys_common/backtrace.rs:59
May 09 14:33:30 raspi-bad nice[556]: 2018-05-09 14-33-30 [Info]                        at libstd/panicking.rs:380
May 09 14:33:30 raspi-bad nice[556]: 2018-05-09 14-33-30 [Info]    3:   0x9f86b3 - std::panicking::default_hook::h0f6cb16cf06a0198
May 09 14:33:30 raspi-bad nice[556]: 2018-05-09 14-33-30 [Info]                        at libstd/panicking.rs:396
May 09 14:33:30 raspi-bad nice[556]: 2018-05-09 14-33-30 [Info]    4:   0x9f8f73 - std::panicking::rust_panic_with_hook::h2207195920ffa55f
May 09 14:33:30 raspi-bad nice[556]: 2018-05-09 14-33-30 [Info]                        at libstd/panicking.rs:576
May 09 14:33:30 raspi-bad nice[556]: 2018-05-09 14-33-30 [Info]    5:   0x9f8dd7 - std::panicking::begin_panic::h8d43a09cf6d6e5f1
May 09 14:33:30 raspi-bad nice[556]: 2018-05-09 14-33-30 [Info]                        at libstd/panicking.rs:537
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) hd9afc94159ee9735
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) libstd/panicking.rs
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) 9f8cf3
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) rust_begin_unwind
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) libstd/panicking.rs
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) a46b57
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) panicking
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) panic_fmt
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) h0bd854df201d1baf
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) libcore/panicking.rs
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) 59bcf7
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) result
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) unwrap_failed
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) hb871a2e167f8a266
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) 5979c3
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) librespot_playback
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) player
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) PlayerInternal
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) h716c64411ae5f020
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) 528b5f
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) sys_common
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) backtrace
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) __rust_begin_short_backtrace
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) he7ec4d93e04aa040
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) 50d8eb
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) panicking
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) do_call
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) h7d89514a01c5107f
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) a08373
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) __rust_maybe_catch_panic
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) libpanic_unwind/lib.rs
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) 50eb33
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) alloc
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) boxed
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) FnBox
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) call_box
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) h7d9ef2bdaa46d172
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) 9ff00b
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) thread
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) Thread
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) thread_start
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) hb1d1727b173caaf8
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) /checkout/src/liballoc/boxed.rs
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) libstd/sys_common/thread.rs
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] (Spotify) libstd/sys/unix/thread.rs
May 09 14:24:13 raspi-bad nice[556]: 2018-05-09 14-24-13 [Info] onStateChanged (Spotify): 1
May 09 14:33:30 raspi-bad nice[556]: 2018-05-09 14-33-30 [Info] (Spotify) ' panicked at 'called `Result::unwrap()` on an `Err` value: "SendError(..)"', libcore/result.rs:945:5
May 09 14:33:30 raspi-bad nice[556]: 2018-05-09 14-33-30 [Info] stack backtrace:
May 09 14:33:30 raspi-bad nice[556]: 2018-05-09 14-33-30 [Info]    0:   0x9fa05f - std::sys::unix::backtrace::tracing::imp::unwind_backtrace::h4ef6490c84cef3d0
May 09 14:33:30 raspi-bad nice[556]: 2018-05-09 14-33-30 [Info]                        at libstd/sys/unix/backtrace/tracing/gcc_s.rs:49
May 09 14:33:30 raspi-bad nice[556]: 2018-05-09 14-33-30 [Info]    1:   0x9f3dbb - std::sys_common::backtrace::_print::hea150ee4f33bb5de
May 09 14:33:30 raspi-bad nice[556]: 2018-05-09 14-33-30 [Info]                        at libstd/sys_common/backtrace.rs:71
May 09 14:33:30 raspi-bad nice[556]: 2018-05-09 14-33-30 [Info]    2:   0x9f8acf - std::panicking::default_hook::{{closure}}::h6c4396ff5bd61d89
May 09 14:33:30 raspi-bad nice[556]: 2018-05-09 14-33-30 [Info]                        at libstd/sys_common/backtrace.rs:59
May 09 14:33:30 raspi-bad nice[556]: 2018-05-09 14-33-30 [Info]                        at libstd/panicking.rs:380
May 09 14:33:30 raspi-bad nice[556]: 2018-05-09 14-33-30 [Info]    3:   0x9f86b3 - std::panicking::default_hook::h0f6cb16cf06a0198
May 09 14:33:30 raspi-bad nice[556]: 2018-05-09 14-33-30 [Info]                        at libstd/panicking.rs:396
May 09 14:33:30 raspi-bad nice[556]: 2018-05-09 14-33-30 [Info]    4:   0x9f8f73 - std::panicking::rust_panic_with_hook::h2207195920ffa55f
May 09 14:33:30 raspi-bad nice[556]: 2018-05-09 14-33-30 [Info]                        at libstd/panicking.rs:576
May 09 14:33:30 raspi-bad nice[556]: 2018-05-09 14-33-30 [Info]    5:   0x9f8dd7 - std::panicking::begin_panic::h8d43a09cf6d6e5f1
May 09 14:33:30 raspi-bad nice[556]: 2018-05-09 14-33-30 [Info]                        at libstd/panicking.rs:537
May 09 14:33:30 raspi-bad nice[556]: 2018-05-09 14-33-30 [Info]    6:   0x9f8d5b - std::panicking::begin_panic_fmt::hd9afc94159ee9735
May 09 14:33:30 raspi-bad nice[556]: 2018-05-09 14-33-30 [Info]                        at libstd/panicking.rs:521
May 09 14:33:30 raspi-bad nice[556]: 2018-05-09 14-33-30 [Info]    7:   0x9f8cf3 - rust_begin_unwind
May 09 14:33:30 raspi-bad nice[556]: 2018-05-09 14-33-30 [Info]                        at libstd/panicking.rs:497
May 09 14:33:30 raspi-bad nice[556]: 2018-05-09 14-33-30 [Info]    8:   0xa46b57 - core::panicking::panic_fmt::h0bd854df201d1baf
May 09 14:33:30 raspi-bad nice[556]: 2018-05-09 14-33-30 [Info]                        at libcore/panicking.rs:71
May 09 14:33:30 raspi-bad nice[556]: 2018-05-09 14-33-30 [Info]    9:   0x59bc4f - core::result::unwrap_failed::hb5309a53cc9baafd
May 09 14:33:30 raspi-bad nice[556]: 2018-05-09 14-33-30 [Info]   10:   0x58f5ef - librespot_playback::player::Player::load::ha1457ea9a025a068
May 09 14:33:30 raspi-bad nice[556]: 2018-05-09 14-33-30 [Info]   11:   0x5516f3 - librespot_connect::spirc::SpircTask::load_track::h811b0ff8d2e7e184
May 09 14:33:30 raspi-bad nice[556]: 2018-05-09 14-33-30 [Info]   12:   0x550bbf - librespot_connect::spirc::SpircTask::handle_next::hf6a252da73b8ecf3
May 09 14:33:30 raspi-bad nice[556]: 2018-05-09 14-33-30 [Info]   13:   0x54feb7 - <librespot_connect::spirc::SpircTask as futures::future::Future>::poll::h3aa21d3f3938041e
May 09 14:33:30 raspi-bad nice[556]: 2018-05-09 14-33-30 [Info]   14:   0x533a23 - <librespot::Main as futures::future::Future>::poll::hcaa1da13888abbda
May 09 14:33:30 raspi-bad nice[556]: 2018-05-09 14-33-30 [Info]   15:   0x50f063 - futures::task_impl::std::set::habaea1ac6226f3d5
May 09 14:33:30 raspi-bad nice[556]: 2018-05-09 14-33-30 [Info]   16:   0x52b0e7 - <futures::future::lazy::Lazy<F, R> as futures::future::Future>::poll::h000b8eb0aa8abb93
May 09 14:33:30 raspi-bad nice[556]: 2018-05-09 14-33-30 [Info]   17:   0x50ef4f - futures::task_impl::std::set::h9a7175e007921cdc
May 09 14:33:30 raspi-bad nice[556]: 2018-05-09 14-33-30 [Info]   18:   0x515ceb - <std::thread::local::LocalKey<T>>
May 09 14:33:30 raspi-bad nice[556]: 2018-05-09 14-33-30 [Info] (Spotify) ::with::h631b79174c366208
May 09 14:33:30 raspi-bad nice[556]: 2018-05-09 14-33-30 [Info]   19:   0x51a703 - <tokio::executor::current_thread::Entered<'a, P>>::block_on::h121e2013bc72c084
May 09 14:33:30 raspi-bad nice[556]: 2018-05-09 14-33-30 [Info]   20:   0x515b23 - <std::thread::local::LocalKey<T>>::with::h4bbda60b79a8b31a
May 09 14:33:30 raspi-bad nice[556]: 2018-05-09 14-33-30 [Info]   21:   0x515663 - <std::thread::local::LocalKey<T>>::with::h0e6453ea61f586a7
May 09 14:33:30 raspi-bad nice[556]: 2018-05-09 14-33-30 [Info]   22:   0x5158d3 - <std::thread::local::LocalKey<T>>::with::h1dc135eb563de91f
May 09 14:33:30 raspi-bad nice[556]: 2018-05-09 14-33-30 [Info]   23:   0x5172ef - <scoped_tls::ScopedKey<T>>::set::hbaf051ffecb379c5
May 09 14:33:30 raspi-bad nice[556]: 2018-05-09 14-33-30 [Info]   24:   0x511983 - tokio_core::reactor::Core::run::hda0ba19f949a8f18
May 09 14:33:30 raspi-bad nice[556]: 2018-05-09 14-33-30 [Info]   25:   0x5358c7 - librespot::main::hd05bb25f4d0dd18c
May 09 14:33:30 raspi-bad nice[556]: 2018-05-09 14-33-30 [Info]   26:   0x528bf3 - std::rt::lang_start::{{closure}}::ha9c718613290118d
May 09 14:33:30 raspi-bad nice[556]: 2018-05-09 14-33-30 [Info]   27:   0x9f8c2b - std::panicking::try::do_call::h5f03c49f73b7300e
May 09 14:33:30 raspi-bad nice[556]: 2018-05-09 14-33-30 [Info]                        at libstd/rt.rs:59
May 09 14:33:30 raspi-bad nice[556]: 2018-05-09 14-33-30 [Info]                        at libstd/panicking.rs:479
May 09 14:33:30 raspi-bad nice[556]: 2018-05-09 14-33-30 [Info]   28:   0xa08373 - __rust_maybe_catch_panic
May 09 14:33:30 raspi-bad nice[556]: 2018-05-09 14-33-30 [Info]                        at libpanic_unwind/lib.rs:102
May 09 14:33:30 raspi-bad nice[556]: 2018-05-09 14-33-30 [Info]   29:   0x9f939b - std::rt::lang_start_internal::h907d77b40aa767dd
May 09 14:33:30 raspi-bad nice[556]: 2018-05-09 14-33-30 [Info]                        at libstd/panicking.rs:458
May 09 14:33:30 raspi-bad nice[556]: 2018-05-09 14-33-30 [Info]                        at libstd/panic.rs:358
May 09 14:33:30 raspi-bad nice[556]: 2018-05-09 14-33-30 [Info]                        at libstd/rt.rs:58
May 09 14:33:30 raspi-bad nice[556]: 2018-05-09 14-33-30 [Info]   30:   0x5364bf - main
May 09 14:33:30 raspi-bad nice[556]: 2018-05-09 14-33-30 [Info]   31: 0x76ccd677 - __libc_start_main
May 09 14:33:30 raspi-bad nice[556]: 2018-05-09 14-33-30 [Info] ERROR:librespot_playback::player: Player thread panicked!

@l3d00m
Copy link
Author

l3d00m commented May 10, 2018

Reported in #215 too

@roderickvd
Copy link
Member

Closing this for the same reasons as in #215 (Spotify fixed channel errors on their end).

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Projects
None yet
Development

No branches or pull requests

6 participants