Crash on first connection attempt

[jpxd]

Describe the bug After installing raspotify (https://dtcooper.github.io/raspotify/), which uses librespot internally, on my Raspberry Pi 3B+, I switched my already running music from my Macbook to the Raspberry Pi. Raspotify instantly crashed (see log). I tried to replicate with verbose logging but then it worked. Now it even works without verbose logging and I can't reproduce it any more. So this could be a one off error which hopefully never happens again for me. Neverless I'll leave the stack trace here for you, in case it helps finding the bug.

To reproduce Steps to reproduce the behavior:

1. Launch librespot via raspotify for the first time
2. Connect with a MacBook Pro with running music
3. raspotify crashes

Log

Dec 11 17:51:25 janet systemd[1]: Started Raspotify (Spotify Connect Client).
Dec 11 17:52:02 janet librespot[6514]: thread 'main' panicked at 'range end index 16 out of range for slice of length 0', discovery/src/server.rs:89:19
Dec 11 17:52:02 janet librespot[6514]: stack backtrace:
Dec 11 17:52:02 janet librespot[6514]:    0:   0x754c10 - std::backtrace_rs::backtrace::libunwind::trace::h14d80f23337b01fc
Dec 11 17:52:02 janet librespot[6514]:                        at /rustc/897e37553bba8b42751c67658967889d11ecd120/library/std/src/../../backtrace/src/backtrace/libunwind.rs:93:5
Dec 11 17:52:02 janet librespot[6514]:    1:   0x754c10 - std::backtrace_rs::backtrace::trace_unsynchronized::h7f37c71459e9f549
Dec 11 17:52:02 janet librespot[6514]:                        at /rustc/897e37553bba8b42751c67658967889d11ecd120/library/std/src/../../backtrace/src/backtrace/mod.rs:66:5
Dec 11 17:52:02 janet librespot[6514]:    2:   0x754c10 - std::sys_common::backtrace::_print_fmt::h53f2b10355c4ff84
Dec 11 17:52:02 janet librespot[6514]:                        at /rustc/897e37553bba8b42751c67658967889d11ecd120/library/std/src/sys_common/backtrace.rs:66:5
Dec 11 17:52:02 janet librespot[6514]:    3:   0x754c10 - <std::sys_common::backtrace::_print::DisplayBacktrace as core::fmt::Display>::fmt::hf58f9d1e255cdabd
Dec 11 17:52:02 janet librespot[6514]:                        at /rustc/897e37553bba8b42751c67658967889d11ecd120/library/std/src/sys_common/backtrace.rs:45:22
Dec 11 17:52:02 janet librespot[6514]:    4:   0x50f918 - core::fmt::write::ha633ce200262a27a
Dec 11 17:52:02 janet librespot[6514]:                        at /rustc/897e37553bba8b42751c67658967889d11ecd120/library/core/src/fmt/mod.rs:1202:17
Dec 11 17:52:02 janet librespot[6514]:    5:   0x727be4 - std::io::Write::write_fmt::hfbfdb2028ac11914
Dec 11 17:52:02 janet librespot[6514]:                        at /rustc/897e37553bba8b42751c67658967889d11ecd120/library/std/src/io/mod.rs:1679:15
Dec 11 17:52:02 janet librespot[6514]:    6:   0x7568a4 - std::sys_common::backtrace::_print::h93be7040ad47e85c
Dec 11 17:52:02 janet librespot[6514]:                        at /rustc/897e37553bba8b42751c67658967889d11ecd120/library/std/src/sys_common/backtrace.rs:48:5
Dec 11 17:52:02 janet librespot[6514]:    7:   0x7568a4 - std::sys_common::backtrace::print::hf56c57924dc18e75
Dec 11 17:52:02 janet librespot[6514]:                        at /rustc/897e37553bba8b42751c67658967889d11ecd120/library/std/src/sys_common/backtrace.rs:35:9
Dec 11 17:52:02 janet librespot[6514]:    8:   0x7568a4 - std::panicking::default_hook::{{closure}}::hce7eea153e929503
Dec 11 17:52:02 janet librespot[6514]:                        at /rustc/897e37553bba8b42751c67658967889d11ecd120/library/std/src/panicking.rs:295:22
Dec 11 17:52:02 janet librespot[6514]:    9:   0x7576d4 - std::panicking::default_hook::h616b0242201740b4
Dec 11 17:52:02 janet librespot[6514]:                        at /rustc/897e37553bba8b42751c67658967889d11ecd120/library/std/src/panicking.rs:314:9
Dec 11 17:52:02 janet librespot[6514]:   10:   0x7576d4 - std::panicking::rust_panic_with_hook::h8efe579765744b3c
Dec 11 17:52:02 janet librespot[6514]:                        at /rustc/897e37553bba8b42751c67658967889d11ecd120/library/std/src/panicking.rs:698:17
Dec 11 17:52:02 janet librespot[6514]:   11:   0x75723c - std::panicking::begin_panic_handler::{{closure}}::he045c9f3a57a47c1
Dec 11 17:52:02 janet librespot[6514]:                        at /rustc/897e37553bba8b42751c67658967889d11ecd120/library/std/src/panicking.rs:588:13
Dec 11 17:52:02 janet librespot[6514]:   12:   0x7571e0 - std::sys_common::backtrace::__rust_end_short_backtrace::h35d6578f5b240f70
Dec 11 17:52:02 janet librespot[6514]:                        at /rustc/897e37553bba8b42751c67658967889d11ecd120/library/std/src/sys_common/backtrace.rs:138:18
Dec 11 17:52:02 janet librespot[6514]:   13:   0x7571b4 - rust_begin_unwind
Dec 11 17:52:02 janet librespot[6514]:                        at /rustc/897e37553bba8b42751c67658967889d11ecd120/library/std/src/panicking.rs:584:5
Dec 11 17:52:02 janet librespot[6514]:   14:   0x45ce68 - core::panicking::panic_fmt::h33cb74c4e3aba0f5
Dec 11 17:52:02 janet librespot[6514]:                        at /rustc/897e37553bba8b42751c67658967889d11ecd120/library/core/src/panicking.rs:142:14
Dec 11 17:52:02 janet librespot[6514]:   15:   0x50f27c - core::slice::index::slice_end_index_len_fail_rt::h2787fdeec5c285b1
Dec 11 17:52:02 janet librespot[6514]:                        at /rustc/897e37553bba8b42751c67658967889d11ecd120/library/core/src/slice/index.rs:76:5
Dec 11 17:52:02 janet librespot[6514]:   16:   0x45cef4 - core::slice::index::slice_end_index_len_fail::h58dd07dace215cee
Dec 11 17:52:02 janet librespot[6514]:                        at /rustc/897e37553bba8b42751c67658967889d11ecd120/library/core/src/slice/index.rs:69:9
Dec 11 17:52:02 janet librespot[6514]:   17:   0x59d65c - librespot_discovery::server::RequestHandler::handle_add_user::hb450b218bd5b3d42
Dec 11 17:52:02 janet librespot[6514]:   18:   0x5a9410 - <hyper::server::server::new_svc::NewSvcTask<I,N,S,E,W> as core::future::future::Future>::poll::h2e01d9e993ae2735
Dec 11 17:52:02 janet librespot[6514]:   19:   0x5b8810 - tokio::runtime::task::raw::poll::hb720b90a444485d9
Dec 11 17:52:02 janet librespot[6514]:   20:   0x4e3730 - librespot::main::hbb21c8d9712c9b71
Dec 11 17:52:02 janet librespot[6514]:   21:   0x4840a8 - std::sys_common::backtrace::__rust_begin_short_backtrace::h2fc318d282236471
Dec 11 17:52:02 janet librespot[6514]:   22:   0x4ef24c - main
Dec 11 17:52:02 janet librespot[6514]:   23: 0x76b93740 - __libc_start_main
Dec 11 17:52:02 janet librespot[6514]:                        at ./csu/./csu/libc-start.c:308:16
Dec 11 17:52:02 janet systemd[1]: raspotify.service: Main process exited, code=killed, status=6/ABRT
Dec 11 17:52:02 janet systemd[1]: raspotify.service: Failed with result 'signal'.

Host (what you are running librespot on):

• OS: Raspbian (Debian Bullseye)
• Platform: RPi 3B+

[JasonLG1979]

I believe this is already fixed in dev.

That bit of discovery has been rewritten from stable to dev to check for that particular situation:

https://github.com/librespot-org/librespot/blob/dev/discovery/src/server.rs#L134-L136

        if encrypted_blob_len < 16 {
            return Err(DiscoveryError::HmacError(encrypted_blob.to_vec()).into());
        }

Raspotify is based on stable. As soon as what is now dev is released as a stable version the fix will come along with it to Raspotify.

[roderickvd]

Indeed! As to why that circumstance happens occasionally, I do not know.

[jpxd]

Perfect! Thanks for the quick answer!