-- Logs begin at Tue 2024-04-16 14:50:09 UTC, end at Tue 2024-04-16 17:22:33 UTC. --
Apr 16 17:22:29 volumio volumio[21144]: [Vollibrespot] : Connecting to AP "ap-gue1.spotify.com:443"
Apr 16 17:22:29 volumio volumio[21144]: [Vollibrespot] : Authenticated as "noboismannofraid" !
Apr 16 17:22:29 volumio volumio[21144]: [Vollibrespot] : Setting up new mixer: card:hw:0 mixer:Master index:0
Apr 16 17:22:29 volumio volumio[21144]: [Vollibrespot] : Alsa min-db is not SND_CTL_TLV_DB_GAIN_MUTE!!
Apr 16 17:22:29 volumio volumio[21144]: [Vollibrespot] : Alsa Mixer info min: 0 (MilliBel(-6400)[dB]) -- max: 64 (MilliBel(0)[dB]) HW: true
Apr 16 17:22:29 volumio volumio[21144]: [Vollibrespot] : Alsa min-db is not SND_CTL_TLV_DB_GAIN_MUTE!!
Apr 16 17:22:29 volumio volumio[21144]: [Vollibrespot] : Country: "CA"
Apr 16 17:22:29 volumio volumio[21144]: [Vollibrespot] : Metadata pipe established
Apr 16 17:22:29 volumio volumio[21144]: [Vollibrespot] : Event: Volume { volume_to_mixer: 0 }
Apr 16 17:22:29 volumio volumio[1072]: [SpotifyConnect] 0
Apr 16 17:22:29 volumio volumio[1072]: [SpotifyConnect] Volume: Spotify:0 Volumio: 0
Apr 16 17:22:29 volumio volumio[1072]: info: CoreStateMachine::pushState
Apr 16 17:22:29 volumio volumio[1072]: info: CoreStateMachine::getState
Apr 16 17:22:29 volumio volumio[1072]: info: CoreCommandRouter::volumioPushState
Apr 16 17:22:29 volumio volumio[1072]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Apr 16 17:22:29 volumio volumio[1072]: info: interfaceApi::pushState
Apr 16 17:22:29 volumio volumio[21144]: [Vollibrespot] : Using alsa sink
Apr 16 17:22:29 volumio volumio[1072]: info: Pushing Favourites {"service":"airplay","uri":"","favourite":false}
Apr 16 17:22:29 volumio volumio[21144]: [Vollibrespot] : Fetching autoplay context uri
Apr 16 17:22:29 volumio volumio[21144]: [Vollibrespot] : Event: SessionActive { became_active_at: 1713288149659 }
Apr 16 17:22:29 volumio volumio[21144]: [Vollibrespot] : SessionActive!
Apr 16 17:22:29 volumio volumio[1072]: [SpotifyConnect] A connect session has begun
Apr 16 17:22:29 volumio volumio[1072]: [SpotifyConnect] Device palyback is active!
Apr 16 17:22:29 volumio volumio[21144]: [Vollibrespot] : Event: PlaybackStarted { track_id: SpotifyId { id: 65192376432616478662396887347209877237, audio_type: Track } }
Apr 16 17:22:29 volumio volumio[21144]: [Vollibrespot] : Event: PlaybackLoading { track_id: SpotifyId { id: 65192376432616478662396887347209877237, audio_type: Track } }
Apr 16 17:22:29 volumio volumio[1072]: info: CoreCommandRouter::volumioGetState
Apr 16 17:22:29 volumio volumio[1072]: info: CoreStateMachine::getState
Apr 16 17:22:29 volumio volumio[1072]: [SpotifyConnect] Currently active: airplay
Apr 16 17:22:29 volumio volumio[1072]: [SpotifyConnect] Stopping currently active service
Apr 16 17:22:29 volumio volumio[1072]: info: CoreCommandRouter::volumioStop
Apr 16 17:22:29 volumio volumio[1072]: info: CoreStateMachine::stop
Apr 16 17:22:29 volumio volumio[1072]: info: CoreStateMachine::serviceStop
Apr 16 17:22:29 volumio volumio[1072]: info: CoreCommandRouter::serviceStop
Apr 16 17:22:29 volumio volumio[1072]: error: WARNING: No stop method for service airplay
Apr 16 17:22:29 volumio volumio[21144]: [Vollibrespot] : Autoplay uri resolved to <"spotify:station:playlist:1PJlZrKug0LXiKaCHjSDu7">
Apr 16 17:22:29 volumio volumio[21144]: [Vollibrespot] : Resolving uri "spotify:station:playlist:1PJlZrKug0LXiKaCHjSDu7"
Apr 16 17:22:29 volumio volumio[21144]: [Vollibrespot] : Event: GotToken { token: Token { access_token: "BQAxqLhVjN9uXiYLkfB3xNHByc0z17z_h1Uayr8TvuYLMI0b8IL8Y0xz6fy0vwRGoApAxOGP23JaRQmf9Ldob6QoGEF3Rui5OGSD3CRRRR4CjQy0n5NtLfPZu3O2-2PF3OmpSrS34SqbZbU8yYerPuciqAsQAkNykQIo6JcXXSithbbjN4TZmzICfJNdkDwLvPYYdKZaYs3ljg", expires_in: 3600, token_type: "Bearer", scope: ["streaming", "user-read-playback-state", "user-modify-playback-state", "user-read-currently-playing", "user-read-private"] } }
Apr 16 17:22:29 volumio volumio[1072]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Apr 16 17:22:29 volumio volumio[21144]: [Vollibrespot] : Loading with Spotify URI
Apr 16 17:22:29 volumio volumio[1072]: TypeError: Cannot read property 'then' of undefined
Apr 16 17:22:29 volumio volumio[1072]: at SpotConnEvents.SpotConn.on (/data/plugins/music_service/volspotconnect2/index.js:143:23)
Apr 16 17:22:29 volumio volumio[1072]: at emitNone (events.js:106:13)
Apr 16 17:22:29 volumio volumio[1072]: at SpotConnEvents.emit (events.js:208:7)
Apr 16 17:22:29 volumio volumio[1072]: at SpotConnEvents.parseData (/data/plugins/music_service/volspotconnect2/SpotConnController.js:73:16)
Apr 16 17:22:29 volumio volumio[1072]: at Socket.SpotConnEvents._udpsource.on.msg (/data/plugins/music_service/volspotconnect2/SpotConnController.js:15:12)
Apr 16 17:22:29 volumio volumio[1072]: at emitTwo (events.js:126:13)
Apr 16 17:22:29 volumio volumio[1072]: at Socket.emit (events.js:214:7)
Apr 16 17:22:29 volumio volumio[1072]: at UDP.onMessage [as onmessage] (dgram.js:659:8)
Apr 16 17:22:29 volumio volumio[1072]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Apr 16 17:22:30 volumio volumio[21144]: [Vollibrespot] : Resolved 50 tracks from <"spotify:playlist:1PJlZrKug0LXiKaCHjSDu7">
Apr 16 17:22:30 volumio volumio[21144]: [Vollibrespot] : (213000 ms) loaded
Apr 16 17:22:30 volumio volumio[21144]: [Vollibrespot] : Alsa error PCM open ALSA function 'snd_pcm_open' failed with error 'EBUSY: Device or resource busy'
Apr 16 17:22:30 volumio volumio[21144]: [Vollibrespot] : Could not start audio: Alsa error: PCM open failed
Apr 16 17:22:30 volumio volumio[21144]: [Vollibrespot] : Alsa error PCM open ALSA function 'snd_pcm_open' failed with error 'EBUSY: Device or resource busy'
Apr 16 17:22:30 volumio volumio[21144]: [Vollibrespot] : Could not start audio: Alsa error: PCM open failed
Apr 16 17:22:30 volumio volumio[21144]: [Vollibrespot] : Alsa error PCM open ALSA function 'snd_pcm_open' failed with error 'EBUSY: Device or resource busy'
Apr 16 17:22:30 volumio volumio[21144]: [Vollibrespot] : Could not start audio: Alsa error: PCM open failed
Apr 16 17:22:30 volumio volumio[21144]: thread '' panicked at 'called `Option::unwrap()` on a `None` value', /build/cache/git/checkouts/librespot-6f197fd632ef9380/08d8bcc/playback/src/audio_backend/alsa.rs:129:35
Apr 16 17:22:30 volumio volumio[21144]: stack backtrace:
Apr 16 17:22:31 volumio volumio[21144]: 0: 0xaeeae38 - backtrace::backtrace::libunwind::trace::ha66f0a58dafef379
Apr 16 17:22:31 volumio volumio[21144]: at /cargo/registry/src/github.com-1285ae84e5963aae/backtrace-0.3.46/src/backtrace/libunwind.rs:86
Apr 16 17:22:31 volumio volumio[21144]: 1: 0xaeeae38 - backtrace::backtrace::trace_unsynchronized::h1af62022ad7ddee3
Apr 16 17:22:31 volumio volumio[21144]: at /cargo/registry/src/github.com-1285ae84e5963aae/backtrace-0.3.46/src/backtrace/mod.rs:66
Apr 16 17:22:31 volumio volumio[21144]: 2: 0xaeeae38 - std::sys_common::backtrace::_print_fmt::hb97d84e219f64b39
Apr 16 17:22:31 volumio volumio[21144]: at src/libstd/sys_common/backtrace.rs:78
Apr 16 17:22:31 volumio volumio[21144]: 3: 0xaeeae38 - ::fmt::h100f5a82407b68e4
Apr 16 17:22:31 volumio volumio[21144]: at src/libstd/sys_common/backtrace.rs:59
Apr 16 17:22:31 volumio volumio[21144]: 4: 0xaf14e80 - core::fmt::write::he118d0604e33df81
Apr 16 17:22:31 volumio volumio[21144]: at src/libcore/fmt/mod.rs:1076
Apr 16 17:22:31 volumio volumio[21144]: 5: 0xaee471c - std::io::Write::write_fmt::h003436247c3fc214
Apr 16 17:22:31 volumio volumio[21144]: at src/libstd/io/mod.rs:1537
Apr 16 17:22:31 volumio volumio[21144]: 6: 0xaeed76e - std::sys_common::backtrace::_print::h83f536c912b08532
Apr 16 17:22:31 volumio volumio[21144]: at src/libstd/sys_common/backtrace.rs:62
Apr 16 17:22:31 volumio volumio[21144]: 7: 0xaeed76e - std::sys_common::backtrace::print::h89499a5fd474cd45
Apr 16 17:22:31 volumio volumio[21144]: at src/libstd/sys_common/backtrace.rs:49
Apr 16 17:22:31 volumio volumio[21144]: 8: 0xaeed76e - std::panicking::default_hook::{{closure}}::h105742511edf80c2
Apr 16 17:22:31 volumio volumio[21144]: at src/libstd/panicking.rs:198
Apr 16 17:22:31 volumio volumio[21144]: 9: 0xaeed498 - std::panicking::default_hook::h4b1ff4bee1a0989c
Apr 16 17:22:31 volumio volumio[21144]: at src/libstd/panicking.rs:217
Apr 16 17:22:31 volumio volumio[21144]: 10: 0xaeede16 - std::panicking::rust_panic_with_hook::h403abc20e0fb824f
Apr 16 17:22:31 volumio volumio[21144]: at src/libstd/panicking.rs:526
Apr 16 17:22:31 volumio volumio[21144]: 11: 0xaeed9c8 - rust_begin_unwind
Apr 16 17:22:31 volumio volumio[21144]: at src/libstd/panicking.rs:437
Apr 16 17:22:31 volumio volumio[21144]: 12: 0xaf12ab0 - core::panicking::panic_fmt::h280e963ddd15a643
Apr 16 17:22:31 volumio volumio[21144]: at src/libcore/panicking.rs:85
Apr 16 17:22:31 volumio volumio[21144]: 13: 0xaf129ec - core::panicking::panic::h9ccc1b62a8119bd7
Apr 16 17:22:31 volumio volumio[21144]: at src/libcore/panicking.rs:50
Apr 16 17:22:31 volumio volumio[21144]: 14: 0xaae7f8d - ::write::h3581324fecd47df1
Apr 16 17:22:31 volumio volumio[21144]: 15: 0xaac0ac6 - ::poll::hc21f5ecf7ce2e698
Apr 16 17:22:31 volumio volumio[21144]: 16: 0xa9d6e66 - futures::task_impl::std::set::h7d1d91c2a2b6f5b8
Apr 16 17:22:31 volumio volumio[21144]: 17: 0xa9cc055 - futures::task_impl::Spawn::poll_future_notify::h66f1553db90c4a22
Apr 16 17:22:31 volumio volumio[21144]: 18: 0xa9e476c - futures::future::Future::wait::hfe836d397a4aec59
Apr 16 17:22:31 volumio volumio[21144]: 19: 0xa9cd6e6 - std::sys_common::backtrace::__rust_begin_short_backtrace::h5ece287f9f454f8f
Apr 16 17:22:31 volumio volumio[21144]: 20: 0xa9eb4ab - core::ops::function::FnOnce::call_once{{vtable.shim}}::he930b09a4d23e04c
Apr 16 17:22:31 volumio volumio[21144]: 21: 0xaef12ef - as core::ops::function::FnOnce>::call_once::h248edc50ac6013fc
Apr 16 17:22:31 volumio volumio[21144]: at /rustc/04488afe34512aa4c33566eb16d8c912a3ae04f9/src/liballoc/boxed.rs:1081
Apr 16 17:22:31 volumio volumio[21144]: 22: 0xaef12ef - as core::ops::function::FnOnce>::call_once::h97a26f5b6bb26bb1
Apr 16 17:22:31 volumio volumio[21144]: at /rustc/04488afe34512aa4c33566eb16d8c912a3ae04f9/src/liballoc/boxed.rs:1081
Apr 16 17:22:31 volumio volumio[21144]: 23: 0xaef12ef - std::sys::unix::thread::Thread::new::thread_start::h74eb381cbdc8573a
Apr 16 17:22:31 volumio volumio[21144]: at src/libstd/sys/unix/thread.rs:87
Apr 16 17:22:31 volumio volumio[21144]: 24: 0xb390fd67 - start_thread
Apr 16 17:22:31 volumio volumio[21144]: 25: 0xb384f64e - clone
Apr 16 17:22:31 volumio volumio[21144]: 26: 0x0 -
Apr 16 17:22:33 volumio sudo[32323]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-04-16 17:21
Apr 16 17:22:33 volumio sudo[32323]: pam_unix(sudo:session): session opened for user root by (uid=0)
PRETTY_NAME="Debian GNU/Linux 8 (jessie)"
NAME="Debian GNU/Linux"
VERSION_ID="8"
VERSION="8 (jessie)"
ID=debian
HOME_URL="http://www.debian.org/"
SUPPORT_URL="http://www.debian.org/support"
BUG_REPORT_URL="https://bugs.debian.org/"
VOLUMIO_BUILD_VERSION="2f09878fca434492a3a1c8d64c992c38a304bdcb"
VOLUMIO_FE_VERSION="81c7100e9c7342b16fc9e0ca5908a26771e08c4f"
VOLUMIO_BE_VERSION="9ddaa4edade219b4424aaf553d8a153e2d73143a"
VOLUMIO_ARCH="x86"
VOLUMIO_VARIANT="volumio"
VOLUMIO_TEST="FALSE"
VOLUMIO_BUILD_DATE="Fri Jun 15 20:45:03 CEST 2018"
VOLUMIO_VERSION="2.411"
VOLUMIO_HARDWARE="x86"