-- Logs begin at Sun 2025-08-31 18:40:32 UTC, end at Fri 2025-09-05 16:30:45 UTC. --
Sep 05 16:29:06 volumio volumio[18752]: [Vollibrespot] : Connecting to AP "ap-gew1.spotify.com:443"
Sep 05 16:29:07 volumio volumio[18752]: [Vollibrespot] : Authenticated as "sb5sm3342cv0bvrcgkuaraeib" !
Sep 05 16:29:07 volumio volumio[18752]: [Vollibrespot] : Setting up new mixer: card:hw:1 mixer:Digital index:0
Sep 05 16:29:07 volumio volumio[18752]: [Vollibrespot] : Alsa min-db is not SND_CTL_TLV_DB_GAIN_MUTE!!
Sep 05 16:29:07 volumio volumio[18752]: [Vollibrespot] : Alsa Mixer info min: 0 (MilliBel(0)[dB]) -- max: 230 (MilliBel(0)[dB]) HW: false
Sep 05 16:29:07 volumio volumio[18752]: [Vollibrespot] : Switching to linear volume mapping, control range: MilliBel(0)
Sep 05 16:29:07 volumio volumio[18752]: [Vollibrespot] : Alsa min-db is not SND_CTL_TLV_DB_GAIN_MUTE!!
Sep 05 16:29:07 volumio volumio[18752]: [Vollibrespot] : Using alsa sink
Sep 05 16:29:07 volumio volumio[18752]: [Vollibrespot] : Metadata pipe established
Sep 05 16:29:07 volumio volumio[18752]: [Vollibrespot] : Country: "UA"
Sep 05 16:29:07 volumio volumio[18752]: [Vollibrespot] : Event: Volume { volume_to_mixer: 0 }
Sep 05 16:29:07 volumio volumio[869]: [SpotifyConnect] 0
Sep 05 16:29:07 volumio volumio[869]: [SpotifyConnect] Volume: Spotify:0 Volumio: 0
Sep 05 16:29:07 volumio volumio[869]: info: CoreStateMachine::pushState
Sep 05 16:29:07 volumio volumio[869]: info: CoreStateMachine::getState
Sep 05 16:29:07 volumio volumio[869]: info: CoreCommandRouter::volumioPushState
Sep 05 16:29:07 volumio volumio[869]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Sep 05 16:29:07 volumio sudo[18777]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Sep 05 16:29:07 volumio sudo[18777]: pam_unix(sudo:session): session opened for user root by (uid=0)
Sep 05 16:29:07 volumio sudo[18777]: pam_unix(sudo:session): session closed for user root
Sep 05 16:29:07 volumio volumio[18752]: [Vollibrespot] : Fetching autoplay context uri
Sep 05 16:29:07 volumio volumio[18752]: [Vollibrespot] : Event: SessionActive { became_active_at: 1757089747369 }
Sep 05 16:29:07 volumio volumio[18752]: [Vollibrespot] : SessionActive!
Sep 05 16:29:07 volumio volumio[18752]: [Vollibrespot] : Event: PlaybackStarted { track_id: SpotifyId { id: 335000367231854107027198426294870179242, audio_type: Track } }
Sep 05 16:29:07 volumio volumio[18752]: [Vollibrespot] : Event: PlaybackLoading { track_id: SpotifyId { id: 335000367231854107027198426294870179242, audio_type: Track } }
Sep 05 16:29:07 volumio volumio[869]: [SpotifyConnect] A connect session has begun
Sep 05 16:29:07 volumio volumio[869]: [SpotifyConnect] Device palyback is active!
Sep 05 16:29:07 volumio volumio[869]: info: CoreCommandRouter::volumioGetState
Sep 05 16:29:07 volumio volumio[869]: info: CoreStateMachine::getState
Sep 05 16:29:07 volumio volumio[869]: [SpotifyConnect] Currently active: volspotconnect2
Sep 05 16:29:07 volumio volumio[869]: [SpotifyConnect] Not requsting volumioStop on our own service
Sep 05 16:29:07 volumio volumio[869]: [SpotifyConnect] Vollibrespot Active
Sep 05 16:29:07 volumio volumio[869]: info: CoreCommandRouter::volumioGetState
Sep 05 16:29:07 volumio volumio[869]: info: CoreStateMachine::getState
Sep 05 16:29:07 volumio volumio[869]: [SpotifyConnect] Currently active: volspotconnect2
Sep 05 16:29:07 volumio volumio[869]: info: CoreCommandRouter::servicePushState
Sep 05 16:29:07 volumio volumio[869]: info: CoreStateMachine::syncState
Sep 05 16:29:07 volumio volumio[869]: info: CoreStateMachine::pushState
Sep 05 16:29:07 volumio volumio[869]: info: CoreStateMachine::getState
Sep 05 16:29:07 volumio volumio[869]: info: CoreCommandRouter::volumioPushState
Sep 05 16:29:07 volumio volumio[18752]: [Vollibrespot] : error 403 for uri hm://keymaster/token/authenticated?client_id=4ced2e7c73484127be5d36015752eb43&scope=streaming,user-read-playback-state,user-modify-playback-state,user-read-currently-playing,user-read-private
Sep 05 16:29:07 volumio volumio[18752]: [Vollibrespot] : Error: MercuryError
Sep 05 16:29:07 volumio volumio[18752]: thread 'main' panicked at 'cannot poll Map twice', /build/cache/registry/src/github.com-1ecc6299db9ec823/futures-0.1.29/src/future/map.rs:35:29
Sep 05 16:29:07 volumio volumio[18752]: stack backtrace:
Sep 05 16:29:07 volumio volumio[869]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Sep 05 16:29:07 volumio volumio[869]: info: CoreCommandRouter::volumioGetState
Sep 05 16:29:07 volumio volumio[869]: info: CoreStateMachine::getState
Sep 05 16:29:07 volumio volumio[869]: [SpotifyConnect] Currently active: volspotconnect2
Sep 05 16:29:07 volumio volumio[869]: [SpotifyConnect] Pushing new state :: true
Sep 05 16:29:07 volumio volumio[869]: info: CoreCommandRouter::servicePushState
Sep 05 16:29:07 volumio volumio[869]: info: CoreStateMachine::syncState
Sep 05 16:29:07 volumio volumio[869]: info: CoreStateMachine::pushState
Sep 05 16:29:07 volumio volumio[869]: info: CoreStateMachine::getState
Sep 05 16:29:07 volumio volumio[869]: info: CoreCommandRouter::volumioPushState
Sep 05 16:29:07 volumio volumio[869]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Sep 05 16:29:07 volumio sudo[18789]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Sep 05 16:29:07 volumio sudo[18789]: pam_unix(sudo:session): session opened for user root by (uid=0)
Sep 05 16:29:07 volumio sudo[18789]: pam_unix(sudo:session): session closed for user root
Sep 05 16:29:07 volumio sudo[18793]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Sep 05 16:29:07 volumio sudo[18793]: pam_unix(sudo:session): session opened for user root by (uid=0)
Sep 05 16:29:07 volumio sudo[18793]: pam_unix(sudo:session): session closed for user root
Sep 05 16:29:07 volumio volumio[18752]: 0: 0x9d333c - backtrace::backtrace::libunwind::trace::hae21a072c81e5842
Sep 05 16:29:07 volumio volumio[18752]: at /cargo/registry/src/github.com-1ecc6299db9ec823/backtrace-0.3.46/src/backtrace/libunwind.rs:86
Sep 05 16:29:07 volumio volumio[18752]: 1: 0x9d333c - backtrace::backtrace::trace_unsynchronized::h0f9b260087e46e47
Sep 05 16:29:07 volumio volumio[18752]: at /cargo/registry/src/github.com-1ecc6299db9ec823/backtrace-0.3.46/src/backtrace/mod.rs:66
Sep 05 16:29:07 volumio volumio[18752]: 2: 0x9d333c - std::sys_common::backtrace::_print_fmt::hbf1a59173a7860c3
Sep 05 16:29:07 volumio volumio[18752]: at src/libstd/sys_common/backtrace.rs:78
Sep 05 16:29:07 volumio volumio[18752]: 3: 0x9d333c - ::fmt::he1a5d6f378e506c4
Sep 05 16:29:07 volumio volumio[18752]: at src/libstd/sys_common/backtrace.rs:59
Sep 05 16:29:07 volumio volumio[18752]: 4: 0x9f3d5c - core::fmt::write::hb37ae5a5e0b70623
Sep 05 16:29:07 volumio volumio[18752]: at src/libcore/fmt/mod.rs:1076
Sep 05 16:29:07 volumio volumio[18752]: 5: 0x9ccc64 - std::io::Write::write_fmt::ha24bb3f5a858327b
Sep 05 16:29:07 volumio volumio[18752]: at src/libstd/io/mod.rs:1537
Sep 05 16:29:07 volumio volumio[18752]: 6: 0x9d5974 - std::sys_common::backtrace::_print::h47b03aa1342833e3
Sep 05 16:29:07 volumio volumio[18752]: at src/libstd/sys_common/backtrace.rs:62
Sep 05 16:29:07 volumio volumio[18752]: 7: 0x9d5974 - std::sys_common::backtrace::print::h2217cbc390250439
Sep 05 16:29:07 volumio volumio[18752]: at src/libstd/sys_common/backtrace.rs:49
Sep 05 16:29:07 volumio volumio[18752]: 8: 0x9d5974 - std::panicking::default_hook::{{closure}}::h179f5229ea1c8e30
Sep 05 16:29:07 volumio volumio[18752]: at src/libstd/panicking.rs:198
Sep 05 16:29:07 volumio volumio[18752]: 9: 0x9d5640 - std::panicking::default_hook::h46ab82039cbc65eb
Sep 05 16:29:07 volumio volumio[18752]: at src/libstd/panicking.rs:217
Sep 05 16:29:07 volumio volumio[18752]: 10: 0x9d6054 - std::panicking::rust_panic_with_hook::h7326c48419bc7c33
Sep 05 16:29:07 volumio volumio[18752]: at src/libstd/panicking.rs:526
Sep 05 16:29:07 volumio volumio[18752]: 11: 0x9d5c54 - rust_begin_unwind
Sep 05 16:29:07 volumio volumio[18752]: at src/libstd/panicking.rs:437
Sep 05 16:29:07 volumio volumio[18752]: 12: 0x9f1594 - core::panicking::panic_fmt::ha292e19d5ae716ed
Sep 05 16:29:07 volumio volumio[18752]: at src/libcore/panicking.rs:85
Sep 05 16:29:07 volumio volumio[18752]: 13: 0x9f1370 - core::option::expect_failed::he9e39f8f5ba60ecb
Sep 05 16:29:07 volumio volumio[18752]: at src/libcore/option.rs:1261
Sep 05 16:29:07 volumio volumio[18752]: 14: 0x6c7bf8 - as futures::future::Future>::poll::h3d56b212ca27d9e4
Sep 05 16:29:07 volumio volumio[18752]: 15: 0x57d3a4 - ::poll::ha2e91a6b75c719f3
Sep 05 16:29:07 volumio volumio[18752]: 16: 0x4f3ca4 - ::poll::hc5e7d2d1b7dbef13
Sep 05 16:29:07 volumio systemd[1]: volspotconnect2.service: main process exited, code=exited, status=101/n/a
Sep 05 16:29:07 volumio systemd[1]: Unit volspotconnect2.service entered failed state.
Sep 05 16:29:07 volumio volumio[18752]: 17: 0x4bb844 - futures::task_impl::std::set::h8f081cf0436110c9
Sep 05 16:29:07 volumio volumio[18752]: 18: 0x4cf41c - std::thread::local::LocalKey::with::h711a13323aafc45a
Sep 05 16:29:07 volumio volumio[18752]: 19: 0x4aba50 - tokio_current_thread::Entered::block_on::h339073902a399eb7
Sep 05 16:29:07 volumio volumio[18752]: 20: 0x4cfe00 - std::thread::local::LocalKey::with::hff64c13ccfec5327
Sep 05 16:29:07 volumio volumio[18752]: 21: 0x4dc20c - tokio_reactor::with_default::h7ef12e65cb103d2f
Sep 05 16:29:07 volumio volumio[18752]: 22: 0x4af9f8 - tokio::runtime::current_thread::runtime::Runtime::block_on::h043f136d6b8cf48f
Sep 05 16:29:07 volumio volumio[18752]: 23: 0x4f52c8 - vollibrespot::main::h02a0d49d4cc5eaa6
Sep 05 16:29:07 volumio volumio[18752]: 24: 0x4dcf18 - std::rt::lang_start::{{closure}}::h279cd2b7929fdba7
Sep 05 16:29:07 volumio volumio[18752]: 25: 0x9d6404 - std::rt::lang_start_internal::{{closure}}::he93bfc404849b78a
Sep 05 16:29:07 volumio volumio[18752]: at src/libstd/rt.rs:52
Sep 05 16:29:07 volumio volumio[18752]: 26: 0x9d6404 - std::panicking::try::do_call::h6e9e98f4078affb0
Sep 05 16:29:07 volumio volumio[18752]: at src/libstd/panicking.rs:348
Sep 05 16:29:07 volumio volumio[18752]: 27: 0x9d6404 - std::panicking::try::h2e68d4f7f799a6df
Sep 05 16:29:07 volumio volumio[18752]: at src/libstd/panicking.rs:325
Sep 05 16:29:07 volumio volumio[18752]: 28: 0x9d6404 - std::panic::catch_unwind::h8880a4c07cc66391
Sep 05 16:29:07 volumio volumio[18752]: at src/libstd/panic.rs:394
Sep 05 16:29:07 volumio volumio[18752]: 29: 0x9d6404 - std::rt::lang_start_internal::hf4ae2140248bf16b
Sep 05 16:29:07 volumio volumio[18752]: at src/libstd/rt.rs:51
Sep 05 16:29:07 volumio volumio[18752]: 30: 0x4f5d84 - main
Sep 05 16:29:07 volumio volumio[18752]: 31: 0x76cc7294 - __libc_start_main
Sep 05 16:29:07 volumio volumio[18752]: [Vollibrespot] : EventSender disconnected
Sep 05 16:29:07 volumio volumio[869]: [SpotifyConnect] Device palyback is inactive
Sep 05 16:29:07 volumio volumio[869]: [SpotifyConnect] Device Session is_active: true
Sep 05 16:29:07 volumio volumio[869]: [SpotifyConnect] Sink released
Sep 05 16:29:07 volumio volumio[869]: info: CoreCommandRouter::servicePushState
Sep 05 16:29:07 volumio volumio[869]: info: CoreStateMachine::syncState
Sep 05 16:29:07 volumio volumio[869]: info: CoreStateMachine::pushState
Sep 05 16:29:07 volumio volumio[869]: info: CoreStateMachine::getState
Sep 05 16:29:07 volumio volumio[869]: info: CoreCommandRouter::volumioPushState
Sep 05 16:29:07 volumio volumio[869]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Sep 05 16:29:07 volumio sudo[18812]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Sep 05 16:29:07 volumio sudo[18812]: pam_unix(sudo:session): session opened for user root by (uid=0)
Sep 05 16:29:07 volumio sudo[18812]: pam_unix(sudo:session): session closed for user root
Sep 05 16:29:09 volumio systemd[1]: volspotconnect2.service holdoff time over, scheduling restart.
Sep 05 16:29:09 volumio systemd[1]: Stopping Volspotconnect2 Daemon...
Sep 05 16:29:09 volumio systemd[1]: Starting Volspotconnect2 Daemon...
Sep 05 16:29:09 volumio systemd[1]: Started Volspotconnect2 Daemon.
Sep 05 16:29:09 volumio volumio[18827]: vollibrespot v0.2.2 cd96399 2020-10-07 (librespot 08d8bcc 2020-10-07) -- Built On 2020-10-07
Sep 05 16:29:09 volumio volumio[18827]: Reading Config from "volspotify.toml"
Sep 05 16:29:09 volumio volumio[18827]: [Vollibrespot] : Using Alsa backend with device: plughw:1
Sep 05 16:29:09 volumio volumio[18827]: [Vollibrespot] : Failed to register IPv6 receiver: Os { code: 19, kind: Other, message: "No such device" }
Sep 05 16:29:14 volumio sudo[18840]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Sep 05 16:29:14 volumio sudo[18840]: pam_unix(sudo:session): session opened for user root by (uid=0)
Sep 05 16:29:14 volumio sudo[18842]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Sep 05 16:29:14 volumio sudo[18842]: pam_unix(sudo:session): session opened for user root by (uid=0)
Sep 05 16:29:14 volumio sudo[18840]: pam_unix(sudo:session): session closed for user root
Sep 05 16:29:14 volumio sudo[18842]: pam_unix(sudo:session): session closed for user root
Sep 05 16:29:15 volumio volumio[869]: info: CoreCommandRouter::volumioGetVisibleSources
Sep 05 16:29:15 volumio volumio[869]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Sep 05 16:29:15 volumio volumio[869]: info: CoreCommandRouter::volumioGetState
Sep 05 16:29:15 volumio volumio[869]: info: CoreStateMachine::getState
Sep 05 16:29:15 volumio volumio[869]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings
Sep 05 16:29:15 volumio volumio[869]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Sep 05 16:29:15 volumio volumio[869]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard
Sep 05 16:29:15 volumio volumio[869]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard
Sep 05 16:29:15 volumio volumio[869]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom
Sep 05 16:29:15 volumio sudo[18863]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Sep 05 16:29:15 volumio volumio[869]: error: Could not retrieve plugin audio_interface multiroom
Sep 05 16:29:15 volumio volumio[869]: info: Listing playlists
Sep 05 16:29:15 volumio sudo[18865]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Sep 05 16:29:15 volumio sudo[18863]: pam_unix(sudo:session): session opened for user root by (uid=0)
Sep 05 16:29:15 volumio sudo[18865]: pam_unix(sudo:session): session opened for user root by (uid=0)
Sep 05 16:29:15 volumio volumio[869]: info: No input data
Sep 05 16:29:15 volumio sudo[18863]: pam_unix(sudo:session): session closed for user root
Sep 05 16:29:15 volumio sudo[18865]: pam_unix(sudo:session): session closed for user root
Sep 05 16:29:21 volumio volumio[18827]: [Vollibrespot] : Connecting to AP "ap-gew1.spotify.com:443"
Sep 05 16:29:22 volumio volumio[18827]: [Vollibrespot] : Authenticated as "sb5sm3342cv0bvrcgkuaraeib" !
Sep 05 16:29:22 volumio volumio[18827]: [Vollibrespot] : Setting up new mixer: card:hw:1 mixer:Digital index:0
Sep 05 16:29:22 volumio volumio[18827]: [Vollibrespot] : Alsa min-db is not SND_CTL_TLV_DB_GAIN_MUTE!!
Sep 05 16:29:22 volumio volumio[18827]: [Vollibrespot] : Alsa Mixer info min: 0 (MilliBel(0)[dB]) -- max: 230 (MilliBel(0)[dB]) HW: false
Sep 05 16:29:22 volumio volumio[18827]: [Vollibrespot] : Switching to linear volume mapping, control range: MilliBel(0)
Sep 05 16:29:22 volumio volumio[18827]: [Vollibrespot] : Alsa min-db is not SND_CTL_TLV_DB_GAIN_MUTE!!
Sep 05 16:29:22 volumio volumio[18827]: [Vollibrespot] : Using alsa sink
Sep 05 16:29:22 volumio volumio[18827]: [Vollibrespot] : Metadata pipe established
Sep 05 16:29:22 volumio volumio[18827]: [Vollibrespot] : Country: "UA"
Sep 05 16:29:22 volumio volumio[18827]: [Vollibrespot] : Event: Volume { volume_to_mixer: 0 }
Sep 05 16:29:22 volumio volumio[869]: [SpotifyConnect] 0
Sep 05 16:29:22 volumio volumio[869]: [SpotifyConnect] Volume: Spotify:0 Volumio: 0
Sep 05 16:29:22 volumio volumio[869]: info: CoreStateMachine::pushState
Sep 05 16:29:22 volumio volumio[869]: info: CoreStateMachine::getState
Sep 05 16:29:22 volumio volumio[869]: info: CoreCommandRouter::volumioPushState
Sep 05 16:29:22 volumio volumio[869]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Sep 05 16:29:22 volumio sudo[18905]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Sep 05 16:29:22 volumio sudo[18905]: pam_unix(sudo:session): session opened for user root by (uid=0)
Sep 05 16:29:22 volumio sudo[18905]: pam_unix(sudo:session): session closed for user root
Sep 05 16:29:22 volumio volumio[18827]: [Vollibrespot] : Fetching autoplay context uri
Sep 05 16:29:22 volumio volumio[18827]: [Vollibrespot] : Event: SessionActive { became_active_at: 1757089762321 }
Sep 05 16:29:22 volumio volumio[18827]: [Vollibrespot] : SessionActive!
Sep 05 16:29:22 volumio volumio[18827]: [Vollibrespot] : Event: PlaybackStarted { track_id: SpotifyId { id: 335000367231854107027198426294870179242, audio_type: Track } }
Sep 05 16:29:22 volumio volumio[18827]: [Vollibrespot] : Event: PlaybackLoading { track_id: SpotifyId { id: 335000367231854107027198426294870179242, audio_type: Track } }
Sep 05 16:29:22 volumio volumio[869]: [SpotifyConnect] A connect session has begun
Sep 05 16:29:22 volumio volumio[869]: [SpotifyConnect] Device palyback is active!
Sep 05 16:29:22 volumio volumio[869]: info: CoreCommandRouter::volumioGetState
Sep 05 16:29:22 volumio volumio[869]: info: CoreStateMachine::getState
Sep 05 16:29:22 volumio volumio[869]: [SpotifyConnect] Currently active: volspotconnect2
Sep 05 16:29:22 volumio volumio[869]: [SpotifyConnect] Not requsting volumioStop on our own service
Sep 05 16:29:22 volumio volumio[869]: [SpotifyConnect] Vollibrespot Active
Sep 05 16:29:22 volumio volumio[869]: info: CoreCommandRouter::volumioGetState
Sep 05 16:29:22 volumio volumio[869]: info: CoreStateMachine::getState
Sep 05 16:29:22 volumio volumio[869]: [SpotifyConnect] Currently active: volspotconnect2
Sep 05 16:29:22 volumio volumio[869]: info: CoreCommandRouter::servicePushState
Sep 05 16:29:22 volumio volumio[869]: info: CoreStateMachine::syncState
Sep 05 16:29:22 volumio volumio[869]: info: CoreStateMachine::pushState
Sep 05 16:29:22 volumio volumio[869]: info: CoreStateMachine::getState
Sep 05 16:29:22 volumio volumio[869]: info: CoreCommandRouter::volumioPushState
Sep 05 16:29:22 volumio volumio[869]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Sep 05 16:29:22 volumio volumio[18827]: [Vollibrespot] : error 403 for uri hm://keymaster/token/authenticated?client_id=4ced2e7c73484127be5d36015752eb43&scope=streaming,user-read-playback-state,user-modify-playback-state,user-read-currently-playing,user-read-private
Sep 05 16:29:22 volumio volumio[18827]: [Vollibrespot] : Error: MercuryError
Sep 05 16:29:22 volumio volumio[18827]: thread 'main' panicked at 'cannot poll Map twice', /build/cache/registry/src/github.com-1ecc6299db9ec823/futures-0.1.29/src/future/map.rs:35:29
Sep 05 16:29:22 volumio volumio[18827]: stack backtrace:
Sep 05 16:29:22 volumio volumio[869]: info: CoreCommandRouter::volumioGetState
Sep 05 16:29:22 volumio volumio[869]: info: CoreStateMachine::getState
Sep 05 16:29:22 volumio volumio[869]: [SpotifyConnect] Currently active: volspotconnect2
Sep 05 16:29:22 volumio volumio[869]: [SpotifyConnect] Pushing new state :: true
Sep 05 16:29:22 volumio volumio[869]: info: CoreCommandRouter::servicePushState
Sep 05 16:29:22 volumio volumio[869]: info: CoreStateMachine::syncState
Sep 05 16:29:22 volumio volumio[869]: info: CoreStateMachine::pushState
Sep 05 16:29:22 volumio volumio[869]: info: CoreStateMachine::getState
Sep 05 16:29:22 volumio volumio[869]: info: CoreCommandRouter::volumioPushState
Sep 05 16:29:22 volumio volumio[869]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Sep 05 16:29:22 volumio sudo[18917]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Sep 05 16:29:22 volumio sudo[18917]: pam_unix(sudo:session): session opened for user root by (uid=0)
Sep 05 16:29:22 volumio sudo[18917]: pam_unix(sudo:session): session closed for user root
Sep 05 16:29:22 volumio sudo[18925]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Sep 05 16:29:22 volumio sudo[18925]: pam_unix(sudo:session): session opened for user root by (uid=0)
Sep 05 16:29:22 volumio sudo[18925]: pam_unix(sudo:session): session closed for user root
Sep 05 16:29:22 volumio volumio[18827]: 0: 0xa1b33c - backtrace::backtrace::libunwind::trace::hae21a072c81e5842
Sep 05 16:29:22 volumio volumio[18827]: at /cargo/registry/src/github.com-1ecc6299db9ec823/backtrace-0.3.46/src/backtrace/libunwind.rs:86
Sep 05 16:29:22 volumio volumio[18827]: 1: 0xa1b33c - backtrace::backtrace::trace_unsynchronized::h0f9b260087e46e47
Sep 05 16:29:22 volumio volumio[18827]: at /cargo/registry/src/github.com-1ecc6299db9ec823/backtrace-0.3.46/src/backtrace/mod.rs:66
Sep 05 16:29:22 volumio volumio[18827]: 2: 0xa1b33c - std::sys_common::backtrace::_print_fmt::hbf1a59173a7860c3
Sep 05 16:29:22 volumio volumio[18827]: at src/libstd/sys_common/backtrace.rs:78
Sep 05 16:29:22 volumio volumio[18827]: 3: 0xa1b33c - ::fmt::he1a5d6f378e506c4
Sep 05 16:29:22 volumio volumio[18827]: at src/libstd/sys_common/backtrace.rs:59
Sep 05 16:29:22 volumio volumio[18827]: 4: 0xa3bd5c - core::fmt::write::hb37ae5a5e0b70623
Sep 05 16:29:22 volumio volumio[18827]: at src/libcore/fmt/mod.rs:1076
Sep 05 16:29:22 volumio volumio[18827]: 5: 0xa14c64 - std::io::Write::write_fmt::ha24bb3f5a858327b
Sep 05 16:29:22 volumio volumio[18827]: at src/libstd/io/mod.rs:1537
Sep 05 16:29:22 volumio volumio[18827]: 6: 0xa1d974 - std::sys_common::backtrace::_print::h47b03aa1342833e3
Sep 05 16:29:22 volumio volumio[18827]: at src/libstd/sys_common/backtrace.rs:62
Sep 05 16:29:22 volumio volumio[18827]: 7: 0xa1d974 - std::sys_common::backtrace::print::h2217cbc390250439
Sep 05 16:29:22 volumio volumio[18827]: at src/libstd/sys_common/backtrace.rs:49
Sep 05 16:29:22 volumio volumio[18827]: 8: 0xa1d974 - std::panicking::default_hook::{{closure}}::h179f5229ea1c8e30
Sep 05 16:29:22 volumio volumio[18827]: at src/libstd/panicking.rs:198
Sep 05 16:29:22 volumio volumio[18827]: 9: 0xa1d640 - std::panicking::default_hook::h46ab82039cbc65eb
Sep 05 16:29:22 volumio volumio[18827]: at src/libstd/panicking.rs:217
Sep 05 16:29:22 volumio volumio[18827]: 10: 0xa1e054 - std::panicking::rust_panic_with_hook::h7326c48419bc7c33
Sep 05 16:29:22 volumio volumio[18827]: at src/libstd/panicking.rs:526
Sep 05 16:29:22 volumio volumio[18827]: 11: 0xa1dc54 - rust_begin_unwind
Sep 05 16:29:22 volumio volumio[18827]: at src/libstd/panicking.rs:437
Sep 05 16:29:22 volumio volumio[18827]: 12: 0xa39594 - core::panicking::panic_fmt::ha292e19d5ae716ed
Sep 05 16:29:22 volumio volumio[18827]: at src/libcore/panicking.rs:85
Sep 05 16:29:22 volumio volumio[18827]: 13: 0xa39370 - core::option::expect_failed::he9e39f8f5ba60ecb
Sep 05 16:29:22 volumio volumio[18827]: at src/libcore/option.rs:1261
Sep 05 16:29:22 volumio volumio[18827]: 14: 0x70fbf8 - as futures::future::Future>::poll::h3d56b212ca27d9e4
Sep 05 16:29:22 volumio volumio[18827]: 15: 0x5c53a4 - ::poll::ha2e91a6b75c719f3
Sep 05 16:29:22 volumio volumio[18827]: 16: 0x53bca4 - ::poll::hc5e7d2d1b7dbef13
Sep 05 16:29:22 volumio volumio[18827]: 17: 0x503844 - futures::task_impl::std::set::h8f081cf0436110c9
Sep 05 16:29:22 volumio volumio[18827]: 18: 0x51741c - std::thread::local::LocalKey::with::h711a13323aafc45a
Sep 05 16:29:22 volumio systemd[1]: volspotconnect2.service: main process exited, code=exited, status=101/n/a
Sep 05 16:29:22 volumio systemd[1]: Unit volspotconnect2.service entered failed state.
Sep 05 16:29:22 volumio volumio[18827]: 19: 0x4f3a50 - tokio_current_thread::Entered::block_on::h339073902a399eb7
Sep 05 16:29:22 volumio volumio[18827]: 20: 0x517e00 - std::thread::local::LocalKey::with::hff64c13ccfec5327
Sep 05 16:29:22 volumio volumio[18827]: 21: 0x52420c - tokio_reactor::with_default::h7ef12e65cb103d2f
Sep 05 16:29:22 volumio volumio[18827]: 22: 0x4f79f8 - tokio::runtime::current_thread::runtime::Runtime::block_on::h043f136d6b8cf48f
Sep 05 16:29:22 volumio volumio[18827]: 23: 0x53d2c8 - vollibrespot::main::h02a0d49d4cc5eaa6
Sep 05 16:29:22 volumio volumio[18827]: 24: 0x524f18 - std::rt::lang_start::{{closure}}::h279cd2b7929fdba7
Sep 05 16:29:22 volumio volumio[18827]: 25: 0xa1e404 - std::rt::lang_start_internal::{{closure}}::he93bfc404849b78a
Sep 05 16:29:22 volumio volumio[18827]: at src/libstd/rt.rs:52
Sep 05 16:29:22 volumio volumio[18827]: 26: 0xa1e404 - std::panicking::try::do_call::h6e9e98f4078affb0
Sep 05 16:29:22 volumio volumio[18827]: at src/libstd/panicking.rs:348
Sep 05 16:29:22 volumio volumio[18827]: 27: 0xa1e404 - std::panicking::try::h2e68d4f7f799a6df
Sep 05 16:29:22 volumio volumio[18827]: at src/libstd/panicking.rs:325
Sep 05 16:29:22 volumio volumio[18827]: 28: 0xa1e404 - std::panic::catch_unwind::h8880a4c07cc66391
Sep 05 16:29:22 volumio volumio[18827]: at src/libstd/panic.rs:394
Sep 05 16:29:22 volumio volumio[18827]: 29: 0xa1e404 - std::rt::lang_start_internal::hf4ae2140248bf16b
Sep 05 16:29:22 volumio volumio[18827]: at src/libstd/rt.rs:51
Sep 05 16:29:22 volumio volumio[18827]: 30: 0x53dd84 - main
Sep 05 16:29:22 volumio volumio[18827]: 31: 0x76c95294 - __libc_start_main
Sep 05 16:29:22 volumio volumio[18827]: [Vollibrespot] : EventSender disconnected
Sep 05 16:29:22 volumio volumio[869]: [SpotifyConnect] Device palyback is inactive
Sep 05 16:29:22 volumio volumio[869]: [SpotifyConnect] Device Session is_active: true
Sep 05 16:29:22 volumio volumio[869]: [SpotifyConnect] Sink released
Sep 05 16:29:22 volumio volumio[869]: info: CoreCommandRouter::servicePushState
Sep 05 16:29:22 volumio volumio[869]: info: CoreStateMachine::syncState
Sep 05 16:29:22 volumio volumio[869]: info: CoreStateMachine::pushState
Sep 05 16:29:22 volumio volumio[869]: info: CoreStateMachine::getState
Sep 05 16:29:22 volumio volumio[869]: info: CoreCommandRouter::volumioPushState
Sep 05 16:29:22 volumio volumio[869]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Sep 05 16:29:22 volumio sudo[18942]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Sep 05 16:29:22 volumio sudo[18942]: pam_unix(sudo:session): session opened for user root by (uid=0)
Sep 05 16:29:22 volumio sudo[18942]: pam_unix(sudo:session): session closed for user root
Sep 05 16:29:24 volumio systemd[1]: volspotconnect2.service holdoff time over, scheduling restart.
Sep 05 16:29:24 volumio systemd[1]: Stopping Volspotconnect2 Daemon...
Sep 05 16:29:24 volumio systemd[1]: Starting Volspotconnect2 Daemon...
Sep 05 16:29:24 volumio systemd[1]: Started Volspotconnect2 Daemon.
Sep 05 16:29:24 volumio volumio[18956]: vollibrespot v0.2.2 cd96399 2020-10-07 (librespot 08d8bcc 2020-10-07) -- Built On 2020-10-07
Sep 05 16:29:24 volumio volumio[18956]: Reading Config from "volspotify.toml"
Sep 05 16:29:24 volumio volumio[18956]: [Vollibrespot] : Using Alsa backend with device: plughw:1
Sep 05 16:29:24 volumio volumio[18956]: [Vollibrespot] : Failed to register IPv6 receiver: Os { code: 19, kind: Other, message: "No such device" }
Sep 05 16:29:27 volumio volumio[869]: info: VolumeController::SetAlsaVolume92
Sep 05 16:29:27 volumio volumio[869]: info: CoreStateMachine::pushState
Sep 05 16:29:27 volumio volumio[869]: info: CoreStateMachine::getState
Sep 05 16:29:27 volumio volumio[869]: info: CoreCommandRouter::volumioPushState
Sep 05 16:29:27 volumio volumio[869]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Sep 05 16:29:27 volumio sudo[18966]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Sep 05 16:29:28 volumio sudo[18966]: pam_unix(sudo:session): session opened for user root by (uid=0)
Sep 05 16:29:28 volumio sudo[18966]: pam_unix(sudo:session): session closed for user root
Sep 05 16:29:29 volumio volumio[869]: info: VolumeController::SetAlsaVolume94
Sep 05 16:29:29 volumio volumio[869]: info: CoreStateMachine::pushState
Sep 05 16:29:29 volumio volumio[869]: info: CoreStateMachine::getState
Sep 05 16:29:29 volumio volumio[869]: info: CoreCommandRouter::volumioPushState
Sep 05 16:29:29 volumio volumio[869]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Sep 05 16:29:29 volumio sudo[18980]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Sep 05 16:29:29 volumio sudo[18980]: pam_unix(sudo:session): session opened for user root by (uid=0)
Sep 05 16:29:29 volumio sudo[18980]: pam_unix(sudo:session): session closed for user root
Sep 05 16:29:30 volumio volumio[869]: info: CoreCommandRouter::volumioVolatilePlay
Sep 05 16:29:30 volumio volumio[869]: info: CoreStateMachine::volatilePlay
Sep 05 16:29:30 volumio volumio[869]: [SpotifyConnect] Received play:
Sep 05 16:29:30 volumio volumio[869]: [SpotifyConnect] Unauthorized
Sep 05 16:29:30 volumio volumio[869]: (node:869) UnhandledPromiseRejectionWarning
Sep 05 16:29:30 volumio volumio[869]: (node:869) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). (rejection id: 1)
Sep 05 16:29:30 volumio volumio[869]: (node:869) [DEP0018] DeprecationWarning: Unhandled promise rejections are deprecated. In the future, promise rejections that are not handled will terminate the Node.js process with a non-zero exit code.
Sep 05 16:29:39 volumio volumio[869]: info: [{"prettyName":"Spotify","name":"spop","category":"music_service","version":"3.0.3","icon":"fa-spotify","active":false},{"prettyName":"Volumio Spotify Connect2","name":"volspotconnect2","category":"music_service","version":"1.0.5","icon":"fa-spotify","enabled":true,"active":true}]
Sep 05 16:29:47 volumio volumio[869]: info: Starting Uninstall of plugin music_service - volspotconnect2
Sep 05 16:29:47 volumio volumio[869]: info: Uninstalling plugin volspotconnect2
Sep 05 16:29:47 volumio volumio[869]: [SpotifyConnect] Relinquishing Volumio State
Sep 05 16:29:47 volumio volumio[869]: UNSET VOLATILE
Sep 05 16:29:47 volumio volumio[869]: [SpotifyConnect] unSetVolatile called
Sep 05 16:29:47 volumio volumio[869]: [SpotifyConnect] Relinquishing Volumio State to another service
Sep 05 16:29:47 volumio volumio[869]: [SpotifyConnect] Received stop
Sep 05 16:29:47 volumio volumio[869]: [SpotifyConnect] Stopping Vollibrespot daemon
Sep 05 16:29:47 volumio volumio[869]: [SpotifyConnect] Closing metadata listener
Sep 05 16:29:47 volumio volumio[869]: info: CoreStateMachine::resetVolumioState
Sep 05 16:29:47 volumio volumio[869]: info: CoreStateMachine::getcurrentVolume
Sep 05 16:29:47 volumio volumio[869]: info: CoreCommandRouter::volumioRetrievevolume
Sep 05 16:29:47 volumio sudo[19028]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volspotconnect2.service
Sep 05 16:29:47 volumio volumio[869]: info: Disabling plugin volspotconnect2
Sep 05 16:29:47 volumio sudo[19028]: pam_unix(sudo:session): session opened for user root by (uid=0)
Sep 05 16:29:47 volumio volumio[869]: info: Checking if uninstall.sh is present
Sep 05 16:29:47 volumio volumio[869]: info: Executing uninstall.sh
Sep 05 16:29:47 volumio systemd[1]: Stopping Volspotconnect2 Daemon...
Sep 05 16:29:47 volumio systemd[1]: Stopped Volspotconnect2 Daemon.
Sep 05 16:29:48 volumio volumio[869]: info: VolumeController:: Volume=undefined Mute =false
Sep 05 16:29:48 volumio volumio[869]: info: CoreStateMachine::pushState
Sep 05 16:29:48 volumio volumio[869]: info: CoreStateMachine::getState
Sep 05 16:29:48 volumio volumio[869]: info: CorePlayQueue::getTrack 0
Sep 05 16:29:48 volumio sudo[19028]: pam_unix(sudo:session): session closed for user root
Sep 05 16:29:48 volumio volumio[869]: info: CoreCommandRouter::volumioPushState
Sep 05 16:29:48 volumio volumio[869]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Sep 05 16:29:48 volumio volumio[869]: [SpotifyConnect] Vollibrespot Daemon service stoped!
Sep 05 16:29:48 volumio sudo[19043]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Sep 05 16:29:48 volumio sudo[19043]: pam_unix(sudo:session): session opened for user root by (uid=0)
Sep 05 16:29:48 volumio sudo[19043]: pam_unix(sudo:session): session closed for user root
Sep 05 16:29:48 volumio sudo[19038]: pam_unix(sudo:auth): authentication failure; logname= uid=1000 euid=0 tty= ruser=volumio rhost= user=volumio
Sep 05 16:29:50 volumio sudo[19038]: pam_unix(sudo:auth): conversation failed
Sep 05 16:29:50 volumio sudo[19038]: pam_unix(sudo:auth): auth could not identify password for [volumio]
Sep 05 16:29:50 volumio sudo[19038]: volumio : 1 incorrect password attempt ; TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/sh /data/plugins/music_service/volspotconnect2/uninstall.sh
Sep 05 16:29:50 volumio volumio[869]: info: Uninstall script return the error Error: Command failed: echo volumio | sudo -S sh /data/plugins/music_service/volspotconnect2/uninstall.sh > /tmp/installog
Sep 05 16:29:50 volumio volumio[869]: [sudo] password for volumio: Sorry, try again.
Sep 05 16:29:50 volumio volumio[869]: [sudo] password for volumio:
Sep 05 16:29:50 volumio volumio[869]: sudo: 1 incorrect password attempt
Sep 05 16:29:56 volumio volumio[869]: [SpotifyConnect] Stopping Vollibrespot daemon
Sep 05 16:29:56 volumio volumio[869]: [SpotifyConnect] Closing metadata listener
Sep 05 16:29:56 volumio volumio[869]: [SpotifyConnect] Error stopping Vollibrespot daemon: Error [ERR_SOCKET_DGRAM_NOT_RUNNING]: Not running
Sep 05 16:29:56 volumio volumio[869]: at Socket._healthCheck (dgram.js:638:11)
Sep 05 16:29:56 volumio volumio[869]: at Socket.close (dgram.js:516:8)
Sep 05 16:29:56 volumio volumio[869]: at SpotConnEvents.close (/data/plugins/music_service/volspotconnect2/SpotConnController.js:112:21)
Sep 05 16:29:56 volumio volumio[869]: at ControllerVolspotconnect.onStop (/data/plugins/music_service/volspotconnect2/index.js:373:19)
Sep 05 16:29:56 volumio volumio[869]: at PluginManager.stopPlugin (/volumio/app/pluginmanager.js:370:27)
Sep 05 16:29:56 volumio volumio[869]: at PluginManager.disableAndStopPlugin (/volumio/app/pluginmanager.js:1719:7)
Sep 05 16:29:56 volumio volumio[869]: at CoreCommandRouter.disableAndStopPlugin (/volumio/app/index.js:1508:28)
Sep 05 16:29:56 volumio volumio[869]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:1311:44)
Sep 05 16:29:56 volumio volumio[869]: at emitTwo (events.js:126:13)
Sep 05 16:29:56 volumio volumio[869]: at Socket.emit (events.js:214:7)
Sep 05 16:29:56 volumio volumio[869]: at /volumio/node_modules/socket.io/lib/socket.js:503:12
Sep 05 16:29:56 volumio volumio[869]: at _combinedTickCallback (internal/process/next_tick.js:131:7)
Sep 05 16:29:56 volumio volumio[869]: at process._tickCallback (internal/process/next_tick.js:180:9)
Sep 05 16:29:56 volumio sudo[19077]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volspotconnect2.service
Sep 05 16:29:56 volumio volumio[869]: info: Disabling plugin volspotconnect2
Sep 05 16:29:56 volumio volumio[869]: info: Done.
Sep 05 16:29:56 volumio sudo[19077]: pam_unix(sudo:session): session opened for user root by (uid=0)
Sep 05 16:29:56 volumio systemd[1]: Stopped Volspotconnect2 Daemon.
Sep 05 16:29:56 volumio sudo[19077]: pam_unix(sudo:session): session closed for user root
Sep 05 16:29:56 volumio volumio[869]: [SpotifyConnect] Vollibrespot Daemon service stoped!
Sep 05 16:29:58 volumio volumio[869]: info: Enabling plugin volspotconnect2
Sep 05 16:29:58 volumio volumio[869]: info: Loading plugin "volspotconnect2"...
Sep 05 16:29:58 volumio volumio[869]: info: PLUGIN START: volspotconnect2
Sep 05 16:29:58 volumio volumio[869]: [SpotifyConnect] Creating VLS config file
Sep 05 16:29:58 volumio volumio[869]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 05 16:29:58 volumio volumio[869]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 05 16:29:58 volumio volumio[869]: [SpotifyConnect] Unimplemented debug mode!!
Sep 05 16:29:58 volumio volumio[869]: [SpotifyConnect] Starting metadata listener
Sep 05 16:29:58 volumio sudo[19088]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volspotconnect2.service
Sep 05 16:29:58 volumio sudo[19088]: pam_unix(sudo:session): session opened for user root by (uid=0)
Sep 05 16:29:58 volumio systemd[1]: Starting Volspotconnect2 Daemon...
Sep 05 16:29:58 volumio systemd[1]: Started Volspotconnect2 Daemon.
Sep 05 16:29:58 volumio sudo[19088]: pam_unix(sudo:session): session closed for user root
Sep 05 16:29:58 volumio volumio[19095]: vollibrespot v0.2.2 cd96399 2020-10-07 (librespot 08d8bcc 2020-10-07) -- Built On 2020-10-07
Sep 05 16:29:58 volumio volumio[19095]: Reading Config from "volspotify.toml"
Sep 05 16:29:58 volumio volumio[19095]: [Vollibrespot] : Using Alsa backend with device: plughw:1
Sep 05 16:29:58 volumio volumio[869]: [SpotifyConnect] Vollibrespot Daemon service started!
Sep 05 16:29:58 volumio volumio[869]: SpotifyConnect: 142.289ms
Sep 05 16:29:58 volumio volumio[869]: info: Done.
Sep 05 16:29:58 volumio volumio[19095]: [Vollibrespot] : Failed to register IPv6 receiver: Os { code: 19, kind: Other, message: "No such device" }
Sep 05 16:30:00 volumio volumio[869]: info: CoreCommandRouter::getUIConfigOnPlugin
Sep 05 16:30:00 volumio volumio[869]: [SpotifyConnect] config : toggling initvol/volume_ctrl
Sep 05 16:30:04 volumio volumio[869]: info: CALLMETHOD: music_service volspotconnect2 saveVolspotconnectAccount [object Object]
Sep 05 16:30:04 volumio volumio[869]: info: CoreCommandRouter::executeOnPlugin: volspotconnect2 , saveVolspotconnectAccount
Sep 05 16:30:04 volumio volumio[869]: [SpotifyConnect] Creating VLS config file
Sep 05 16:30:04 volumio volumio[869]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 05 16:30:04 volumio volumio[869]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 05 16:30:04 volumio volumio[869]: [SpotifyConnect] Unimplemented debug mode!!
Sep 05 16:30:04 volumio volumio[869]: [SpotifyConnect] Restarting Vollibrespot Daemon
Sep 05 16:30:04 volumio sudo[19111]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volspotconnect2.service
Sep 05 16:30:04 volumio sudo[19111]: pam_unix(sudo:session): session opened for user root by (uid=0)
Sep 05 16:30:04 volumio systemd[1]: Stopping Volspotconnect2 Daemon...
Sep 05 16:30:04 volumio systemd[1]: Starting Volspotconnect2 Daemon...
Sep 05 16:30:04 volumio systemd[1]: Started Volspotconnect2 Daemon.
Sep 05 16:30:04 volumio sudo[19111]: pam_unix(sudo:session): session closed for user root
Sep 05 16:30:04 volumio volumio[19117]: vollibrespot v0.2.2 cd96399 2020-10-07 (librespot 08d8bcc 2020-10-07) -- Built On 2020-10-07
Sep 05 16:30:04 volumio volumio[19117]: Reading Config from "volspotify.toml"
Sep 05 16:30:04 volumio volumio[19117]: [Vollibrespot] : Using Alsa backend with device: plughw:1
Sep 05 16:30:04 volumio volumio[869]: [SpotifyConnect] Vollibrespot Daemon service restarted!
Sep 05 16:30:04 volumio volumio[19117]: [Vollibrespot] : Failed to register IPv6 receiver: Os { code: 19, kind: Other, message: "No such device" }
Sep 05 16:30:06 volumio volumio[869]: info: [{"prettyName":"Spotify","name":"spop","category":"music_service","version":"3.0.3","icon":"fa-spotify","active":false},{"prettyName":"Volumio Spotify Connect2","name":"volspotconnect2","category":"music_service","version":"1.0.5","icon":"fa-spotify","enabled":true,"active":true}]
Sep 05 16:30:09 volumio volumio[869]: info: Enabling plugin spop
Sep 05 16:30:09 volumio volumio[869]: info: Loading plugin "spop"...
Sep 05 16:30:13 volumio volumio[869]: info: PLUGIN START: spop
Sep 05 16:30:13 volumio volumio[869]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Sep 05 16:30:13 volumio volumio[869]: [SpotifyConnect] Creating VLS config file
Sep 05 16:30:13 volumio volumio[869]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 05 16:30:13 volumio volumio[869]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 05 16:30:13 volumio volumio[869]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 05 16:30:13 volumio volumio[869]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 05 16:30:13 volumio volumio[869]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 05 16:30:13 volumio volumio[869]: [SpotifyConnect] Starting metadata listener
Sep 05 16:30:13 volumio sudo[19134]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/hosts
Sep 05 16:30:13 volumio sudo[19134]: pam_unix(sudo:session): session opened for user root by (uid=0)
Sep 05 16:30:13 volumio volumio[869]: [SpotifyConnect] Error: bind EADDRINUSE 0.0.0.0:5030
Sep 05 16:30:13 volumio volumio[869]: at Object._errnoException (util.js:1022:11)
Sep 05 16:30:13 volumio volumio[869]: at _exceptionWithHostPort (util.js:1044:20)
Sep 05 16:30:13 volumio volumio[869]: at _handle.lookup (dgram.js:266:18)
Sep 05 16:30:13 volumio volumio[869]: at _combinedTickCallback (internal/process/next_tick.js:141:11)
Sep 05 16:30:13 volumio volumio[869]: at process._tickCallback (internal/process/next_tick.js:180:9)
Sep 05 16:30:13 volumio volumio[869]: [SpotifyConnect] Error [ERR_SOCKET_CANNOT_SEND]: Unable to send data
Sep 05 16:30:13 volumio volumio[869]: at Socket.onListenError (dgram.js:362:22)
Sep 05 16:30:13 volumio volumio[869]: at Object.onceWrapper (events.js:315:30)
Sep 05 16:30:13 volumio volumio[869]: at emitOne (events.js:121:20)
Sep 05 16:30:13 volumio volumio[869]: at Socket.emit (events.js:211:7)
Sep 05 16:30:13 volumio volumio[869]: at _handle.lookup (dgram.js:267:14)
Sep 05 16:30:13 volumio volumio[869]: at _combinedTickCallback (internal/process/next_tick.js:141:11)
Sep 05 16:30:13 volumio volumio[869]: at process._tickCallback (internal/process/next_tick.js:180:9)
Sep 05 16:30:13 volumio sudo[19134]: pam_unix(sudo:session): session closed for user root
Sep 05 16:30:13 volumio sudo[19139]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volspotconnect.service
Sep 05 16:30:13 volumio volumio[869]: info: CoreCommandRouter::getUIConfigOnPlugin
Sep 05 16:30:13 volumio sudo[19139]: pam_unix(sudo:session): session opened for user root by (uid=0)
Sep 05 16:30:13 volumio systemd[1]: Starting Volspotconnect2 Daemon...
Sep 05 16:30:13 volumio systemd[1]: Started Volspotconnect2 Daemon.
Sep 05 16:30:13 volumio sudo[19139]: pam_unix(sudo:session): session closed for user root
Sep 05 16:30:13 volumio volumio[19150]: /usr/lib/startconnect.sh: line 4: ./data/plugins/music_service/spop/bin/vollibrespot: Permission denied
Sep 05 16:30:13 volumio volumio[869]: [SpotifyConnect] Vollibrespot Daemon service started!
Sep 05 16:30:13 volumio volumio[869]: SpotifyConnect: 222.618ms
Sep 05 16:30:13 volumio volumio[869]: info: Done.
Sep 05 16:30:15 volumio systemd[1]: volspotconnect.service holdoff time over, scheduling restart.
Sep 05 16:30:15 volumio systemd[1]: Stopping Volspotconnect2 Daemon...
Sep 05 16:30:15 volumio systemd[1]: Starting Volspotconnect2 Daemon...
Sep 05 16:30:15 volumio systemd[1]: Started Volspotconnect2 Daemon.
Sep 05 16:30:15 volumio volumio[19158]: /usr/lib/startconnect.sh: line 4: ./data/plugins/music_service/spop/bin/vollibrespot: Permission denied
Sep 05 16:30:17 volumio volumio[869]: info: Checking Spotify Web API
Sep 05 16:30:18 volumio systemd[1]: volspotconnect.service holdoff time over, scheduling restart.
Sep 05 16:30:18 volumio systemd[1]: Stopping Volspotconnect2 Daemon...
Sep 05 16:30:18 volumio systemd[1]: Starting Volspotconnect2 Daemon...
Sep 05 16:30:18 volumio systemd[1]: Started Volspotconnect2 Daemon.
Sep 05 16:30:18 volumio volumio[19188]: /usr/lib/startconnect.sh: line 4: ./data/plugins/music_service/spop/bin/vollibrespot: Permission denied
Sep 05 16:30:19 volumio volumio[869]: info: CALLMETHOD: music_service spop saveVolspotconnectAccount [object Object]
Sep 05 16:30:19 volumio volumio[869]: info: CoreCommandRouter::executeOnPlugin: spop , saveVolspotconnectAccount
Sep 05 16:30:20 volumio systemd[1]: volspotconnect.service holdoff time over, scheduling restart.
Sep 05 16:30:20 volumio systemd[1]: Stopping Volspotconnect2 Daemon...
Sep 05 16:30:20 volumio systemd[1]: Starting Volspotconnect2 Daemon...
Sep 05 16:30:20 volumio systemd[1]: Started Volspotconnect2 Daemon.
Sep 05 16:30:20 volumio volumio[19196]: /usr/lib/startconnect.sh: line 4: ./data/plugins/music_service/spop/bin/vollibrespot: Permission denied
Sep 05 16:30:22 volumio systemd[1]: volspotconnect.service holdoff time over, scheduling restart.
Sep 05 16:30:22 volumio systemd[1]: Stopping Volspotconnect2 Daemon...
Sep 05 16:30:22 volumio systemd[1]: Starting Volspotconnect2 Daemon...
Sep 05 16:30:22 volumio systemd[1]: Started Volspotconnect2 Daemon.
Sep 05 16:30:22 volumio volumio[19203]: /usr/lib/startconnect.sh: line 4: ./data/plugins/music_service/spop/bin/vollibrespot: Permission denied
Sep 05 16:30:24 volumio systemd[1]: volspotconnect.service holdoff time over, scheduling restart.
Sep 05 16:30:24 volumio systemd[1]: Stopping Volspotconnect2 Daemon...
Sep 05 16:30:24 volumio systemd[1]: Starting Volspotconnect2 Daemon...
Sep 05 16:30:24 volumio systemd[1]: Started Volspotconnect2 Daemon.
Sep 05 16:30:24 volumio volumio[19210]: /usr/lib/startconnect.sh: line 4: ./data/plugins/music_service/spop/bin/vollibrespot: Permission denied
Sep 05 16:30:27 volumio systemd[1]: volspotconnect.service holdoff time over, scheduling restart.
Sep 05 16:30:27 volumio systemd[1]: Stopping Volspotconnect2 Daemon...
Sep 05 16:30:27 volumio systemd[1]: Starting Volspotconnect2 Daemon...
Sep 05 16:30:27 volumio systemd[1]: Started Volspotconnect2 Daemon.
Sep 05 16:30:27 volumio volumio[19217]: /usr/lib/startconnect.sh: line 4: ./data/plugins/music_service/spop/bin/vollibrespot: Permission denied
Sep 05 16:30:29 volumio systemd[1]: volspotconnect.service holdoff time over, scheduling restart.
Sep 05 16:30:29 volumio systemd[1]: Stopping Volspotconnect2 Daemon...
Sep 05 16:30:29 volumio systemd[1]: Starting Volspotconnect2 Daemon...
Sep 05 16:30:29 volumio systemd[1]: Started Volspotconnect2 Daemon.
Sep 05 16:30:29 volumio volumio[19226]: /usr/lib/startconnect.sh: line 4: ./data/plugins/music_service/spop/bin/vollibrespot: Permission denied
Sep 05 16:30:31 volumio systemd[1]: volspotconnect.service holdoff time over, scheduling restart.
Sep 05 16:30:31 volumio systemd[1]: Stopping Volspotconnect2 Daemon...
Sep 05 16:30:31 volumio systemd[1]: Starting Volspotconnect2 Daemon...
Sep 05 16:30:31 volumio systemd[1]: Started Volspotconnect2 Daemon.
Sep 05 16:30:31 volumio volumio[19233]: /usr/lib/startconnect.sh: line 4: ./data/plugins/music_service/spop/bin/vollibrespot: Permission denied
Sep 05 16:30:33 volumio systemd[1]: volspotconnect.service holdoff time over, scheduling restart.
Sep 05 16:30:33 volumio systemd[1]: Stopping Volspotconnect2 Daemon...
Sep 05 16:30:33 volumio systemd[1]: Starting Volspotconnect2 Daemon...
Sep 05 16:30:33 volumio systemd[1]: Started Volspotconnect2 Daemon.
Sep 05 16:30:33 volumio volumio[19240]: /usr/lib/startconnect.sh: line 4: ./data/plugins/music_service/spop/bin/vollibrespot: Permission denied
Sep 05 16:30:36 volumio systemd[1]: volspotconnect.service holdoff time over, scheduling restart.
Sep 05 16:30:36 volumio systemd[1]: Stopping Volspotconnect2 Daemon...
Sep 05 16:30:36 volumio systemd[1]: Starting Volspotconnect2 Daemon...
Sep 05 16:30:36 volumio systemd[1]: Started Volspotconnect2 Daemon.
Sep 05 16:30:36 volumio volumio[19247]: /usr/lib/startconnect.sh: line 4: ./data/plugins/music_service/spop/bin/vollibrespot: Permission denied
Sep 05 16:30:38 volumio systemd[1]: volspotconnect.service holdoff time over, scheduling restart.
Sep 05 16:30:38 volumio systemd[1]: Stopping Volspotconnect2 Daemon...
Sep 05 16:30:38 volumio systemd[1]: Starting Volspotconnect2 Daemon...
Sep 05 16:30:38 volumio systemd[1]: Started Volspotconnect2 Daemon.
Sep 05 16:30:38 volumio volumio[19255]: /usr/lib/startconnect.sh: line 4: ./data/plugins/music_service/spop/bin/vollibrespot: Permission denied
Sep 05 16:30:38 volumio volumio[869]: info: CALLMETHOD: music_service spop saveVolspotconnectAccount [object Object]
Sep 05 16:30:38 volumio volumio[869]: info: CoreCommandRouter::executeOnPlugin: spop , saveVolspotconnectAccount
Sep 05 16:30:38 volumio volumio[869]: [SpotifyConnect] Creating VLS config file
Sep 05 16:30:38 volumio volumio[869]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 05 16:30:38 volumio volumio[869]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 05 16:30:38 volumio volumio[869]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 05 16:30:38 volumio volumio[869]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 05 16:30:38 volumio volumio[869]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Sep 05 16:30:38 volumio volumio[869]: [SpotifyConnect] Restarting Vollibrespot Daemon
Sep 05 16:30:38 volumio sudo[19261]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volspotconnect.service
Sep 05 16:30:38 volumio sudo[19261]: pam_unix(sudo:session): session opened for user root by (uid=0)
Sep 05 16:30:38 volumio systemd[1]: Stopping Volspotconnect2 Daemon...
Sep 05 16:30:38 volumio systemd[1]: Starting Volspotconnect2 Daemon...
Sep 05 16:30:38 volumio systemd[1]: Started Volspotconnect2 Daemon.
Sep 05 16:30:38 volumio sudo[19261]: pam_unix(sudo:session): session closed for user root
Sep 05 16:30:38 volumio volumio[19266]: /usr/lib/startconnect.sh: line 4: ./data/plugins/music_service/spop/bin/vollibrespot: Permission denied
Sep 05 16:30:39 volumio volumio[869]: [SpotifyConnect] Vollibrespot Daemon service restarted!
Sep 05 16:30:41 volumio systemd[1]: volspotconnect.service holdoff time over, scheduling restart.
Sep 05 16:30:41 volumio systemd[1]: Stopping Volspotconnect2 Daemon...
Sep 05 16:30:41 volumio systemd[1]: Starting Volspotconnect2 Daemon...
Sep 05 16:30:41 volumio systemd[1]: Started Volspotconnect2 Daemon.
Sep 05 16:30:41 volumio volumio[19276]: /usr/lib/startconnect.sh: line 4: ./data/plugins/music_service/spop/bin/vollibrespot: Permission denied
Sep 05 16:30:43 volumio systemd[1]: volspotconnect.service holdoff time over, scheduling restart.
Sep 05 16:30:43 volumio systemd[1]: Stopping Volspotconnect2 Daemon...
Sep 05 16:30:43 volumio systemd[1]: Starting Volspotconnect2 Daemon...
Sep 05 16:30:43 volumio systemd[1]: Started Volspotconnect2 Daemon.
Sep 05 16:30:43 volumio volumio[19283]: /usr/lib/startconnect.sh: line 4: ./data/plugins/music_service/spop/bin/vollibrespot: Permission denied
Sep 05 16:30:43 volumio volumio[869]: info: CALLMETHOD: music_service spop saveVolspotconnectSettings [object Object]
Sep 05 16:30:43 volumio volumio[869]: info: CoreCommandRouter::executeOnPlugin: spop , saveVolspotconnectSettings
Sep 05 16:30:43 volumio volumio[869]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Sep 05 16:30:43 volumio volumio[869]: TypeError: Cannot read property 'config' of undefined
Sep 05 16:30:43 volumio volumio[869]: at ControllerSpotify.saveVolspotconnectSettings (/data/plugins/music_service/spop/index.js:2612:19)
Sep 05 16:30:43 volumio volumio[869]: at CoreCommandRouter.executeOnPlugin (/volumio/app/index.js:1076:29)
Sep 05 16:30:43 volumio volumio[869]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:312:38)
Sep 05 16:30:43 volumio volumio[869]: at emitTwo (events.js:126:13)
Sep 05 16:30:43 volumio volumio[869]: at Socket.emit (events.js:214:7)
Sep 05 16:30:43 volumio volumio[869]: at /volumio/node_modules/socket.io/lib/socket.js:503:12
Sep 05 16:30:43 volumio volumio[869]: at _combinedTickCallback (internal/process/next_tick.js:131:7)
Sep 05 16:30:43 volumio volumio[869]: at process._tickCallback (internal/process/next_tick.js:180:9)
Sep 05 16:30:43 volumio volumio[869]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Sep 05 16:30:45 volumio sudo[19294]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-09-05 16:29
Sep 05 16:30:45 volumio sudo[19294]: pam_unix(sudo:session): session opened for user root by (uid=0)
PRETTY_NAME="Raspbian GNU/Linux 8 (jessie)"
NAME="Raspbian GNU/Linux"
VERSION_ID="8"
VERSION="8 (jessie)"
ID=raspbian
ID_LIKE=debian
HOME_URL="http://www.raspbian.org/"
SUPPORT_URL="http://www.raspbian.org/RaspbianForums"
BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs"
VOLUMIO_BUILD_VERSION="7434a810e3a57a07e8ee53a8f2063b5b15d2425c"
VOLUMIO_FE_VERSION="46e747523792c7107b0d7a2371009ff8ec0ee423"
VOLUMIO_BE_VERSION="fe61ccbb192df885af66ab16b273ac1aa9bf2c72"
VOLUMIO_ARCH="arm"
VOLUMIO_VARIANT="volumio"
VOLUMIO_TEST="FALSE"
VOLUMIO_BUILD_DATE="Sat Oct 12 10:05:28 PDT 2019"
VOLUMIO_VERSION="2.632"
VOLUMIO_HARDWARE="pi"
VOLUMIO_HASH="d41d8cd98f00b204e9800998ecf8427e"