-- Logs begin at Fri 2021-07-02 10:45:33 UTC, end at Fri 2024-04-05 14:24:38 UTC. --
Apr 05 14:24:10 volumio systemd[1]: Starting Cleanup of Temporary Directories...
Apr 05 14:24:10 volumio volumio[1083]: ------------------------------------ BT MESSAGE: BT STATUS: running
Apr 05 14:24:10 volumio volumio[1083]: BT PLUGIN MESSAGE: Playing: false
Apr 05 14:24:10 volumio volumio[1083]: BT PLUGIN MESSAGE: VOLATILE: tidalconnect
Apr 05 14:24:10 volumio volumio[1083]: BT PLUGIN MESSAGE: STATE:undefined
Apr 05 14:24:10 volumio systemd[1]: Started Cleanup of Temporary Directories.
Apr 05 14:24:24 volumio volumio[1219]: [Vollibrespot] : Fetching autoplay context uri
Apr 05 14:24:24 volumio volumio[1219]: thread 'main' panicked at 'called `Result::unwrap()` on an `Err` value: SendError("...")', /build/cache/git/checkouts/librespot-6f197fd632ef9380/08d8bcc/playback/src/player.rs:232:61
Apr 05 14:24:24 volumio volumio[1219]: stack backtrace:
Apr 05 14:24:24 volumio volumio[1219]: 0:   0xa4033c - backtrace::backtrace::libunwind::trace::hae21a072c81e5842
Apr 05 14:24:24 volumio volumio[1219]: at /cargo/registry/src/github.com-1ecc6299db9ec823/backtrace-0.3.46/src/backtrace/libunwind.rs:86
Apr 05 14:24:24 volumio volumio[1219]: 1:   0xa4033c - backtrace::backtrace::trace_unsynchronized::h0f9b260087e46e47
Apr 05 14:24:24 volumio volumio[1219]: at /cargo/registry/src/github.com-1ecc6299db9ec823/backtrace-0.3.46/src/backtrace/mod.rs:66
Apr 05 14:24:24 volumio volumio[1219]: 2:   0xa4033c - std::sys_common::backtrace::_print_fmt::hbf1a59173a7860c3
Apr 05 14:24:24 volumio volumio[1219]: at src/libstd/sys_common/backtrace.rs:78
Apr 05 14:24:24 volumio volumio[1219]: 3:   0xa4033c - ::fmt::he1a5d6f378e506c4
Apr 05 14:24:24 volumio volumio[1219]: at src/libstd/sys_common/backtrace.rs:59
Apr 05 14:24:24 volumio volumio[1219]: 4:   0xa60d5c - core::fmt::write::hb37ae5a5e0b70623
Apr 05 14:24:24 volumio volumio[1219]: at src/libcore/fmt/mod.rs:1076
Apr 05 14:24:24 volumio volumio[1219]: 5:   0xa39c64 - std::io::Write::write_fmt::ha24bb3f5a858327b
Apr 05 14:24:24 volumio volumio[1219]: at src/libstd/io/mod.rs:1537
Apr 05 14:24:24 volumio volumio[1219]: 6:   0xa42974 - std::sys_common::backtrace::_print::h47b03aa1342833e3
Apr 05 14:24:24 volumio volumio[1219]: at src/libstd/sys_common/backtrace.rs:62
Apr 05 14:24:24 volumio volumio[1219]: 7:   0xa42974 - std::sys_common::backtrace::print::h2217cbc390250439
Apr 05 14:24:24 volumio volumio[1219]: at src/libstd/sys_common/backtrace.rs:49
Apr 05 14:24:24 volumio volumio[1219]: 8:   0xa42974 - std::panicking::default_hook::{{closure}}::h179f5229ea1c8e30
Apr 05 14:24:24 volumio volumio[1219]: at src/libstd/panicking.rs:198
Apr 05 14:24:24 volumio volumio[1219]: 9:   0xa42640 - std::panicking::default_hook::h46ab82039cbc65eb
Apr 05 14:24:24 volumio volumio[1219]: at src/libstd/panicking.rs:217
Apr 05 14:24:24 volumio volumio[1219]: 10:   0xa43054 - std::panicking::rust_panic_with_hook::h7326c48419bc7c33
Apr 05 14:24:24 volumio volumio[1219]: at src/libstd/panicking.rs:526
Apr 05 14:24:24 volumio volumio[1219]: 11:   0xa42c54 - rust_begin_unwind
Apr 05 14:24:24 volumio volumio[1219]: at src/libstd/panicking.rs:437
Apr 05 14:24:24 volumio volumio[1219]: 12:   0xa5e594 - core::panicking::panic_fmt::ha292e19d5ae716ed
Apr 05 14:24:24 volumio volumio[1219]: at src/libcore/panicking.rs:85
Apr 05 14:24:24 volumio volumio[1219]: 13:   0xa5e3ec - core::option::expect_none_failed::h5afc8f3774fae01b
Apr 05 14:24:24 volumio volumio[1219]: at src/libcore/option.rs:1269
Apr 05 14:24:24 volumio volumio[1219]: 14:   0x613ee8 - librespot_playback::player::Player::load::h2fbc0f0186244952
Apr 05 14:24:24 volumio volumio[1219]: 15:   0x5edf44 - librespot_connect::spirc::SpircTask::load_track::hfca5ae127a06d3ea
Apr 05 14:24:24 volumio volumio[1219]: 16:   0x5e9fc8 - ::poll::ha2e91a6b75c719f3
Apr 05 14:24:24 volumio volumio[1219]: 17:   0x560ca4 - ::poll::hc5e7d2d1b7dbef13
Apr 05 14:24:24 volumio volumio[1219]: 18:   0x528844 - futures::task_impl::std::set::h8f081cf0436110c9
Apr 05 14:24:24 volumio volumio[1219]: 19:   0x53c41c - std::thread::local::LocalKey::with::h711a13323aafc45a
Apr 05 14:24:24 volumio volumio[1219]: 20:   0x518a50 - tokio_current_thread::Entered

