-- Logs begin at Thu 2024-08-29 09:47:37 UTC, end at Sat 2024-08-31 17:56:09 UTC. -- Aug 31 17:55:00 volumio wpa_supplicant[10209]: wlan0: Failed to initiate sched scan Aug 31 17:55:02 volumio volumio[11250]: ERROR:librespot_core::session: Error { repr: Os { code: 104, message: "Connection reset by peer" } } Aug 31 17:55:02 volumio volumio[11250]: INFO:librespot_core::session: Connecting to AP "ap-gew4.spotify.com:4070" Aug 31 17:55:02 volumio volumio[11250]: INFO:librespot_core::session: Authenticated as "crowthewarriorking" ! Aug 31 17:55:02 volumio volumio[11250]: INFO:librespot_core::session: Country: "DE" Aug 31 17:55:02 volumio volumio[11250]: INFO:librespot_playback::player: new Player[1] Aug 31 17:55:02 volumio volumio[11250]: INFO:librespot_playback::audio_backend::alsa: Using alsa sink Aug 31 17:55:06 volumio wpa_supplicant[10209]: wlan0: Failed to initiate sched scan Aug 31 17:55:11 volumio wpa_supplicant[10209]: wlan0: Failed to initiate sched scan Aug 31 17:55:17 volumio wpa_supplicant[10209]: wlan0: Failed to initiate sched scan Aug 31 17:55:23 volumio wpa_supplicant[10209]: wlan0: Failed to initiate sched scan Aug 31 17:55:28 volumio wpa_supplicant[10209]: wlan0: Failed to initiate sched scan Aug 31 17:55:34 volumio wpa_supplicant[10209]: wlan0: Failed to initiate sched scan Aug 31 17:55:39 volumio wpa_supplicant[10209]: wlan0: Failed to initiate sched scan Aug 31 17:55:45 volumio wpa_supplicant[10209]: wlan0: Failed to initiate sched scan Aug 31 17:55:51 volumio wpa_supplicant[10209]: wlan0: Failed to initiate sched scan Aug 31 17:55:52 volumio volumio[11250]: WARN:librespot_playback::player: Player::stop called from invalid state Aug 31 17:55:56 volumio wpa_supplicant[10209]: wlan0: Failed to initiate sched scan Aug 31 17:56:02 volumio wpa_supplicant[10209]: wlan0: Failed to initiate sched scan Aug 31 17:56:07 volumio volumio[11250]: INFO:librespot_playback::player: SpCon::kSpPlaybackNotifyBecameActive Aug 31 17:56:07 volumio volumio[11250]: INFO:librespot_playback::player: SpCon::token Aug 31 17:56:07 volumio volumio[1066]: info: [SpConDebug] Session is active! Aug 31 17:56:07 volumio volumio[1066]: info: CoreCommandRouter::volumioGetState Aug 31 17:56:07 volumio volumio[1066]: info: CoreStateMachine::getState Aug 31 17:56:07 volumio volumio[1066]: info: CorePlayQueue::getTrack 0 Aug 31 17:56:07 volumio volumio[1066]: info: [SpConDebug] Currently active:mpd Aug 31 17:56:07 volumio volumio[1066]: info: [SpConDebug] Stopping currently active service Aug 31 17:56:07 volumio volumio[1066]: info: CoreCommandRouter::volumioStop Aug 31 17:56:07 volumio volumio[1066]: info: CoreStateMachine::stop Aug 31 17:56:07 volumio volumio[1066]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 31 17:56:07 volumio volumio[1066]: UNSET VOLATILE Aug 31 17:56:07 volumio volumio[1066]: info: [SpConDebug] SpotConn Active Aug 31 17:56:07 volumio volumio[1066]: info: CoreCommandRouter::volumioGetState Aug 31 17:56:07 volumio volumio[1066]: info: CoreStateMachine::getState Aug 31 17:56:07 volumio volumio[1066]: info: CorePlayQueue::getTrack 0 Aug 31 17:56:07 volumio volumio[1066]: info: [SpConDebug] Currently active:mpd Aug 31 17:56:07 volumio volumio[1066]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 31 17:56:07 volumio volumio[1066]: info: CoreCommandRouter::servicePushState Aug 31 17:56:07 volumio volumio[1066]: info: CoreStateMachine::syncState Aug 31 17:56:07 volumio volumio[1066]: info: CorePlayQueue::getTrack 0 Aug 31 17:56:07 volumio volumio[1066]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current mpd Received volspotconnect2 Aug 31 17:56:07 volumio volumio[1066]: info: [SpConDebug] Token: BQAbLFbeOY1aJkoEAIuokZ1zoCjdU_EwxLba66JqXrjhCp_ZxCuXwEaTOoPx99PR-NhDu2MpoTAA8X8ARUsJgI1yoMgcxvB9zN0jRYWYfzp8CdF0xC08fcH_d6CyrjLsUNR47c-n-p32ZfUslBRJiiWw3WIUoknySsT4MPheK0Jmw80bCtYkotha9UFCYOxsAh593FEZ_hrv6Bys2Y0c-c0Tgmps5Qax Aug 31 17:56:07 volumio volumio[11250]: INFO:librespot_playback::player: SpCon::metadata Aug 31 17:56:07 volumio volumio[1066]: info: [SpConDebug] Pushing metadata::Vollibrespot:true Aug 31 17:56:07 volumio volumio[1066]: info: CoreCommandRouter::servicePushState Aug 31 17:56:07 volumio volumio[1066]: info: CoreStateMachine::syncState Aug 31 17:56:07 volumio volumio[1066]: info: CorePlayQueue::getTrack 0 Aug 31 17:56:07 volumio volumio[1066]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current mpd Received volspotconnect2 Aug 31 17:56:07 volumio volumio[11250]: INFO:librespot_playback::player: Loading track "Wünsch dir was" with Spotify URI "spotify:track:1uwKheREvZPoKTbZ72usSV" Aug 31 17:56:07 volumio wpa_supplicant[10209]: wlan0: Failed to initiate sched scan Aug 31 17:56:08 volumio volumio[11250]: INFO:librespot_playback::player: Track "Wünsch dir was" loaded Aug 31 17:56:08 volumio volumio[11250]: INFO:librespot_playback::player: SpCon::kSpDeviceActive Aug 31 17:56:08 volumio volumio[1066]: info: [SpConDebug] Device is active! Aug 31 17:56:08 volumio volumio[1066]: info: CoreCommandRouter::volumioGetState Aug 31 17:56:08 volumio volumio[1066]: info: CoreStateMachine::getState Aug 31 17:56:08 volumio volumio[1066]: info: [SpConDebug] Currently active:airplay Aug 31 17:56:08 volumio volumio[1066]: info: [SpConDebug] Stopping currently active service Aug 31 17:56:08 volumio volumio[1066]: info: CoreCommandRouter::volumioStop Aug 31 17:56:08 volumio volumio[1066]: info: CoreStateMachine::stop Aug 31 17:56:08 volumio volumio[1066]: info: CoreStateMachine::serviceStop Aug 31 17:56:08 volumio volumio[1066]: info: Received STOP, but no service to execute it Aug 31 17:56:08 volumio volumio[1066]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 31 17:56:08 volumio volumio[1066]: TypeError: Cannot read property 'then' of undefined Aug 31 17:56:08 volumio volumio[1066]: at SpotConnEvents. (/data/plugins/music_service/volspotconnect2/index.js:147:21) Aug 31 17:56:08 volumio volumio[1066]: at emitOne (events.js:96:13) Aug 31 17:56:08 volumio volumio[1066]: at SpotConnEvents.emit (events.js:188:7) Aug 31 17:56:08 volumio volumio[1066]: at SpotConnEvents.parseData (/data/plugins/music_service/volspotconnect2/SpotConnController.js:43:16) Aug 31 17:56:08 volumio volumio[1066]: at Socket.SpotConnEvents.self._udpsource.on.msg (/data/plugins/music_service/volspotconnect2/SpotConnController.js:16:12) Aug 31 17:56:08 volumio volumio[1066]: at emitTwo (events.js:106:13) Aug 31 17:56:08 volumio volumio[1066]: at Socket.emit (events.js:191:7) Aug 31 17:56:08 volumio volumio[1066]: at UDP.onMessage (dgram.js:548:8) Aug 31 17:56:08 volumio volumio[1066]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 31 17:56:08 volumio volumio[11250]: INFO:librespot_playback::player: SpCon::kSpSinkActive Aug 31 17:56:09 volumio sudo[6950]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-08-31 17:55 Aug 31 17:56:09 volumio sudo[6950]: 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="0047b8c9feaa5e4ceb66739aad5c179741acce54" VOLUMIO_FE_VERSION="" VOLUMIO_BE_VERSION="9ec9402ca0a423856feda09b210aa4e517a345ec" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Mon Mar 26 20:20:16 CEST 2018" VOLUMIO_VERSION="2.389" VOLUMIO_HARDWARE="pi"