-- Logs begin at Thu 2019-02-14 11:11:59 CET, end at Fri 2024-04-12 20:08:20 CEST. --
Apr 12 20:07:08 badkamer volumio[820]: info: CoreCommandRouter::volumioGetState
Apr 12 20:07:18 badkamer volumio[820]: info: CoreCommandRouter::volumioGetState
Apr 12 20:07:35 badkamer sudo[580]: volumio : TTY=pts/0 ; PWD=/home/volumio ; USER=root ; COMMAND=/bin/systemctl stop volumio.service
Apr 12 20:07:35 badkamer sudo[580]: pam_unix(sudo:session): session opened for user root by volumio(uid=0)
Apr 12 20:07:35 badkamer systemd[1]: Stopping Volumio Backend Module...
Apr 12 20:07:35 badkamer kernel: bcm2835_audio bcm2835_audio: failed to close VCHI service connection (status=1)
Apr 12 20:07:35 badkamer volumio-remote-updater[504]: [2024-04-12 20:07:35] [error] handle_read_frame error: websocketpp.transport:7 (End of File)
Apr 12 20:07:35 badkamer volumio-remote-updater[504]: [2024-04-12 20:07:35] [disconnect] Disconnect close local:[1006,End of File] remote:[1006]
Apr 12 20:07:35 badkamer go-librespot[30193]: time="2024-04-12T20:07:35+02:00" level=error msg="websocket connection errored" error="failed to get reader: failed to read frame header: EOF"
Apr 12 20:07:35 badkamer systemd[1]: volumio.service: Main process exited, code=killed, status=15/TERM
Apr 12 20:07:35 badkamer systemd[1]: volumio.service: Succeeded.
Apr 12 20:07:35 badkamer systemd[1]: Stopped Volumio Backend Module.
Apr 12 20:07:35 badkamer sudo[580]: pam_unix(sudo:session): session closed for user root
Apr 12 20:07:35 badkamer sudo[583]: volumio : TTY=pts/0 ; PWD=/home/volumio ; USER=root ; COMMAND=/bin/systemctl start volumio.service
Apr 12 20:07:35 badkamer sudo[583]: pam_unix(sudo:session): session opened for user root by volumio(uid=0)
Apr 12 20:07:35 badkamer systemd[1]: Started dynamicswap service.
Apr 12 20:07:35 badkamer systemd[1]: Started Volumio Backend Module.
Apr 12 20:07:35 badkamer sudo[583]: pam_unix(sudo:session): session closed for user root
Apr 12 20:07:35 badkamer systemd[1]: dynamicswap.service: Succeeded.
Apr 12 20:07:37 badkamer volumio[587]: info: -------------------------------------------
Apr 12 20:07:37 badkamer volumio[587]: info: ----- Volumio3 ----
Apr 12 20:07:37 badkamer volumio[587]: info: -------------------------------------------
Apr 12 20:07:37 badkamer volumio[587]: info: ----- System startup ----
Apr 12 20:07:37 badkamer volumio[587]: info: -------------------------------------------
Apr 12 20:07:38 badkamer volumio[587]: info: MYVOLUMIO Environment detected
Apr 12 20:07:38 badkamer volumio[587]: info: Plugin folders cleanup
Apr 12 20:07:38 badkamer volumio[587]: info: Scanning into folder /volumio/app/plugins/
Apr 12 20:07:38 badkamer volumio[587]: info: Scanning category audio_interface
Apr 12 20:07:38 badkamer volumio[587]: info: Scanning category miscellanea
Apr 12 20:07:38 badkamer volumio[587]: info: Scanning category music_service
Apr 12 20:07:38 badkamer volumio[587]: info: Scanning category plugins.json
Apr 12 20:07:38 badkamer volumio[587]: info: Scanning category system_controller
Apr 12 20:07:38 badkamer volumio[587]: info: Scanning category user_interface
Apr 12 20:07:38 badkamer volumio[587]: info: Scanning into folder /data/plugins/
Apr 12 20:07:38 badkamer volumio[587]: info: Scanning category audio_interface
Apr 12 20:07:38 badkamer volumio[587]: info: Scanning category music_service
Apr 12 20:07:38 badkamer volumio[587]: info: Plugin folders cleanup completed
Apr 12 20:07:38 badkamer volumio[587]: info: -------------------------------------------
Apr 12 20:07:38 badkamer volumio[587]: info: ----- Core plugins startup ----
Apr 12 20:07:38 badkamer volumio[587]: info: -------------------------------------------
Apr 12 20:07:38 badkamer volumio[587]: info: Loading plugins from folder /volumio/app/plugins/
Apr 12 20:07:38 badkamer volumio[587]: info: Adding plugin upnp to MyMusic Plugins
Apr 12 20:07:38 badkamer volumio[587]: info: Adding plugin airplay_emulation to MyMusic Plugins
Apr 12 20:07:38 badkamer volumio[587]: info: Adding plugin upnp_browser to MyMusic Plugins
Apr 12 20:07:38 badkamer volumio[587]: info: Loading plugins from folder /data/plugins/
Apr 12 20:07:38 badkamer volumio[587]: info: Loading plugin "system"...
Apr 12 20:07:38 badkamer volumio[587]: info: Loading plugin "appearance"...
Apr 12 20:07:39 badkamer volumio[587]: info: Loading plugin "network"...
Apr 12 20:07:39 badkamer volumio[587]: info: Refreshing Cached IP Addresses
Apr 12 20:07:39 badkamer sudo[662]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Apr 12 20:07:39 badkamer sudo[662]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 12 20:07:39 badkamer sudo[662]: pam_unix(sudo:session): session closed for user root
Apr 12 20:07:39 badkamer sudo[664]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Apr 12 20:07:39 badkamer volumio[587]: info: Loading plugin "services"...
Apr 12 20:07:39 badkamer sudo[664]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 12 20:07:39 badkamer volumio[587]: info: Loading plugin "alsa_controller"...
Apr 12 20:07:39 badkamer sudo[664]: pam_unix(sudo:session): session closed for user root
Apr 12 20:07:39 badkamer sudo[668]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwlist wlan0 scan
Apr 12 20:07:39 badkamer sudo[668]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 12 20:07:39 badkamer volumio[587]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Apr 12 20:07:39 badkamer volumio[587]: info: Loading plugin "wizard"...
Apr 12 20:07:39 badkamer volumio[587]: info: Loading plugin "networkfs"...
Apr 12 20:07:39 badkamer volumio[587]: info: Starting Udev Watcher for removable devices
Apr 12 20:07:39 badkamer volumio[587]: info: Ignoring mount for partition: boot
Apr 12 20:07:39 badkamer volumio[587]: info: Ignoring mount for partition: volumio
Apr 12 20:07:39 badkamer volumio[587]: info: Ignoring mount for partition: volumio_data
Apr 12 20:07:39 badkamer volumio[587]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Apr 12 20:07:39 badkamer volumio[587]: info: Loading plugin "volumio_command_line_client"...
Apr 12 20:07:39 badkamer volumio[587]: info: Plugin upnp is not enabled
Apr 12 20:07:39 badkamer volumio[587]: info: Loading plugin "my_music"...
Apr 12 20:07:39 badkamer volumio[587]: info: Loading plugin "mpd"...
Apr 12 20:07:40 badkamer volumio[587]: info: Plugin upnp_browser is not enabled
Apr 12 20:07:40 badkamer volumio[587]: info: Loading plugin "alarm-clock"...
Apr 12 20:07:40 badkamer volumio[587]: info: Loading plugin "airplay_emulation"...
Apr 12 20:07:40 badkamer volumio[587]: info: Starting Shairport Sync
Apr 12 20:07:40 badkamer volumio[587]: info: Loading plugin "last_100"...
Apr 12 20:07:40 badkamer volumio[587]: info: Loading plugin "webradio"...
Apr 12 20:07:40 badkamer volumio[587]: info: Loading plugin "i2s_dacs"...
Apr 12 20:07:40 badkamer volumio[587]: info: I2S DAC not set, start Auto-detection
Apr 12 20:07:40 badkamer volumio[587]: info: Loading plugin "volumiodiscovery"...
Apr 12 20:07:40 badkamer volumio[587]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Apr 12 20:07:40 badkamer volumio[587]: *** WARNING *** Please fix your application to use the native API of Avahi!
Apr 12 20:07:40 badkamer volumio[587]: *** WARNING *** For more information see
Apr 12 20:07:40 badkamer volumio[587]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Apr 12 20:07:40 badkamer node[587]: *** WARNING *** The program 'node' uses the Apple Bonjour compatibility layer of Avahi.
Apr 12 20:07:40 badkamer volumio[587]: *** WARNING *** Please fix your application to use the native API of Avahi!
Apr 12 20:07:40 badkamer volumio[587]: *** WARNING *** For more information see
Apr 12 20:07:40 badkamer node[587]: *** WARNING *** Please fix your application to use the native API of Avahi!
Apr 12 20:07:40 badkamer node[587]: *** WARNING *** For more information see
Apr 12 20:07:40 badkamer node[587]: *** WARNING *** The program 'node' called 'DNSServiceRegister()' which is not supported (or only supported partially) in the Apple Bonjour compatibility layer of Avahi.
Apr 12 20:07:40 badkamer node[587]: *** WARNING *** Please fix your application to use the native API of Avahi!
Apr 12 20:07:40 badkamer node[587]: *** WARNING *** For more information see
Apr 12 20:07:40 badkamer volumio[587]: info: Applying required configuration parameters for plugin volumiodiscovery
Apr 12 20:07:40 badkamer volumio[587]: info: Discovery: Started advertising with name: Badkamer
Apr 12 20:07:40 badkamer volumio-remote-updater[504]: [2024-04-12 20:07:40] [connect] Successful connection
Apr 12 20:07:40 badkamer volumio[587]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback
Apr 12 20:07:40 badkamer volumio[587]: info: Loading plugin "spop"...
Apr 12 20:07:40 badkamer sudo[668]: pam_unix(sudo:session): session closed for user root
Apr 12 20:07:41 badkamer volumio[587]: info: Loading plugin "outputs"...
Apr 12 20:07:41 badkamer volumio[587]: info: Loading plugin "albumart"...
Apr 12 20:07:41 badkamer volumio[587]: info: Plugin example_plugin is not enabled
Apr 12 20:07:41 badkamer volumio[587]: info: Loading plugin "inputs"...
Apr 12 20:07:41 badkamer volumio[587]: info: Loading plugin "updater_comm"...
Apr 12 20:07:41 badkamer volumio[587]: info: Plugin mpdemulation is not enabled
Apr 12 20:07:41 badkamer volumio[587]: info: Loading plugin "rest_api"...
Apr 12 20:07:41 badkamer volumio[587]: info: Loading plugin "websocket"...
Apr 12 20:07:41 badkamer volumio[587]: info: Loading plugin "fusiondsp"...
Apr 12 20:07:42 badkamer volumio[587]: Forking 3 albumart workers
Apr 12 20:07:42 badkamer volumio[587]: info: Applying required configuration parameters for plugin fusiondsp
Apr 12 20:07:42 badkamer volumio[587]: info: Loading i18n strings for locale nl
Apr 12 20:07:42 badkamer volumio[587]: Updating browse sources language
Apr 12 20:07:42 badkamer volumio[587]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Apr 12 20:07:42 badkamer volumio[587]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Apr 12 20:07:42 badkamer volumio[587]: info: CoreCommandRouter::initPlayerControls
Apr 12 20:07:42 badkamer volumio[587]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 12 20:07:42 badkamer volumio[587]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 12 20:07:42 badkamer volumio[587]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 12 20:07:42 badkamer volumio[587]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 12 20:07:42 badkamer volumio[587]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 12 20:07:42 badkamer volumio[587]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 12 20:07:42 badkamer volumio[587]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 12 20:07:42 badkamer volumio[587]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 12 20:07:42 badkamer volumio[587]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam
Apr 12 20:07:42 badkamer volumio[587]: Express server listening on port 3000
Apr 12 20:07:42 badkamer volumio[587]: [Metrics] WebUI: 5s 758.88ms
Apr 12 20:07:42 badkamer volumio[587]: info: CoreStateMachine::resetVolumioState
Apr 12 20:07:42 badkamer volumio[587]: info: CoreStateMachine::getcurrentVolume
Apr 12 20:07:42 badkamer volumio[587]: info: CoreCommandRouter::volumioRetrievevolume
Apr 12 20:07:42 badkamer volumio[587]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Apr 12 20:07:42 badkamer volumio[587]: verbose: New Socket.io Connection to 192.168.0.253 from 192.168.0.228 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/123.0.0.0 Safari/537.36 Total Clients: 1
Apr 12 20:07:43 badkamer volumio-remote-updater[504]: [2024-04-12 20:07:43] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1712945260 101
Apr 12 20:07:43 badkamer volumio[587]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Total Clients: 2
Apr 12 20:07:43 badkamer volumio[587]: verbose: New Socket.io Connection to 192.168.0.253 from 192.168.0.228 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/123.0.0.0 Safari/537.36 Total Clients: 3
Apr 12 20:07:43 badkamer volumio[587]: verbose: New Socket.io Connection to 192.168.0.253:3000 from 192.168.0.254 UA: node-XMLHttpRequest Total Clients: 4
Apr 12 20:07:43 badkamer volumio[587]: info: CoreCommandRouter::volumioGetState
Apr 12 20:07:43 badkamer volumio[587]: info: CorePlayQueue::getTrack 0
Apr 12 20:07:43 badkamer volumio[587]: info: Reloading queue from file
Apr 12 20:07:43 badkamer volumio[587]: info: VolumeController:: Volume=44 Mute =false
Apr 12 20:07:43 badkamer volumio[587]: info: CoreStateMachine::pushState
Apr 12 20:07:43 badkamer volumio[587]: info: CorePlayQueue::getTrack 0
Apr 12 20:07:43 badkamer volumio[587]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Apr 12 20:07:43 badkamer volumio[587]: info: CoreCommandRouter::volumioPushState
Apr 12 20:07:43 badkamer volumio[587]: info: CoreStateMachine::updateTrackBlock
Apr 12 20:07:43 badkamer volumio[587]: info: CorePlayQueue::getTrackBlock
Apr 12 20:07:43 badkamer volumio[587]: info: CoreCommandRouter::volumioRetrievevolume
Apr 12 20:07:43 badkamer volumio[587]: Starting albumart workers
Apr 12 20:07:43 badkamer volumio[587]: Starting albumart workers
Apr 12 20:07:43 badkamer volumio[587]: info: Setting Device type: Raspberry PI
Apr 12 20:07:43 badkamer volumio[587]: info: CoreStateMachine::setRepeat null single undefined
Apr 12 20:07:43 badkamer volumio[587]: info: CoreStateMachine::pushState
Apr 12 20:07:43 badkamer volumio[587]: info: CorePlayQueue::getTrack 0
Apr 12 20:07:43 badkamer volumio[587]: info: CoreCommandRouter::volumioPushState
Apr 12 20:07:43 badkamer volumio[587]: info: CoreStateMachine::setRandom null
Apr 12 20:07:43 badkamer volumio[587]: info: CoreStateMachine::pushState
Apr 12 20:07:43 badkamer volumio[587]: info: CorePlayQueue::getTrack 0
Apr 12 20:07:43 badkamer volumio[587]: info: CoreCommandRouter::volumioPushState
Apr 12 20:07:43 badkamer volumio[587]: info: Discovery: adding ca1e79c3-843a-4bff-89ba-7436a862d7e5
Apr 12 20:07:43 badkamer volumio[587]: info: Discovery: Found device Versterker
Apr 12 20:07:43 badkamer volumio[587]: Starting albumart workers
Apr 12 20:07:43 badkamer volumio[587]: info: Discovery: Connecting to remote: 192.168.0.254
Apr 12 20:07:43 badkamer volumio[587]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , initSocket
Apr 12 20:07:43 badkamer volumio[587]: info: CoreCommandRouter::volumioGetState
Apr 12 20:07:43 badkamer volumio[587]: info: CorePlayQueue::getTrack 0
Apr 12 20:07:43 badkamer volumio[587]: info: Discovery: adding 6c5bd8de-8264-40cd-a810-150d93a6a8d3
Apr 12 20:07:43 badkamer volumio[587]: info: Discovery: Found device Badkamer
Apr 12 20:07:43 badkamer volumio[587]: info: CoreCommandRouter::volumioGetState
Apr 12 20:07:43 badkamer volumio[587]: info: CorePlayQueue::getTrack 0
Apr 12 20:07:43 badkamer volumio[587]: info: VolumeController:: Volume=44 Mute =false
Apr 12 20:07:43 badkamer volumio[587]: info: CoreStateMachine::pushState
Apr 12 20:07:43 badkamer volumio[587]: info: CorePlayQueue::getTrack 0
Apr 12 20:07:43 badkamer volumio[587]: info: CoreCommandRouter::volumioPushState
Apr 12 20:07:43 badkamer volumio[587]: info: Discovery: Connected to remote: 192.168.0.254
Apr 12 20:07:53 badkamer volumio[587]: info: CoreCommandRouter::volumioGetState
Apr 12 20:07:53 badkamer volumio[587]: info: CorePlayQueue::getTrack 0
Apr 12 20:07:55 badkamer go-librespot[30193]: time="2024-04-12T20:07:55+02:00" level=debug msg="handling transfer player command from e41e6e21657a3e547616abf732378a36c228c3e2"
Apr 12 20:07:55 badkamer go-librespot[30193]: time="2024-04-12T20:07:55+02:00" level=trace msg="fetched new page 0 with 35 items (list: 35)"
Apr 12 20:07:55 badkamer go-librespot[30193]: time="2024-04-12T20:07:55+02:00" level=debug msg="shuffled context with seed 8338342994377961816 (len: 35, keep: 10)"
Apr 12 20:07:55 badkamer go-librespot[30193]: time="2024-04-12T20:07:55+02:00" level=debug msg="loading track spotify:track:6tGCxVJPo7iIydUVHOjVbM (paused: false, position: 2534ms)"
Apr 12 20:07:55 badkamer go-librespot[30193]: time="2024-04-12T20:07:55+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Apr 12 20:07:55 badkamer go-librespot[30193]: time="2024-04-12T20:07:55+02:00" level=trace msg="emitting websocket event: will_play"
Apr 12 20:07:55 badkamer go-librespot[30193]: time="2024-04-12T20:07:55+02:00" level=debug msg="selected format OGG_VORBIS_320 for spotify:track:6tGCxVJPo7iIydUVHOjVbM"
Apr 12 20:07:55 badkamer go-librespot[30193]: time="2024-04-12T20:07:55+02:00" level=debug msg="requested aes key for file cbca793c1205cdd6c14a103807f764821c1b872e, gid: 6tGCxVJPo7iIydUVHOjVbM"
Apr 12 20:07:56 badkamer go-librespot[30193]: time="2024-04-12T20:07:56+02:00" level=debug msg="fetched first chunk of 18, total size is 9046756 bytes"
Apr 12 20:07:56 badkamer go-librespot[30193]: time="2024-04-12T20:07:56+02:00" level=warning msg="reducing track normalisation factor to prevent clipping, please add negative pregain to avoid"
Apr 12 20:07:56 badkamer go-librespot[30193]: time="2024-04-12T20:07:56+02:00" level=trace msg="seek to 2534ms (diff: 138ms, samples: 111749, bytes: 87159)"
Apr 12 20:07:56 badkamer go-librespot[30193]: time="2024-04-12T20:07:56+02:00" level=info msg="loaded track \"Falling Apart\" (uri: spotify:track:6tGCxVJPo7iIydUVHOjVbM, paused: false, position: 2534ms, duration: 206616ms)"
Apr 12 20:07:56 badkamer go-librespot[30193]: time="2024-04-12T20:07:56+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 241"
Apr 12 20:07:56 badkamer go-librespot[30193]: time="2024-04-12T20:07:56+02:00" level=debug msg="fetched chunk 1/17, size: 524288"
Apr 12 20:07:56 badkamer go-librespot[30193]: time="2024-04-12T20:07:56+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Apr 12 20:07:56 badkamer go-librespot[30193]: time="2024-04-12T20:07:56+02:00" level=trace msg="emitting websocket event: metadata"
Apr 12 20:07:56 badkamer go-librespot[30193]: time="2024-04-12T20:07:56+02:00" level=trace msg="emitting websocket event: active"
Apr 12 20:07:56 badkamer go-librespot[30193]: time="2024-04-12T20:07:56+02:00" level=debug msg="sending successful reply for delaer request"
Apr 12 20:07:56 badkamer go-librespot[30193]: time="2024-04-12T20:07:56+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update
Apr 12 20:07:56 badkamer go-librespot[30193]: time="2024-04-12T20:07:56+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Apr 12 20:07:56 badkamer go-librespot[30193]: time="2024-04-12T20:07:56+02:00" level=trace msg="emitting websocket event: playing"
Apr 12 20:07:56 badkamer go-librespot[30193]: time="2024-04-12T20:07:56+02:00" level=debug msg="fetched chunk 2/17, size: 524288"
Apr 12 20:07:56 badkamer go-librespot[30193]: time="2024-04-12T20:07:56+02:00" level=debug msg="fetched chunk 3/17, size: 524288"
Apr 12 20:07:58 badkamer volumio[587]: info: Getting Push Notification urls
Apr 12 20:07:58 badkamer volumio[587]: info: Adding Push Notification url
Apr 12 20:08:06 badkamer go-librespot[30193]: time="2024-04-12T20:08:06+02:00" level=debug msg="update volume to 32767/65535"
Apr 12 20:08:07 badkamer go-librespot[30193]: time="2024-04-12T20:08:07+02:00" level=debug msg="put connect state because VOLUME_CHANGED"
Apr 12 20:08:07 badkamer go-librespot[30193]: time="2024-04-12T20:08:07+02:00" level=trace msg="emitting websocket event: volume"
Apr 12 20:08:07 badkamer go-librespot[30193]: time="2024-04-12T20:08:07+02:00" level=debug msg="update volume to 36699/65535"
Apr 12 20:08:07 badkamer go-librespot[30193]: time="2024-04-12T20:08:07+02:00" level=debug msg="put connect state because VOLUME_CHANGED"
Apr 12 20:08:07 badkamer go-librespot[30193]: time="2024-04-12T20:08:07+02:00" level=trace msg="emitting websocket event: volume"
Apr 12 20:08:08 badkamer go-librespot[30193]: time="2024-04-12T20:08:08+02:00" level=debug msg="update volume to 32767/65535"
Apr 12 20:08:08 badkamer go-librespot[30193]: time="2024-04-12T20:08:08+02:00" level=debug msg="put connect state because VOLUME_CHANGED"
Apr 12 20:08:08 badkamer go-librespot[30193]: time="2024-04-12T20:08:08+02:00" level=trace msg="emitting websocket event: volume"
Apr 12 20:08:08 badkamer go-librespot[30193]: time="2024-04-12T20:08:08+02:00" level=debug msg="update volume to 36699/65535"
Apr 12 20:08:09 badkamer go-librespot[30193]: time="2024-04-12T20:08:09+02:00" level=debug msg="put connect state because VOLUME_CHANGED"
Apr 12 20:08:09 badkamer go-librespot[30193]: time="2024-04-12T20:08:09+02:00" level=trace msg="emitting websocket event: volume"
Apr 12 20:08:12 badkamer volumio[587]: error: Plugin system_controller system failed to complete 'onVolumioStart' in a timely fashion
Apr 12 20:08:12 badkamer volumio[587]: info: Preparing to generate the ALSA configuration file
Apr 12 20:08:12 badkamer volumio[587]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf
Apr 12 20:08:12 badkamer volumio[587]: info: Reading ALSA contributions from plugins.
Apr 12 20:08:12 badkamer volumio[587]: info: Asound.conf file unchanged, so no further update is needed
Apr 12 20:08:12 badkamer volumio[587]: info: Output device has changed, restarting MPD
Apr 12 20:08:12 badkamer sudo[751]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Apr 12 20:08:12 badkamer volumio[587]: info: Output device has changed, restarting Shairport Sync
Apr 12 20:08:12 badkamer sudo[751]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 12 20:08:12 badkamer volumio[587]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 12 20:08:12 badkamer volumio[587]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Apr 12 20:08:12 badkamer sudo[751]: pam_unix(sudo:session): session closed for user root
Apr 12 20:08:12 badkamer sudo[753]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Apr 12 20:08:12 badkamer sudo[753]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 12 20:08:12 badkamer systemd[1]: Stopping Music Player Daemon...
Apr 12 20:08:12 badkamer systemd[1]: mpd.service: Succeeded.
Apr 12 20:08:12 badkamer systemd[1]: Stopped Music Player Daemon.
Apr 12 20:08:12 badkamer volumio[587]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Apr 12 20:08:12 badkamer volumio[587]: info: ___________ START PLUGINS ___________
Apr 12 20:08:12 badkamer volumio[587]: info: ControllerMpd::onStart: Initializing MPD
Apr 12 20:08:12 badkamer volumio[587]: info: Creating MPD Configuration file
Apr 12 20:08:12 badkamer sudo[762]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Apr 12 20:08:12 badkamer sudo[762]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 12 20:08:12 badkamer volumio[587]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 12 20:08:12 badkamer volumio[587]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Apr 12 20:08:12 badkamer sudo[762]: pam_unix(sudo:session): session closed for user root
Apr 12 20:08:12 badkamer systemd[1]: Starting Music Player Daemon...
Apr 12 20:08:12 badkamer sudo[767]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Apr 12 20:08:12 badkamer sudo[767]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 12 20:08:12 badkamer systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM
Apr 12 20:08:12 badkamer systemd[1]: mpd.service: Succeeded.
Apr 12 20:08:12 badkamer systemd[1]: Stopped Music Player Daemon.
Apr 12 20:08:12 badkamer systemd[1]: Starting Music Player Daemon...
Apr 12 20:08:12 badkamer volumio[587]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Apr 12 20:08:12 badkamer volumio[587]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 12 20:08:12 badkamer volumio[587]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Apr 12 20:08:12 badkamer volumio[587]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Apr 12 20:08:12 badkamer volumio[587]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Apr 12 20:08:12 badkamer volumio[587]: info: [1712945292768] CoreMusicLibrary::Adding element Last_100
Apr 12 20:08:12 badkamer volumio[587]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Apr 12 20:08:12 badkamer volumio[587]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Apr 12 20:08:12 badkamer volumio[587]: info: [1712945292780] CoreMusicLibrary::Adding element Webradio
Apr 12 20:08:12 badkamer volumio[587]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Apr 12 20:08:12 badkamer volumio[587]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Apr 12 20:08:12 badkamer volumio[587]: info: Creating Spotify config file
Apr 12 20:08:12 badkamer volumio[587]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 12 20:08:12 badkamer go-librespot[30193]: time="2024-04-12T20:08:12+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 241"
Apr 12 20:08:12 badkamer volumio[587]: info: Loading i18n strings for locale nl
Apr 12 20:08:12 badkamer volumio[587]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile
Apr 12 20:08:12 badkamer volumio[587]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 12 20:08:12 badkamer volumio[587]: info: FusionDsp - mixtype--------------------- Hardware
Apr 12 20:08:12 badkamer volumio[587]: info: Volumio Calling Home
Apr 12 20:08:12 badkamer go-librespot[30193]: time="2024-04-12T20:08:12+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update
Apr 12 20:08:12 badkamer volumio[587]: info: Preparing to generate the ALSA configuration file
Apr 12 20:08:13 badkamer volumio[587]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf
Apr 12 20:08:13 badkamer volumio[587]: info: Reading ALSA contributions from plugins.
Apr 12 20:08:13 badkamer volumio[587]: info: MPD Permissions set
Apr 12 20:08:13 badkamer volumio[587]: info: MPD Permissions set
Apr 12 20:08:13 badkamer volumio[587]: info: Spotify config file written
Apr 12 20:08:13 badkamer volumio[587]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 5
Apr 12 20:08:13 badkamer volumio[587]: info: Volumio called home
Apr 12 20:08:13 badkamer sudo[781]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service
Apr 12 20:08:13 badkamer sudo[781]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 12 20:08:13 badkamer volumio[587]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 12 20:08:13 badkamer volumio[587]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 12 20:08:13 badkamer volumio[587]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 12 20:08:13 badkamer volumio[587]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 12 20:08:13 badkamer volumio[587]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 12 20:08:13 badkamer volumio[587]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 12 20:08:13 badkamer volumio[587]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 12 20:08:13 badkamer systemd[1]: Stopping go-librespot Daemon...
Apr 12 20:08:13 badkamer systemd[1]: go-librespot-daemon.service: Main process exited, code=killed, status=15/TERM
Apr 12 20:08:13 badkamer systemd[1]: go-librespot-daemon.service: Succeeded.
Apr 12 20:08:13 badkamer systemd[1]: Stopped go-librespot Daemon.
Apr 12 20:08:13 badkamer volumio[587]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Apr 12 20:08:13 badkamer volumio[587]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 12 20:08:13 badkamer volumio[587]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 12 20:08:13 badkamer volumio[587]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 12 20:08:13 badkamer volumio[587]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 12 20:08:13 badkamer volumio[587]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 12 20:08:13 badkamer volumio[587]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 12 20:08:13 badkamer volumio[587]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 12 20:08:13 badkamer volumio[587]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 12 20:08:13 badkamer volumio[587]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 12 20:08:13 badkamer systemd[1]: Started go-librespot Daemon.
Apr 12 20:08:13 badkamer go-librespot[784]: Librespot-go daemon starting...
Apr 12 20:08:13 badkamer sudo[781]: pam_unix(sudo:session): session closed for user root
Apr 12 20:08:13 badkamer go-librespot[784]: time="2024-04-12T20:08:13+02:00" level=info msg="generated new device id: aa2db1f42557b28c19b6f0abc88f03a27be30461"
Apr 12 20:08:13 badkamer go-librespot[784]: time="2024-04-12T20:08:13+02:00" level=debug msg="stored credentials found for jx616n9bbgb1ojonzhjwb27gh"
Apr 12 20:08:13 badkamer volumio[587]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Apr 12 20:08:13 badkamer volumio[587]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 12 20:08:13 badkamer volumio[587]: info: Starting Shairport Sync
Apr 12 20:08:13 badkamer volumio[587]: info: Starting Shairport Sync
Apr 12 20:08:13 badkamer sudo[799]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Apr 12 20:08:13 badkamer volumio[587]: info: Starting Shairport Sync
Apr 12 20:08:13 badkamer sudo[799]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 12 20:08:13 badkamer systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver...
Apr 12 20:08:13 badkamer systemd[1]: shairport-sync.service: Succeeded.
Apr 12 20:08:13 badkamer systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver.
Apr 12 20:08:13 badkamer sudo[802]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Apr 12 20:08:13 badkamer sudo[802]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 12 20:08:13 badkamer sudo[804]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Apr 12 20:08:13 badkamer systemd[1]: Started Shairport Sync - AirPlay Audio Receiver.
Apr 12 20:08:13 badkamer volumio[587]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------
Apr 12 20:08:13 badkamer volumio[587]: SPOTIFY: BQBVPrP0tcHP0FQ1HXa9oduSDal22U9p-P3miKFkcJj6Oq6Xu6j4oAQQ7z8FiHrxAiGxU-xcIl_h4tUqpynEU4FeSxt5qMc6NYYDrLOhJqSvVZ3VC7APnbZRsTVW3jy82hXh7yqhHCVB_l1CgPRyXb-tY6sILdOykGd7bPcRsRRnBIct0dBEtCa6bNN9Mz0QxPp4Z8WqpJcJaBIQyiiyhHlYe1PjPsCS2XaLZZohp3YydygpydAOyQu4HoNmM0abc57WZaM
Apr 12 20:08:13 badkamer volumio[587]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------
Apr 12 20:08:13 badkamer volumio[587]: info: New Spotify access token = BQBVPrP0tcHP0FQ1HXa9oduSDal22U9p-P3miKFkcJj6Oq6Xu6j4oAQQ7z8FiHrxAiGxU-xcIl_h4tUqpynEU4FeSxt5qMc6NYYDrLOhJqSvVZ3VC7APnbZRsTVW3jy82hXh7yqhHCVB_l1CgPRyXb-tY6sILdOykGd7bPcRsRRnBIct0dBEtCa6bNN9Mz0QxPp4Z8WqpJcJaBIQyiiyhHlYe1PjPsCS2XaLZZohp3YydygpydAOyQu4HoNmM0abc57WZaM
Apr 12 20:08:13 badkamer volumio[587]: info: Spotify credentials grant success - running version from March 24, 2019
Apr 12 20:08:13 badkamer sudo[799]: pam_unix(sudo:session): session closed for user root
Apr 12 20:08:13 badkamer systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver...
Apr 12 20:08:13 badkamer systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM
Apr 12 20:08:13 badkamer systemd[1]: shairport-sync.service: Succeeded.
Apr 12 20:08:13 badkamer sudo[804]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 12 20:08:13 badkamer systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver.
Apr 12 20:08:13 badkamer systemd[1]: Started Shairport Sync - AirPlay Audio Receiver.
Apr 12 20:08:13 badkamer sudo[802]: pam_unix(sudo:session): session closed for user root
Apr 12 20:08:13 badkamer systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver...
Apr 12 20:08:13 badkamer systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM
Apr 12 20:08:13 badkamer systemd[1]: shairport-sync.service: Succeeded.
Apr 12 20:08:13 badkamer systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver.
Apr 12 20:08:13 badkamer volumio[587]: info: Asound.conf file unchanged, so no further update is needed
Apr 12 20:08:13 badkamer volumio[587]: info: Output device has changed, restarting MPD
Apr 12 20:08:13 badkamer systemd[1]: Started Shairport Sync - AirPlay Audio Receiver.
Apr 12 20:08:13 badkamer sudo[804]: pam_unix(sudo:session): session closed for user root
Apr 12 20:08:13 badkamer go-librespot[784]: time="2024-04-12T20:08:13+02:00" level=debug msg="obtained new client token: AADbtQ8NP0GbNGN/p31hXBymkoyObjuSAd2Kzqk6SXWEDXzluUE30VDPpdRbazZjVVjJqrMi2tL8XG/G+G31LwotuAq+SUzEbQEBztonZ2gslqM3IHHI3ml9N07uaUb4/DOUXjV3JuY7n+YxkXbu0vbjwXJPtUfMKemwIi7V8HEKEym1ySqEq9qeSzG10VGDkrdMXcsjIlTmYKjRT2r3wX5UcgD7uBHwpyv2/ziIw4Ia6ceIIQ6lP2lv56oK5Yb1"
Apr 12 20:08:13 badkamer volumio[587]: info: Output device has changed, restarting Shairport Sync
Apr 12 20:08:13 badkamer volumio[587]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 12 20:08:13 badkamer volumio[587]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Apr 12 20:08:13 badkamer sudo[812]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf
Apr 12 20:08:13 badkamer sudo[812]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 12 20:08:13 badkamer sudo[812]: pam_unix(sudo:session): session closed for user root
Apr 12 20:08:13 badkamer sudo[817]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service
Apr 12 20:08:13 badkamer sudo[817]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 12 20:08:13 badkamer go-librespot[784]: time="2024-04-12T20:08:13+02:00" level=debug msg="fetched new accesspoints: [ap-gew4.spotify.com:4070 ap-gew4.spotify.com:443 ap-gew4.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gae2.spotify.com:80]"
Apr 12 20:08:13 badkamer volumio[587]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
Apr 12 20:08:13 badkamer systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM
Apr 12 20:08:13 badkamer systemd[1]: mpd.service: Succeeded.
Apr 12 20:08:13 badkamer systemd[1]: Stopped Music Player Daemon.
Apr 12 20:08:13 badkamer volumio[587]: info: Shairport-Sync Started
Apr 12 20:08:13 badkamer volumio[587]: Error adding Membership: Error: addMembership EINVAL
Apr 12 20:08:13 badkamer volumio[587]: info: Shairport-Sync Started
Apr 12 20:08:13 badkamer volumio[587]: info: MPD Permissions set
Apr 12 20:08:13 badkamer volumio[587]: info: Shairport-Sync Started
Apr 12 20:08:13 badkamer volumio[587]: info: CoreCommandRouter::volumioGetState
Apr 12 20:08:13 badkamer volumio[587]: info: CorePlayQueue::getTrack 0
Apr 12 20:08:13 badkamer go-librespot[784]: time="2024-04-12T20:08:13+02:00" level=debug msg="completed keyexchange"
Apr 12 20:08:13 badkamer systemd[1]: Starting Music Player Daemon...
Apr 12 20:08:13 badkamer volumio[587]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 12 20:08:13 badkamer volumio[587]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 12 20:08:13 badkamer volumio[587]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 12 20:08:13 badkamer volumio[587]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 12 20:08:13 badkamer volumio[587]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 12 20:08:13 badkamer volumio[587]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 12 20:08:13 badkamer volumio[587]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 12 20:08:13 badkamer volumio[587]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 12 20:08:13 badkamer volumio[587]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam
Apr 12 20:08:13 badkamer volumio[587]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 12 20:08:13 badkamer volumio[587]: info: Starting Shairport Sync
Apr 12 20:08:13 badkamer volumio[587]: SPOTIFY: User informations: {"display_name":"Jelmer","external_urls":{"spotify":"https://open.spotify.com/user/jx616n9bbgb1ojonzhjwb27gh"},"href":"https://api.spotify.com/v1/users/jx616n9bbgb1ojonzhjwb27gh","id":"jx616n9bbgb1ojonzhjwb27gh","images":[],"type":"user","uri":"spotify:user:jx616n9bbgb1ojonzhjwb27gh","followers":{"href":null,"total":0},"country":"NL","product":"premium","explicit_content":{"filter_enabled":false,"filter_locked":false},"email":"jelmerbrand@outlook.com"}
Apr 12 20:08:13 badkamer volumio[587]: info: Spotify Successfully logged in
Apr 12 20:08:13 badkamer sudo[832]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync
Apr 12 20:08:13 badkamer sudo[832]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 12 20:08:13 badkamer volumio[587]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object]
Apr 12 20:08:13 badkamer volumio[587]: info: [1712945293983] CoreMusicLibrary::Adding element Spotify
Apr 12 20:08:13 badkamer volumio[587]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Apr 12 20:08:13 badkamer volumio[587]: Cannot find translation for source Spotify
Apr 12 20:08:14 badkamer systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver...
Apr 12 20:08:14 badkamer systemd[1]: shairport-sync.service: Succeeded.
Apr 12 20:08:14 badkamer systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver.
Apr 12 20:08:14 badkamer volumio[587]: info: CoreCommandRouter::volumioGetState
Apr 12 20:08:14 badkamer volumio[587]: info: CorePlayQueue::getTrack 0
Apr 12 20:08:14 badkamer systemd[1]: Started Shairport Sync - AirPlay Audio Receiver.
Apr 12 20:08:14 badkamer sudo[832]: pam_unix(sudo:session): session closed for user root
Apr 12 20:08:14 badkamer volumio[587]: info: Shairport-Sync Started
Apr 12 20:08:14 badkamer go-librespot[784]: time="2024-04-12T20:08:14+02:00" level=debug msg="completed challenge"
Apr 12 20:08:14 badkamer go-librespot[784]: time="2024-04-12T20:08:14+02:00" level=debug msg="authenticated as jx616n9bbgb1ojonzhjwb27gh"
Apr 12 20:08:14 badkamer go-librespot[784]: time="2024-04-12T20:08:14+02:00" level=debug msg="authenticated as jx616n9bbgb1ojonzhjwb27gh"
Apr 12 20:08:14 badkamer go-librespot[784]: time="2024-04-12T20:08:14+02:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 guc3-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443]"
Apr 12 20:08:14 badkamer go-librespot[784]: time="2024-04-12T20:08:14+02:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]"
Apr 12 20:08:14 badkamer go-librespot[784]: time="2024-04-12T20:08:14+02:00" level=debug msg="dealer connection opened"
Apr 12 20:08:14 badkamer go-librespot[784]: time="2024-04-12T20:08:14+02:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336"
Apr 12 20:08:14 badkamer go-librespot[784]: time="2024-04-12T20:08:14+02:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2"
Apr 12 20:08:14 badkamer go-librespot[784]: time="2024-04-12T20:08:14+02:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17"
Apr 12 20:08:14 badkamer go-librespot[784]: time="2024-04-12T20:08:14+02:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0"
Apr 12 20:08:14 badkamer go-librespot[784]: time="2024-04-12T20:08:14+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 513"
Apr 12 20:08:14 badkamer go-librespot[784]: time="2024-04-12T20:08:14+02:00" level=debug msg="received connection id: OTZlNWY4MmUtZDIzMi00MmEwLTk1NTQtNjM0YTAyMjhkMGYzK2RlYWxlcit0Y3A6Ly9nZXc0LWRlYWxlci1hLXpwbTYuZ2V3NC5zcG90aWZ5Lm5ldDo1NzAwKzIwRjRCRTFGQTMyRDc3NUJCRjIyQzM1RTAwOTU1QTZDMzY5MUYyQTAxNTNDOENDREI4Q0QxOUU1N0ZFQjIzQTg="
Apr 12 20:08:14 badkamer volumio[587]: /usr/bin/mkfifo: cannot create fifo '/tmp/fusiondspfifo': File exists
Apr 12 20:08:14 badkamer volumio[587]: error: FusionDsp - ----failed to create fusiondspfifo :Error: Command failed: /bin/touch /tmp/fusiondsp_stream_params.log && /bin/chmod 666 /tmp/fusiondsp_stream_params.log && /bin/touch /tmp/camilladsp.log && /bin/chmod 666 /tmp/camilladsp.log && /usr/bin/mkfifo -m 646 /tmp/fusiondspfifo
Apr 12 20:08:14 badkamer volumio[587]: /usr/bin/mkfifo: cannot create fifo '/tmp/fusiondspfifo': File exists
Apr 12 20:08:14 badkamer volumio[587]: info: camilladsp spawned new process with pid 845, instance 1, run: true
Apr 12 20:08:14 badkamer volumio[587]: info: camilladsp service started and running in background, instance 1
Apr 12 20:08:14 badkamer volumio[587]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
Apr 12 20:08:15 badkamer mpd[822]: Apr 12 20:08 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg
Apr 12 20:08:15 badkamer systemd[1]: Started Music Player Daemon.
Apr 12 20:08:15 badkamer sudo[753]: pam_unix(sudo:session): session closed for user root
Apr 12 20:08:15 badkamer sudo[767]: pam_unix(sudo:session): session closed for user root
Apr 12 20:08:15 badkamer sudo[817]: pam_unix(sudo:session): session closed for user root
Apr 12 20:08:15 badkamer volumio[587]: info: FusionDsp - AAAAAAAAAAAAAA-> 22050 44100 48000 88200 96000 176400 192000 <-AAAAAAAAAAAAA
Apr 12 20:08:15 badkamer go-librespot[784]: time="2024-04-12T20:08:15+02:00" level=debug msg="put connect state because NEW_DEVICE"
Apr 12 20:08:15 badkamer volumio[587]: info: FusionDsp loaded
Apr 12 20:08:15 badkamer volumio[587]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Apr 12 20:08:15 badkamer sudo[857]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start fusiondsp.service
Apr 12 20:08:15 badkamer sudo[857]: pam_unix(sudo:session): session opened for user root by (uid=0)
Apr 12 20:08:15 badkamer volumio[587]: info: FusionDsp - Reporting Fusion DSP Enabled
Apr 12 20:08:15 badkamer volumio[587]: info: Adding Signal Path Element [object Object]
Apr 12 20:08:15 badkamer volumio[587]: info: Adding fusiondspeq DSP Signal Path Element
Apr 12 20:08:15 badkamer volumio[587]: info: FusionDsp - ---- installed callbackRead
Apr 12 20:08:15 badkamer sudo[857]: pam_unix(sudo:session): session closed for user root
Apr 12 20:08:15 badkamer volumio[587]: info: Completed starting Core Plugins
Apr 12 20:08:15 badkamer volumio[587]: info: -------------------------------------------
Apr 12 20:08:15 badkamer volumio[587]: info: ----- MyVolumio plugins startup ----
Apr 12 20:08:15 badkamer volumio[587]: info: -------------------------------------------
Apr 12 20:08:15 badkamer volumio[587]: info: [MyVolumio PluginManager] Fetching plans data....
Apr 12 20:08:15 badkamer volumio[587]: info: FusionDsp - If filter freq >samplerate/2 then disable it
Apr 12 20:08:15 badkamer volumio[587]: info: MPD running with PID822
Apr 12 20:08:15 badkamer volumio[587]: ,establishing connection
Apr 12 20:08:15 badkamer volumio[587]: error: MPD error: The expression evaluated to a falsy value:
Apr 12 20:08:15 badkamer volumio[587]: assert.ok(self.idling)
Apr 12 20:08:15 badkamer volumio[587]: error: The expression evaluated to a falsy value:
Apr 12 20:08:15 badkamer volumio[587]: assert.ok(self.idling)
Apr 12 20:08:15 badkamer volumio[587]: error: MPD error: The expression evaluated to a falsy value:
Apr 12 20:08:15 badkamer volumio[587]: assert.ok(self.idling)
Apr 12 20:08:15 badkamer volumio[587]: error: The expression evaluated to a falsy value:
Apr 12 20:08:15 badkamer volumio[587]: assert.ok(self.idling)
Apr 12 20:08:15 badkamer volumio[587]: error: MPD error: The expression evaluated to a falsy value:
Apr 12 20:08:15 badkamer volumio[587]: assert.ok(self.idling)
Apr 12 20:08:15 badkamer volumio[587]: error: The expression evaluated to a falsy value:
Apr 12 20:08:15 badkamer volumio[587]: assert.ok(self.idling)
Apr 12 20:08:15 badkamer volumio[587]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 6
Apr 12 20:08:15 badkamer volumio[587]: info: FusionDsp - {"Reload":{"result":"Ok"}}
Apr 12 20:08:15 badkamer volumio[587]: error: updateQueue error: null
Apr 12 20:08:16 badkamer volumio[587]: info: go-librespot daemon successfully initialized
Apr 12 20:08:18 badkamer go-librespot[784]: time="2024-04-12T20:08:18+02:00" level=debug msg="handling transfer player command from e41e6e21657a3e547616abf732378a36c228c3e2"
Apr 12 20:08:18 badkamer go-librespot[784]: time="2024-04-12T20:08:18+02:00" level=trace msg="fetched new page 0 with 33 items (list: 33)"
Apr 12 20:08:18 badkamer go-librespot[784]: time="2024-04-12T20:08:18+02:00" level=debug msg="shuffled context with seed 15469399185353964795 (len: 33, keep: 23)"
Apr 12 20:08:18 badkamer go-librespot[784]: time="2024-04-12T20:08:18+02:00" level=debug msg="loading track spotify:track:6tGCxVJPo7iIydUVHOjVbM (paused: false, position: 25727ms)"
Apr 12 20:08:18 badkamer go-librespot[784]: time="2024-04-12T20:08:18+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 241"
Apr 12 20:08:18 badkamer go-librespot[784]: time="2024-04-12T20:08:18+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Apr 12 20:08:18 badkamer go-librespot[784]: time="2024-04-12T20:08:18+02:00" level=trace msg="emitting websocket event: will_play"
Apr 12 20:08:18 badkamer go-librespot[784]: time="2024-04-12T20:08:18+02:00" level=debug msg="selected format OGG_VORBIS_320 for spotify:track:6tGCxVJPo7iIydUVHOjVbM"
Apr 12 20:08:18 badkamer go-librespot[784]: time="2024-04-12T20:08:18+02:00" level=debug msg="requested aes key for file cbca793c1205cdd6c14a103807f764821c1b872e, gid: 6tGCxVJPo7iIydUVHOjVbM"
Apr 12 20:08:19 badkamer go-librespot[784]: time="2024-04-12T20:08:19+02:00" level=debug msg="fetched first chunk of 18, total size is 9046756 bytes"
Apr 12 20:08:19 badkamer go-librespot[784]: time="2024-04-12T20:08:19+02:00" level=warning msg="reducing track normalisation factor to prevent clipping, please add negative pregain to avoid"
Apr 12 20:08:19 badkamer go-librespot[784]: time="2024-04-12T20:08:19+02:00" level=debug msg="fetched chunk 1/17, size: 524288"
Apr 12 20:08:19 badkamer volumio[587]: info: Initializing connection to go-librespot Websocket
Apr 12 20:08:19 badkamer go-librespot[784]: time="2024-04-12T20:08:19+02:00" level=debug msg="new websocket client"
Apr 12 20:08:19 badkamer volumio[587]: info: Connection to go-librespot Websocket established
Apr 12 20:08:19 badkamer go-librespot[784]: time="2024-04-12T20:08:19+02:00" level=debug msg="fetched chunk 3/17, size: 524288"
Apr 12 20:08:19 badkamer go-librespot[784]: time="2024-04-12T20:08:19+02:00" level=debug msg="fetched chunk 2/17, size: 524288"
Apr 12 20:08:19 badkamer go-librespot[784]: time="2024-04-12T20:08:19+02:00" level=debug msg="fetched chunk 4/17, size: 524288"
Apr 12 20:08:19 badkamer go-librespot[784]: time="2024-04-12T20:08:19+02:00" level=trace msg="seek to 25727ms (diff: 117ms, samples: 1134560, bytes: 1040903)"
Apr 12 20:08:19 badkamer go-librespot[784]: time="2024-04-12T20:08:19+02:00" level=info msg="loaded track \"Falling Apart\" (uri: spotify:track:6tGCxVJPo7iIydUVHOjVbM, paused: false, position: 25727ms, duration: 206616ms)"
Apr 12 20:08:19 badkamer volumio[587]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32
Apr 12 20:08:19 badkamer volumio[587]: info: FusionDsp - ---- read samplerate from file: 44100
Apr 12 20:08:19 badkamer volumio[587]: info: camilladsp stopping service pid 845...
Apr 12 20:08:19 badkamer kernel: bcm2835_audio bcm2835_audio: failed to close VCHI service connection (status=1)
Apr 12 20:08:19 badkamer volumio[587]: info: camilladsp service terminated, instance 1
Apr 12 20:08:19 badkamer volumio[587]: info: FusionDsp - If filter freq >samplerate/2 then disable it
Apr 12 20:08:19 badkamer volumio[587]: info: camilladsp service started and running in background, instance 1
Apr 12 20:08:19 badkamer volumio[587]: info: camilladsp spawned new process with pid 865, instance 1, run: true
Apr 12 20:08:19 badkamer go-librespot[784]: time="2024-04-12T20:08:19+02:00" level=debug msg="fetched chunk 5/17, size: 524288"
Apr 12 20:08:19 badkamer go-librespot[784]: time="2024-04-12T20:08:19+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Apr 12 20:08:19 badkamer go-librespot[784]: time="2024-04-12T20:08:19+02:00" level=trace msg="emitting websocket event: metadata"
Apr 12 20:08:19 badkamer volumio[587]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:6tGCxVJPo7iIydUVHOjVbM","name":"Falling Apart","artist_names":["Massane"],"album_name":"Visage 1 (No Return)","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02e39a9e121bc8c93587c329cb","position":25727,"duration":206616,"release_date":"year:2020 month:4 day:2","track_number":3,"disc_number":1}}
Apr 12 20:08:19 badkamer go-librespot[784]: time="2024-04-12T20:08:19+02:00" level=trace msg="emitting websocket event: active"
Apr 12 20:08:19 badkamer go-librespot[784]: time="2024-04-12T20:08:19+02:00" level=debug msg="sending successful reply for delaer request"
Apr 12 20:08:19 badkamer go-librespot[784]: time="2024-04-12T20:08:19+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update
Apr 12 20:08:19 badkamer volumio[587]: SPOTIFY: received: {"type":"active","data":null}
Apr 12 20:08:19 badkamer volumio[587]: info: Aligning Spotify Volume to Volumio Volume
Apr 12 20:08:19 badkamer volumio[587]: info: CoreCommandRouter::volumioGetState
Apr 12 20:08:19 badkamer volumio[587]: info: CorePlayQueue::getTrack 0
Apr 12 20:08:19 badkamer volumio[587]: info: Setting Spotify Volume from Volumio: 44
Apr 12 20:08:20 badkamer go-librespot[784]: time="2024-04-12T20:08:20+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED"
Apr 12 20:08:20 badkamer go-librespot[784]: time="2024-04-12T20:08:20+02:00" level=trace msg="emitting websocket event: playing"
Apr 12 20:08:20 badkamer volumio[587]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:6tGCxVJPo7iIydUVHOjVbM","play_origin":"com.spotify.service.yourlibrarymusic.ui"}}
Apr 12 20:08:20 badkamer volumio[587]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Apr 12 20:08:20 badkamer volumio[587]: TypeError: Cannot read property 'service' of undefined
Apr 12 20:08:20 badkamer volumio[587]: at ControllerSpotify.identifyPlaybackMode (/data/plugins/music_service/spop/index.js:336:50)
Apr 12 20:08:20 badkamer volumio[587]: at ControllerSpotify.parseEventState (/data/plugins/music_service/spop/index.js:262:18)
Apr 12 20:08:20 badkamer volumio[587]: at WebSocket.message (/data/plugins/music_service/spop/index.js:189:14)
Apr 12 20:08:20 badkamer volumio[587]: at WebSocket.emit (events.js:315:20)
Apr 12 20:08:20 badkamer volumio[587]: at Receiver.receiverOnMessage (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1203:20)
Apr 12 20:08:20 badkamer volumio[587]: at Receiver.emit (events.js:315:20)
Apr 12 20:08:20 badkamer volumio[587]: at /data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:608:16
Apr 12 20:08:20 badkamer volumio[587]: at internal/process/task_queues.js:149:7
Apr 12 20:08:20 badkamer volumio[587]: at AsyncResource.runInAsyncScope (async_hooks.js:197:9)
Apr 12 20:08:20 badkamer volumio[587]: at AsyncResource.runMicrotask (internal/process/task_queues.js:146:8)
Apr 12 20:08:20 badkamer volumio[587]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Apr 12 20:08:20 badkamer sudo[881]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-04-12 20:07
Apr 12 20:08:20 badkamer sudo[881]: pam_unix(sudo:session): session opened for user root by (uid=0)
PRETTY_NAME="Raspbian GNU/Linux 10 (buster)"
NAME="Raspbian GNU/Linux"
VERSION_ID="10"
VERSION="10 (buster)"
VERSION_CODENAME=buster
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="7f9f1bf001add7a8b19a4516e3c74ef598b2730d"
VOLUMIO_FE_VERSION="614d7b13ffdcb0cc5a6072e7d06f59d52e323e71"
VOLUMIO_FE3_VERSION="570aaed971c1346d45d1172dc445b086b258c6d1"
VOLUMIO_BE_VERSION="512433c3e91cdaed7ecd2808b21adeffc2137d7f"
VOLUMIO_ARCH="arm"
VOLUMIO_VARIANT="volumio"
VOLUMIO_TEST="FALSE"
VOLUMIO_BUILD_DATE="Wed 21 Feb 2024 09:37:22 PM CET"
VOLUMIO_VERSION="3.631"
VOLUMIO_HARDWARE="pi"
VOLUMIO_DEVICENAME="Raspberry Pi"
VOLUMIO_HASH="fdd9dd1169c06c1ad0a30ddd24c91b6b"