-- Logs begin at Wed 2024-04-24 16:14:25 UTC, end at Wed 2024-05-01 15:56:31 UTC. --
May 01 15:55:02 volumio-namai wpa_supplicant[1063]: wlan0: Failed to initiate sched scan
May 01 15:55:10 volumio-namai wpa_supplicant[1063]: wlan0: Failed to initiate sched scan
May 01 15:55:17 volumio-namai wpa_supplicant[1063]: wlan0: Failed to initiate sched scan
May 01 15:55:25 volumio-namai wpa_supplicant[1063]: wlan0: Failed to initiate sched scan
May 01 15:55:33 volumio-namai wpa_supplicant[1063]: wlan0: Failed to initiate sched scan
May 01 15:55:41 volumio-namai wpa_supplicant[1063]: wlan0: Failed to initiate sched scan
May 01 15:55:49 volumio-namai wpa_supplicant[1063]: wlan0: Failed to initiate sched scan
May 01 15:55:56 volumio-namai wpa_supplicant[1063]: wlan0: Failed to initiate sched scan
May 01 15:56:02 volumio-namai volumio[1305]: info: CoreCommandRouter::volumioGetQueue
May 01 15:56:02 volumio-namai volumio[1305]: info: CoreStateMachine::getQueue
May 01 15:56:02 volumio-namai volumio[1305]: info: CorePlayQueue::getQueue
May 01 15:56:04 volumio-namai wpa_supplicant[1063]: wlan0: Failed to initiate sched scan
May 01 15:56:05 volumio-namai vtcs[1652]: [2024-05-01 15:56:05] [error] handle_read_frame error: asio.system:104 (Connection reset by peer)
May 01 15:56:05 volumio-namai vtcs[1652]: [2024-05-01 15:56:05] [info] asio async_shutdown error: asio.system:32 (Broken pipe)
May 01 15:56:05 volumio-namai volumio[1305]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
May 01 15:56:05 volumio-namai volumio[1305]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
May 01 15:56:05 volumio-namai volumio[1305]: info: Discovery: Getting this device information
May 01 15:56:05 volumio-namai volumio[1305]: info: CoreCommandRouter::volumioGetState
May 01 15:56:05 volumio-namai volumio[1305]: info: CoreCommandRouter::executeOnPlugin: network , getCachedPAddresses
May 01 15:56:05 volumio-namai volumio[1305]: info: CoreCommandRouter::executeOnPlugin: system , getConf
May 01 15:56:05 volumio-namai volumio[1305]: info: CoreCommandRouter::executeOnPlugin: system , getConf
May 01 15:56:06 volumio-namai volumio[1305]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
May 01 15:56:06 volumio-namai volumio[1305]: info: CoreCommandRouter::executeOnPlugin: my_volumio , detectVolumioHardware
May 01 15:56:06 volumio-namai volumio[1305]: xcb_connection_has_error() returned true
May 01 15:56:08 volumio-namai volumio[1305]: info: Tunnel connection is inactive, restarting it
May 01 15:56:08 volumio-namai volumio[1305]: info: Starting Tunnel 1
May 01 15:56:08 volumio-namai volumio[1305]: info: Starting Tunnel Connection Checker
May 01 15:56:08 volumio-namai sudo[2276]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart sshtunnel.service
May 01 15:56:08 volumio-namai sudo[2276]: pam_unix(sudo:session): session opened for user root by (uid=0)
May 01 15:56:08 volumio-namai systemd[1]: Stopping MyVolumio SSH Tunnel...
May 01 15:56:08 volumio-namai autossh[1567]: received signal to exit (15)
May 01 15:56:08 volumio-namai systemd[1]: Starting MyVolumio SSH Tunnel...
May 01 15:56:08 volumio-namai systemd[1]: Started MyVolumio SSH Tunnel.
May 01 15:56:08 volumio-namai sudo[2276]: pam_unix(sudo:session): session closed for user root
May 01 15:56:08 volumio-namai volumio[1305]: ------------------------------------ BT MESSAGE: BT STATUS: running
May 01 15:56:08 volumio-namai volumio[1305]: BT PLUGIN MESSAGE: Playing: false
May 01 15:56:08 volumio-namai volumio[1305]: BT PLUGIN MESSAGE: VOLATILE: tidalconnect
May 01 15:56:08 volumio-namai volumio[1305]: BT PLUGIN MESSAGE: STATE:undefined
May 01 15:56:08 volumio-namai volumio[1305]: ------------------------------------ BT MESSAGE: BT STATUS: waiting
May 01 15:56:08 volumio-namai volumio[1305]: BT PLUGIN MESSAGE: Playing: false
May 01 15:56:08 volumio-namai autossh[2285]: port set to 0, monitoring disabled
May 01 15:56:08 volumio-namai autossh[2285]: starting ssh (count 1)
May 01 15:56:08 volumio-namai autossh[2285]: ssh child pid is 2289
May 01 15:56:08 volumio-namai volumio[1305]: BT PLUGIN MESSAGE: VOLATILE: tidalconnect
May 01 15:56:08 volumio-namai volumio[1305]: BT PLUGIN MESSAGE: STATE:undefined
May 01 15:56:08 volumio-namai volumio[1305]: info: Remote SSH Started
May 01 15:56:08 volumio-namai volumio[1305]: info: CoreCommandRouter::volumioGetState
May 01 15:56:11 volumio-namai volumiossh-tunnel[2282]: Warning: Permanently added '[eu4.myvolumio.org]:2222,[167.172.103.77]:2222' (RSA) to the list of known hosts.
May 01 15:56:12 volumio-namai wpa_supplicant[1063]: wlan0: Failed to initiate sched scan
May 01 15:56:14 volumio-namai volumio[1305]: info: Downloading plugin at http://plugins.volumio.org/plugins/volumio/armhf/music_service/spop/spop.zip
May 01 15:56:16 volumio-namai volumio[1305]: info: END DOWNLOAD: http://plugins.volumio.org/plugins/volumio/armhf/music_service/spop/spop.zip
May 01 15:56:16 volumio-namai volumio[1305]: info: Folder /tmp/plugins removed
May 01 15:56:17 volumio-namai volumio[1305]: info: Checking if plugin already exists
May 01 15:56:17 volumio-namai volumio[1305]: info: Rename folder
May 01 15:56:17 volumio-namai volumio[1305]: info: Folder /tmp/downloaded_plugin.zip removed
May 01 15:56:17 volumio-namai volumio[1305]: info: Move to category
May 01 15:56:19 volumio-namai volumio[1305]: info: Checking if install.sh is present
May 01 15:56:19 volumio-namai volumio[1305]: info: Executing install.sh
May 01 15:56:20 volumio-namai sudo[2342]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/sh /data/plugins/music_service/spop/install.sh
May 01 15:56:20 volumio-namai sudo[2342]: pam_unix(sudo:session): session opened for user root by (uid=0)
May 01 15:56:20 volumio-namai volumio[1305]: info: Writing systemd unit
May 01 15:56:20 volumio-namai sudo[2342]: pam_unix(sudo:session): session closed for user root
May 01 15:56:20 volumio-namai volumio[1305]: info: Setting permissions
May 01 15:56:20 volumio-namai wpa_supplicant[1063]: wlan0: Failed to initiate sched scan
May 01 15:56:20 volumio-namai volumio[1305]: info: Writing startconnect unit
May 01 15:56:20 volumio-namai volumio[1305]: Plugin install end detected on script
May 01 15:56:20 volumio-namai volumio[1305]: info: Install script completed
May 01 15:56:20 volumio-namai volumio[1305]: info: Adding reference to registry
May 01 15:56:20 volumio-namai volumio[1305]: info: Done installing plugin.
May 01 15:56:20 volumio-namai volumio[1305]: info: Folder /tmp/plugins removed
May 01 15:56:20 volumio-namai volumio[1305]: info: Folder /tmp/downloaded_plugin.zip removed
May 01 15:56:20 volumio-namai volumio[1305]: info: Folder /data/temp removed
May 01 15:56:21 volumio-namai volumio[1305]: info: Enabling plugin spop
May 01 15:56:21 volumio-namai volumio[1305]: info: Loading plugin "spop"...
May 01 15:56:22 volumio-namai volumio[1305]: info: PLUGIN START: spop
May 01 15:56:22 volumio-namai volumio[1305]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
May 01 15:56:22 volumio-namai volumio[1305]: [SpotifyConnect] Creating VLS config file
May 01 15:56:22 volumio-namai volumio[1305]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 01 15:56:22 volumio-namai volumio[1305]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 01 15:56:22 volumio-namai volumio[1305]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
May 01 15:56:22 volumio-namai sudo[2362]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/hosts
May 01 15:56:22 volumio-namai volumio[1305]: [SpotifyConnect] Starting metadata listener
May 01 15:56:22 volumio-namai sudo[2362]: pam_unix(sudo:session): session opened for user root by (uid=0)
May 01 15:56:22 volumio-namai sudo[2362]: pam_unix(sudo:session): session closed for user root
May 01 15:56:22 volumio-namai sudo[2370]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volspotconnect.service
May 01 15:56:22 volumio-namai sudo[2370]: pam_unix(sudo:session): session opened for user root by (uid=0)
May 01 15:56:22 volumio-namai systemd[1]: Starting Volspotconnect2 Daemon...
May 01 15:56:22 volumio-namai systemd[1]: Started Volspotconnect2 Daemon.
May 01 15:56:22 volumio-namai sudo[2370]: pam_unix(sudo:session): session closed for user root
May 01 15:56:22 volumio-namai volumio[2378]: vollibrespot v0.2.5 8922128 2022-05-31 (librespot 08d8bcc 2020-10-07) -- Built On 2022-07-11
May 01 15:56:22 volumio-namai volumio[2378]: Reading Config from "/tmp/volspotify.toml"
May 01 15:56:22 volumio-namai volumio[2378]: [Vollibrespot] : Using Alsa backend with device: plughw:5
May 01 15:56:23 volumio-namai volumio[1305]: [SpotifyConnect] Vollibrespot Daemon service started!
May 01 15:56:23 volumio-namai volumio[1305]: [Metrics] SpotifyConnect: 0s 115.43ms
May 01 15:56:23 volumio-namai volumio[1305]: info: Done.
May 01 15:56:23 volumio-namai volumio[1305]: info: Successfully fixed Spotify hosts
May 01 15:56:23 volumio-namai volumio[2378]: [Vollibrespot] : Failed to register IPv6 receiver: Os { code: 19, kind: Uncategorized, message: "No such device" }
May 01 15:56:27 volumio-namai volumio[1305]: info: Checking Spotify Web API
May 01 15:56:28 volumio-namai wpa_supplicant[1063]: wlan0: Failed to initiate sched scan
May 01 15:56:29 volumio-namai volumio[2378]: [Vollibrespot] : Connecting to AP "ap-gew1.spotify.com:443"
May 01 15:56:30 volumio-namai volumio[2378]: [Vollibrespot] : Authenticated as "93q7odrus0h7l6knee2glq0q7" !
May 01 15:56:30 volumio-namai volumio[2378]: [Vollibrespot] : Using alsa sink
May 01 15:56:30 volumio-namai volumio[2378]: [Vollibrespot] : Metadata pipe established
May 01 15:56:30 volumio-namai volumio[2378]: [Vollibrespot] : Country: "LT"
May 01 15:56:30 volumio-namai volumio[2378]: [Vollibrespot] : Event: Volume { volume_to_mixer: 32768 }
May 01 15:56:30 volumio-namai volumio[1305]: [SpotifyConnect] Volume Spotify: 50.000762951094835 Volumio: 50
May 01 15:56:31 volumio-namai volumio[2378]: [Vollibrespot] : Event: SessionActive { became_active_at: 1714578991105 }
May 01 15:56:31 volumio-namai volumio[2378]: [Vollibrespot] : SessionActive!
May 01 15:56:31 volumio-namai volumio[1305]: [SpotifyConnect] A connect session has begun
May 01 15:56:31 volumio-namai volumio[1305]: info: Acquiring new spotify session
May 01 15:56:31 volumio-namai volumio[1305]: info: CoreCommandRouter::volumioStop
May 01 15:56:31 volumio-namai volumio[1305]: info: CoreStateMachine::stop
May 01 15:56:31 volumio-namai volumio[1305]: info: CoreStateMachine::serviceStop
May 01 15:56:31 volumio-namai volumio[1305]: info: CoreCommandRouter::serviceStop
May 01 15:56:31 volumio-namai volumio[2378]: [Vollibrespot] : Fetching autoplay context uri
May 01 15:56:31 volumio-namai volumio[2378]: [Vollibrespot] : Event: PlaybackStarted { track_id: SpotifyId { id: 321554488295717880364504648136391137553, audio_type: Track } }
May 01 15:56:31 volumio-namai volumio[2378]: [Vollibrespot] : Event: PlaybackLoading { track_id: SpotifyId { id: 321554488295717880364504648136391137553, audio_type: Track } }
May 01 15:56:31 volumio-namai volumio[1305]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
May 01 15:56:31 volumio-namai vtcs[1652]: [2024-05-01 15:56:31.112] [tisoc] [warning] [PlaybackControllerImpl.cpp:472] Illegal state:0
May 01 15:56:31 volumio-namai volumio[1305]: TypeError: Cannot read property 'then' of undefined
May 01 15:56:31 volumio-namai volumio[1305]: at SpotConnEvents.SpotConn.on (/data/plugins/music_service/spop/index.js:2095:31)
May 01 15:56:31 volumio-namai volumio[1305]: at emitNone (events.js:106:13)
May 01 15:56:31 volumio-namai volumio[1305]: at SpotConnEvents.emit (events.js:208:7)
May 01 15:56:31 volumio-namai volumio[1305]: at SpotConnEvents.parseData (/data/plugins/music_service/spop/SpotConnController.js:81:16)
May 01 15:56:31 volumio-namai volumio[1305]: at Socket.SpotConnEvents._udpsource.on.msg (/data/plugins/music_service/spop/SpotConnController.js:15:12)
May 01 15:56:31 volumio-namai volumio[1305]: at emitTwo (events.js:126:13)
May 01 15:56:31 volumio-namai volumio[1305]: at Socket.emit (events.js:214:7)
May 01 15:56:31 volumio-namai volumio[1305]: at UDP.onMessage [as onmessage] (dgram.js:659:8)
May 01 15:56:31 volumio-namai volumio[1305]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
May 01 15:56:31 volumio-namai volumio[2378]: [Vollibrespot] : error 400 for uri hm://autoplay-enabled/query?uri=spotify:search:m%C4%97lynas+aut
May 01 15:56:31 volumio-namai volumio[2378]: [Vollibrespot] : AutoplayError: MercuryError
May 01 15:56:31 volumio-namai volumio[2378]: [Vollibrespot] : Event: GotToken { token: Token { access_token: "BQB6QI6Frzi64iMB6WJyiiaZi563xZpsuknoDIu7e7LKTl870GS1HihKV69yPW9o_RPDDMMopSlxCXJRu-c5WGJl-Rqo6ZbZ1vSZLPOOY37AOwE4wJnpEutbeUlVV5Awy7t8Kf2P0P26iMBLJYka5C4focm9MOZOcLu-RY2NHoa4jVJTvT8VlDs8TWdPGraiiNSEPLXNEGRVbmeMJo2uWWcHIg", expires_in: 3600, token_type: "Bearer", scope: ["streaming", "user-read-playback-state", "user-modify-playback-state", "user-read-currently-playing", "user-read-private"] } }
May 01 15:56:31 volumio-namai volumio[2378]: [Vollibrespot] : Loading with Spotify URI
May 01 15:56:31 volumio-namai sudo[2417]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-05-01 15:55
May 01 15:56:31 volumio-namai sudo[2417]: 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="dd2a4339faaeb892c7f467e7dc8d424aefb0bd03"
VOLUMIO_FE_VERSION="958dedc0edff114f244fa9acc70cf53089d9e5ae"
VOLUMIO_BE_VERSION="fd3e37ffec12db034ec93f94dbc26e5495d5b91a"
VOLUMIO_ARCH="arm"
VOLUMIO_VARIANT="volumio"
VOLUMIO_TEST="FALSE"
VOLUMIO_BUILD_DATE="Wed Oct 6 12:34:49 CEST 2021"
VOLUMIO_VERSION="2.917"
VOLUMIO_HARDWARE="pi"
VOLUMIO_HASH="98c8f08c531a6f0456f17ab17795e35f"