::block_on::h339073902a399eb7 Apr 05 14:24:24 volumio volumio[1219]: 21: 0x53ce00 - std::thread::local::LocalKey::with::hff64c13ccfec5327 Apr 05 14:24:24 volumio volumio[1219]: 22: 0x54920c - tokio_reactor::with_default::h7ef12e65cb103d2f Apr 05 14:24:24 volumio volumio[1219]: 23: 0x51c9f8 - tokio::runtime::current_thread::runtime::Runtime::block_on::h043f136d6b8cf48f Apr 05 14:24:24 volumio volumio[1219]: 24: 0x5622c8 - vollibrespot::main::h02a0d49d4cc5eaa6 Apr 05 14:24:24 volumio volumio[1219]: 25: 0x549f18 - std::rt::lang_start::{{closure}}::h279cd2b7929fdba7 Apr 05 14:24:24 volumio volumio[1219]: 26: 0xa43404 - std::rt::lang_start_internal::{{closure}}::he93bfc404849b78a Apr 05 14:24:24 volumio volumio[1219]: at src/libstd/rt.rs:52 Apr 05 14:24:24 volumio volumio[1219]: 27: 0xa43404 - std::panicking::try::do_call::h6e9e98f4078affb0 Apr 05 14:24:24 volumio volumio[1219]: at src/libstd/panicking.rs:348 Apr 05 14:24:24 volumio volumio[1219]: 28: 0xa43404 - std::panicking::try::h2e68d4f7f799a6df Apr 05 14:24:24 volumio volumio[1219]: at src/libstd/panicking.rs:325 Apr 05 14:24:24 volumio volumio[1219]: 29: 0xa43404 - std::panic::catch_unwind::h8880a4c07cc66391 Apr 05 14:24:24 volumio volumio[1219]: at src/libstd/panic.rs:394 Apr 05 14:24:24 volumio volumio[1219]: 30: 0xa43404 - std::rt::lang_start_internal::hf4ae2140248bf16b Apr 05 14:24:24 volumio volumio[1219]: at src/libstd/rt.rs:51 Apr 05 14:24:24 volumio volumio[1219]: 31: 0x562d84 - main Apr 05 14:24:24 volumio volumio[1219]: 32: 0x76d35678 - __libc_start_main Apr 05 14:24:24 volumio volumio[1219]: [Vollibrespot] : Player thread panicked! Apr 05 14:24:24 volumio volumio[1219]: [Vollibrespot] : EventSender disconnected Apr 05 14:24:24 volumio systemd[1]: volspotconnect2.service: main process exited, code=exited, status=101/n/a Apr 05 14:24:24 volumio systemd[1]: Unit volspotconnect2.service entered failed state. Apr 05 14:24:24 volumio volumio[1083]: [SpotifyConnect] Device palyback is inactive Apr 05 14:24:24 volumio volumio[1083]: [SpotifyConnect] Device is not active. Cleaning up! Apr 05 14:24:24 volumio volumio[1083]: [SpotifyConnect] Sink released Apr 05 14:24:24 volumio volumio[1083]: [SpotifyConnect] Not pushing Pause { active: false, isStopping: false} Apr 05 14:24:27 volumio systemd[1]: volspotconnect2.service holdoff time over, scheduling restart. Apr 05 14:24:27 volumio systemd[1]: Stopping Volspotconnect2 Daemon... Apr 05 14:24:27 volumio systemd[1]: Starting Volspotconnect2 Daemon... Apr 05 14:24:27 volumio systemd[1]: Started Volspotconnect2 Daemon. Apr 05 14:24:27 volumio volumio[4072]: vollibrespot v0.2.2 cd96399 2020-10-07 (librespot 08d8bcc 2020-10-07) -- Built On 2020-10-07 Apr 05 14:24:27 volumio volumio[4072]: Reading Config from "volspotify.toml" Apr 05 14:24:27 volumio volumio[4072]: [Vollibrespot] : Using Alsa backend with device: plughw:2 Apr 05 14:24:27 volumio volumio[4072]: [Vollibrespot] : Failed to register IPv6 receiver: Os { code: 19, kind: Other, message: "No such device" } Apr 05 14:24:35 volumio kernel: rpi_firmware_get_throttled: 26 callbacks suppressed Apr 05 14:24:35 volumio kernel: Under-voltage detected! (0x00050005) Apr 05 14:24:35 volumio volumio[4072]: [Vollibrespot] : Connecting to AP "ap-gew4.spotify.com:443" Apr 05 14:24:36 volumio volumio[4072]: [Vollibrespot] : Authenticated as "7r8379zfzgbs4qv9kn3mf9r72" ! Apr 05 14:24:36 volumio volumio[4072]: [Vollibrespot] : Setting up new mixer: card:hw:2 mixer:Analogue index:0 Apr 05 14:24:36 volumio volumio[4072]: [Vollibrespot] : Alsa min-db is not SND_CTL_TLV_DB_GAIN_MUTE!! Apr 05 14:24:36 volumio volumio[4072]: [Vollibrespot] : Alsa Mixer info min: 0 (MilliBel(-600)[dB]) -- max: 1 (MilliBel(0)[dB]) HW: true Apr 05 14:24:36 volumio volumio[4072]: [Vollibrespot] : Alsa min-db is not SND_CTL_TLV_DB_GAIN_MUTE!! Apr 05 14:24:36 volumio volumio[4072]: [Vollibrespot] : Using alsa sink Apr 05 14:24:36 volumio volumio[4072]: [Vollibrespot] : Metadata pipe established Apr 05 14:24:36 volumio volumio[4072]: [Vollibrespot] : Country: "IT" Apr 05 14:24:36 volumio volumio[4072]: [Vollibrespot] : Event: Volume { volume_to_mixer: 0 } Apr 05 14:24:36 volumio volumio[1083]: [SpotifyConnect] 0 Apr 05 14:24:36 volumio volumio[1083]: [SpotifyConnect] Volume: Spotify:0 Volumio: 0 Apr 05 14:24:36 volumio volumio[1083]: info: CoreStateMachine::pushState Apr 05 14:24:36 volumio volumio[1083]: info: CoreCommandRouter::volumioPushState Apr 05 14:24:36 volumio volumio[1083]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 05 14:24:36 volumio volumio[4072]: [Vollibrespot] : Fetching autoplay context uri Apr 05 14:24:36 volumio volumio[4072]: [Vollibrespot] : Event: SessionActive { became_active_at: 1712327076796 } Apr 05 14:24:36 volumio volumio[4072]: [Vollibrespot] : SessionActive! Apr 05 14:24:36 volumio volumio[4072]: [Vollibrespot] : Event: PlaybackStarted { track_id: SpotifyId { id: 184352277043961164326267947494836131036, audio_type: Track } } Apr 05 14:24:36 volumio volumio[4072]: [Vollibrespot] : Event: PlaybackLoading { track_id: SpotifyId { id: 184352277043961164326267947494836131036, audio_type: Track } } Apr 05 14:24:36 volumio volumio[1083]: [SpotifyConnect] A connect session has begun Apr 05 14:24:36 volumio volumio[1083]: [SpotifyConnect] Device palyback is active! Apr 05 14:24:36 volumio volumio[1083]: info: CoreCommandRouter::volumioGetState Apr 05 14:24:36 volumio volumio[1083]: [SpotifyConnect] Currently active: tidalconnect Apr 05 14:24:36 volumio volumio[1083]: [SpotifyConnect] Stopping currently active service Apr 05 14:24:36 volumio volumio[1083]: info: CoreCommandRouter::volumioStop Apr 05 14:24:36 volumio volumio[1083]: info: CoreStateMachine::stop Apr 05 14:24:36 volumio volumio[1083]: info: CoreStateMachine::serviceStop Apr 05 14:24:36 volumio volumio[1083]: info: CoreCommandRouter::serviceStop Apr 05 14:24:36 volumio volumio[1083]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 05 14:24:36 volumio volumio[4072]: [Vollibrespot] : Autoplay uri resolved to <"spotify:station:playlist:6DeIhuK5xRSU5ola5j2pCE"> Apr 05 14:24:36 volumio volumio[4072]: [Vollibrespot] : Resolving uri "spotify:station:playlist:6DeIhuK5xRSU5ola5j2pCE" Apr 05 14:24:36 volumio volumio[1083]: TypeError: Cannot read property 'then' of undefined Apr 05 14:24:36 volumio volumio[1083]: at SpotConnEvents.SpotConn.on (/data/plugins/music_service/volspotconnect2/index.js:143:23) Apr 05 14:24:36 volumio volumio[1083]: at emitNone (events.js:106:13) Apr 05 14:24:36 volumio volumio[1083]: at SpotConnEvents.emit (events.js:208:7) Apr 05 14:24:36 volumio volumio[1083]: at SpotConnEvents.parseData (/data/plugins/music_service/volspotconnect2/SpotConnController.js:73:16) Apr 05 14:24:36 volumio volumio[1083]: at Socket.SpotConnEvents._udpsource.on.msg (/data/plugins/music_service/volspotconnect2/SpotConnController.js:15:12) Apr 05 14:24:36 volumio volumio[1083]: at emitTwo (events.js:126:13) Apr 05 14:24:36 volumio volumio[1083]: at Socket.emit (events.js:214:7) Apr 05 14:24:36 volumio volumio[1083]: at UDP.onMessage [as onmessage] (dgram.js:659:8) Apr 05 14:24:36 volumio volumio[1083]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 05 14:24:36 volumio volumio[4072]: [Vollibrespot] : Event: GotToken { token: Token { access_token: "BQA2GF3wmZYLKpOUlF3LobXZNvvuG1ApOzxv5dtVIvBJhuJMGaRFLJJTBb2FAiuEUqxrsfryRHN0azftKqjICt-Cnn3gSmuUd8DgcS9XKraEHdgKDTn5u9G2E8moVEawpP4D6TEHFdYmVUsNIWWvHci5rDij_rwfLrDu_-UiHUZO6QlxV5s-LKhUdnxz6NhMgig2a2jvvoQyPtcU1qwBLZnBPw", expires_in: 3600, token_type: "Bearer", scope: ["streaming", "user-read-playback-state", "user-modify-playback-state", "user-read-currently-playing", "user-read-private"] } } Apr 05 14:24:36 volumio volumio[4072]: [Vollibrespot] : Loading with Spotify URI Apr 05 14:24:37 volumio volumio[4072]: [Vollibrespot] : Resolved 50 tracks from <"spotify:playlist:6DeIhuK5xRSU5ola5j2pCE"> Apr 05 14:24:37 volumio volumio[4072]: [Vollibrespot] : (504826 ms) loaded Apr 05 14:24:37 volumio kernel: pcm512x 1-004d: No SCLK, using BCLK: -2 Apr 05 14:24:37 volumio volumio[4072]: [Vollibrespot] : Event: SinkActive Apr 05 14:24:38 volumio sudo[4112]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-04-05 14:23 Apr 05 14:24:38 volumio sudo[4112]: 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="cd11dc738d0d82822d0aa776d0729686b82e3758" VOLUMIO_FE_VERSION="77db3ca2a7f5a7023ece8c5b86e997d58abdace6" VOLUMIO_BE_VERSION="748352701ebc6ec2b59443fcac1ec9aea1f276df" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri Jul 2 12:45:33 CEST 2021" VOLUMIO_VERSION="2.907" VOLUMIO_HARDWARE="pi" VOLUMIO_HASH="858e764292794952fe9c14f4c1868f5a"