Spotify connect fail, panic

Hi,

Thank you for the great combination of Volumio and Spotify I enjoy to hear music almost every day… BUT, suddenly from 2 hours ago, when I tried to connect with Spotify app from my iPad or MacBook, Volumio started to reject my connection request. It looks once accepted, but then failed in a 5 second.

Below is the log file generated by the command “journalctl -f -o cat”

The log file said:

"thread 'main' **panicked** at 'Spotify servers returned an error."
-----------------------------------
root@rotate:/home/volumio# journalctl -f -o cat
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
volspotconnect2.service holdoff time over, scheduling restart.
Stopping Volspotconnect2 Daemon...
Starting Volspotconnect2 Daemon...
Started Volspotconnect2 Daemon.
vollibrespot v0.2.2 cd96399 2020-10-07 (librespot 08d8bcc 2020-10-07) -- Built On 2020-10-07
Reading Config from "volspotify.toml"
[Vollibrespot] : Using Alsa backend with device: plughw:2
[Vollibrespot] : Failed to register IPv6 receiver: Os { code: 19, kind: Other, message: "No such device" }
[Vollibrespot] : Connecting to AP "gae2-accesspoint-b-vfq3.ap.spotify.com:443"
[Vollibrespot] : Authenticated as "21n25wukzzqgsdponevurtrrq" !
[Vollibrespot] : Setting up new mixer: card:hw:2 mixer:Master index:0
[Vollibrespot] : Alsa min-db is not SND_CTL_TLV_DB_GAIN_MUTE!!
[Vollibrespot] : Alsa Mixer info min: 0 (MilliBel(-12750)[dB]) -- max: 255 (MilliBel(0)[dB]) HW: true
[Vollibrespot] : Alsa min-db is not SND_CTL_TLV_DB_GAIN_MUTE!!
[Vollibrespot] : Using alsa sink
[Vollibrespot] : Country: "JP"
[Vollibrespot] : Metadata pipe established
[Vollibrespot] : Event: Volume { volume_to_mixer: 19660 }
[SpotifyConnect] <Volume> 29.999237048905165
[SpotifyConnect] Volume: Spotify:29.999237048905165 Volumio: 30
info: CoreStateMachine::pushState
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
[Vollibrespot] : Fetching autoplay context uri
[Vollibrespot] : Event: SessionActive { became_active_at: 1608022750171 }
[Vollibrespot] : SessionActive!
[Vollibrespot] : Event: PlaybackStarted { track_id: SpotifyId { id: 117025201139629847069006936459738638492, audio_type: Track } }
[Vollibrespot] : Event: PlaybackLoading { track_id: SpotifyId { id: 117025201139629847069006936459738638492, audio_type: Track } }
[SpotifyConnect] <DeviceActive> A connect session has begun
[SpotifyConnect] <PlaybackActive> Device palyback is active!
info: CoreCommandRouter::volumioGetState
[SpotifyConnect] Currently active: volspotconnect2
[SpotifyConnect] Not requsting volumioStop on our own service
[SpotifyConnect] Vollibrespot Active
info: CoreCommandRouter::volumioGetState
[SpotifyConnect] Currently active: volspotconnect2
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
info: CoreCommandRouter::volumioGetState
[SpotifyConnect] Currently active: volspotconnect2
[SpotifyConnect] Pushing new state :: true
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
thread 'main' panicked at 'Spotify servers returned an error. Restart librespot.', /build/cache/git/checkouts/librespot-6f197fd632ef9380/08d8bcc/core/src/mercury/mod.rs:200:13
stack backtrace:
0:   0xa5b33c - backtrace::backtrace::libunwind::trace::hae21a072c81e5842
at /cargo/registry/src/github.com-1ecc6299db9ec823/backtrace-0.3.46/src/backtrace/libunwind.rs:86
1:   0xa5b33c - backtrace::backtrace::trace_unsynchronized::h0f9b260087e46e47
at /cargo/registry/src/github.com-1ecc6299db9ec823/backtrace-0.3.46/src/backtrace/mod.rs:66
2:   0xa5b33c - std::sys_common::backtrace::_print_fmt::hbf1a59173a7860c3
at src/libstd/sys_common/backtrace.rs:78
3:   0xa5b33c - <std::sys_common::backtrace::_print::DisplayBacktrace as core::fmt::Display>::fmt::he1a5d6f378e506c4
at src/libstd/sys_common/backtrace.rs:59
4:   0xa7bd5c - core::fmt::write::hb37ae5a5e0b70623
at src/libcore/fmt/mod.rs:1076
5:   0xa54c64 - std::io::Write::write_fmt::ha24bb3f5a858327b
at src/libstd/io/mod.rs:1537
6:   0xa5d974 - std::sys_common::backtrace::_print::h47b03aa1342833e3
at src/libstd/sys_common/backtrace.rs:62
7:   0xa5d974 - std::sys_common::backtrace::print::h2217cbc390250439
at src/libstd/sys_common/backtrace.rs:49
8:   0xa5d974 - std::panicking::default_hook::{{closure}}::h179f5229ea1c8e30
at src/libstd/panicking.rs:198
9:   0xa5d640 - std::panicking::default_hook::h46ab82039cbc65eb
at src/libstd/panicking.rs:217
10:   0xa5e054 - std::panicking::rust_panic_with_hook::h7326c48419bc7c33
at src/libstd/panicking.rs:526
11:   0x761e60 - std::panicking::begin_panic::h32bd0337e6f60c80
12:   0x777670 - librespot_core::mercury::MercuryManager::dispatch::hfc40927a9e25f6f4
13:   0x7548e4 - librespot_core::session::Session::dispatch::h443b33171bd0a54b
14:   0x755a94 - <librespot_core::session::DispatchTask<S> as futures::future::Future>::poll::h44e39a909986a977
15:   0x6ec544 - <futures::future::join::Join<A,B> as futures::future::Future>::poll::he539c98ccf64057e
16:   0x74f884 - <futures::future::map::Map<A,F> as futures::future::Future>::poll::h22f2ddba187c7f88
17:   0x7aa408 - <futures::future::map_err::MapErr<A,F> as futures::future::Future>::poll::h271e84c19710286e
18:   0x54352c - futures::task_impl::std::set::h73f64ee501dae51c
19:   0x5338f8 - tokio_current_thread::CurrentRunner::set_spawn::hc01b74ea59b01474
20:   0x556070 - tokio_current_thread::scheduler::Scheduler<U>::tick::h4e6f96fbe4f47161
21:   0x533ad4 - tokio_current_thread::Entered<P>::block_on::h339073902a399eb7
22:   0x557e00 - std::thread::local::LocalKey<T>::with::hff64c13ccfec5327
23:   0x56420c - tokio_reactor::with_default::h7ef12e65cb103d2f
24:   0x5379f8 - tokio::runtime::current_thread::runtime::Runtime::block_on::h043f136d6b8cf48f
volspotconnect2.service: main process exited, code=exited, status=101/n/a
Unit volspotconnect2.service entered failed state.
25:   0x57d2c8 - vollibrespot::main::h02a0d49d4cc5eaa6
26:   0x564f18 - std::rt::lang_start::{{closure}}::h279cd2b7929fdba7
27:   0xa5e404 - std::rt::lang_start_internal::{{closure}}::he93bfc404849b78a
at src/libstd/rt.rs:52
28:   0xa5e404 - std::panicking::try::do_call::h6e9e98f4078affb0
at src/libstd/panicking.rs:348
29:   0xa5e404 - std::panicking::try::h2e68d4f7f799a6df
at src/libstd/panicking.rs:325
30:   0xa5e404 - std::panic::catch_unwind::h8880a4c07cc66391
at src/libstd/panic.rs:394
31:   0xa5e404 - std::rt::lang_start_internal::hf4ae2140248bf16b
at src/libstd/rt.rs:51
32:   0x57dd84 - main
33: 0x76ca1294 - __libc_start_main
[Vollibrespot] : EventSender disconnected
[SpotifyConnect] <PlaybackInactive> Device palyback is inactive
[SpotifyConnect] Device Session is_active: true
[SpotifyConnect] <SinkInactive> Sink released
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
volspotconnect2.service holdoff time over, scheduling restart.
Stopping Volspotconnect2 Daemon...
Starting Volspotconnect2 Daemon...
Started Volspotconnect2 Daemon.
vollibrespot v0.2.2 cd96399 2020-10-07 (librespot 08d8bcc 2020-10-07) -- Built On 2020-10-07
Reading Config from "volspotify.toml"
[Vollibrespot] : Using Alsa backend with device: plughw:2
[Vollibrespot] : Failed to register IPv6 receiver: Os { code: 19, kind: Other, message: "No such device" }
^C

root@rotate:/home/volumio# 

Volumio version: 2.863 20 Nov
Rpi 3+, Allo Katana DAC with Digital mixer, touch sreen plug-in added.

Looks like there was a dropped network connection, try restarting the service?

systemctl restart volspotconnect2

Now this was solved, perhaps because Spotify server started again.
Sorry for noisy post, but we need to notify this kind of situation can be happen.

best,
Masaki