Thread 'main' panicked at 'connection closed'

[sashahilton00]

Issue by JoakimLindbom
Tuesday Oct 24, 2017 at 11:35 GMT
Originally opened as plietar/librespot#262

---

Randomly playback is stopped.
I'm running librespot 8971d3a (2017-10-05). Built on 2017-10-05. Build ID: POyxPQVg on a Raspberry Pi 3 with raspotify. Using ALSA with an Hifiberry AMP+
Kernel: 4.9.41-v7+ #1023 SMP Tue Aug 8 16:00:15 BST 2017 armv7l

Oct 24 13:04:08 myplayer librespot[3472]: thread 'main' panicked at 'connection closed', /checkout/src/libcore/option.rs:819:4
Oct 24 13:04:08 myplayer librespot[3472]: note: Run with `RUST_BACKTRACE=1` for a backtrace.
Oct 24 13:04:08 myplayer systemd[1]: raspotify.service: Main process exited, code=exited, status=101/n/a
Oct 24 13:04:08 myplayer systemd[1]: raspotify.service: Unit entered failed state.
Oct 24 13:04:08 myplayer systemd[1]: raspotify.service: Failed with result 'exit-code'.
Oct 24 13:04:18 myplayer systemd[1]: raspotify.service: Service hold-off time over, scheduling restart.
Oct 24 13:04:18 myplayer systemd[1]: Stopped Raspotify.
Oct 24 13:04:18 myplayer systemd[1]: Starting Raspotify...
Oct 24 13:04:18 myplayer systemd[1]: Started Raspotify.
Oct 24 13:04:18 myplayer librespot[3766]: INFO:librespot: librespot 8971d3a (2017-10-05). Built on 2017-10-05. Build ID: POyxPQVg
Oct 24 13:04:19 myplayer librespot[3766]: INFO:librespot_core::session: Connecting to AP "gew1-accesspoint-b-jws4.ap.spotify.com:4070"

[sashahilton00]

Comment by tabell
Friday Oct 27, 2017 at 15:03 GMT

---

Are you able to turn on backtraces and make it happen again?

[sashahilton00]

Comment by tenortim
Monday Oct 30, 2017 at 05:16 GMT

---

I'm running an older build, but basically hitting the same problem randomly. Build is
INFO:librespot: librespot cc9dba8 (2017-03-26). Built on 2017-07-17. Build ID: 8zQE3Bpb
crash is
thread 'main' panicked at 'connection closed', /checkout/src/libcore/option.rs:794

I'll get the full backtrace, but I need to carve out time to look at this.
It doesn't happen immediately but relatively quickly.

[sashahilton00]

Comment by tenortim
Sunday Nov 05, 2017 at 00:16 GMT

---

Full backtrace:

thread 'main' panicked at 'connection closed', /checkout/src/libcore/option.rs:794
stack backtrace:
   0: std::sys::imp::backtrace::tracing::imp::unwind_backtrace
             at /checkout/src/libstd/sys/unix/backtrace/tracing/gcc_s.rs:49
   1: std::sys_common::backtrace::_print
             at /checkout/src/libstd/sys_common/backtrace.rs:71
   2: std::panicking::default_hook::{{closure}}
             at /checkout/src/libstd/sys_common/backtrace.rs:60
             at /checkout/src/libstd/panicking.rs:355
   3: std::panicking::default_hook
             at /checkout/src/libstd/panicking.rs:371
   4: std::panicking::rust_panic_with_hook
             at /checkout/src/libstd/panicking.rs:549
   5: std::panicking::begin_panic
             at /checkout/src/libstd/panicking.rs:511
   6: std::panicking::begin_panic_fmt
             at /checkout/src/libstd/panicking.rs:495
   7: rust_begin_unwind
             at /checkout/src/libstd/panicking.rs:471
   8: core::panicking::panic_fmt
             at /checkout/src/libcore/panicking.rs:69
   9: core::option::expect_failed
             at /checkout/src/libcore/option.rs:794
  10: <futures::future::map::Map<A, F> as futures::future::Future>::poll
  11: <futures::future::map_err::MapErr<A, F> as futures::future::Future>::poll
  12: tokio_core::reactor::Core::poll
  13: librespot::main
  14: __rust_maybe_catch_panic
             at /checkout/src/libpanic_unwind/lib.rs:98
  15: std::rt::lang_start
             at /checkout/src/libstd/panicking.rs:433
             at /checkout/src/libstd/panic.rs:361
             at /checkout/src/libstd/rt.rs:57
  16: __libc_start_main

[sashahilton00]

Comment by tomtaylor
Sunday Jan 14, 2018 at 22:12 GMT

---

@tenortim I get an identical backtrace quite regularly. Did you or anyone manage to resolve it?

[sashahilton00]

Comment by tomtaylor
Sunday Jan 14, 2018 at 22:16 GMT

---

This appears to happen even when librespot is idle, about every 30-60 seconds or so.

[sashahilton00]

Comment by kingosticks
Monday Jan 15, 2018 at 00:10 GMT

---

I don't get this. Could it be a problem with a specific access point?

[sashahilton00]

Comment by tomtaylor
Monday Jan 15, 2018 at 10:10 GMT

---

@kingosticks I can confirm this is happening with multiple (at least 5) access points.

[sashahilton00]

Comment by tomtaylor
Monday Jan 15, 2018 at 10:10 GMT

---

I'm afraid I know very little Rust, but have decent Unix experience, so let me know if I can provide any information to debug this.

[sashahilton00]

Comment by tomtaylor
Monday Jan 15, 2018 at 14:24 GMT

---

OK, this is odd. It only seems to happen when running inside a container running on Docker for Mac. If I build the same container (from the same Dockerfile) in Docker on an Ubuntu box running amd64, it works fine.

[sashahilton00]

Comment by tomtaylor
Monday Jan 15, 2018 at 14:27 GMT

---

If anyone wants to try and reproduce, I've put my Dockerfile and associated files over here: https://github.com/tomtaylor/multiroom-server

[sashahilton00]

Comment by tenortim
Monday Jan 15, 2018 at 20:24 GMT

---

@tomtaylor this is running it on a Raspberry Pi 3. No containers but I am running the prebuilt version. Maybe I should try to build it all from scratch and see what I get. It still happens,

[sashahilton00]

I'm fairly sure that this is a bug that librespot isn't responsible for - there is nothing in the backtrace to suggest librespot is the problem?

[sashahilton00]

Does it run well outside a docker container @tomtaylor?

[sashahilton00]

Closing as no response from OP, and no suggestion in backtrace that this is a bug in librespot. Open a new issue and reference this one if this is still a problem.