-- Logs begin at Thu 2019-02-14 11:11:59 CET, end at Wed 2024-11-27 17:37:16 CET. -- Nov 27 17:36:05 volumio volumio[835]: info: Received OAUTH Data Nov 27 17:36:05 volumio volumio[835]: info: Executing Spotify Oauth Login Nov 27 17:36:05 volumio volumio[835]: info: Saving Spotify Refresh Token Nov 27 17:36:05 volumio volumio[835]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Nov 27 17:36:05 volumio volumio[835]: SPOTIFY: BQBu-s7G5h44XP6A-3kFkuUUgc6Ac3CDhzoUQxlTJzR6DZ-wyNnk0BB9QLi1mpnGHmzK05LihS_-r2EOXgXasJVU6_MsTcJnEWe6583TxUVj_gK_1QAWByJW_eGFbgBb7_UvpDo3IsL4GHC5N2BPfEqbd9XnvMdc_5sspC18YMCRkRkg65UgVvbGaTXe2Z-Hx1ifUxAAGVzCeT5YBVfXWgNrm6CaIsaJI9SFCUl0E0Mum6wjERyp6Djbcrg Nov 27 17:36:05 volumio volumio[835]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Nov 27 17:36:05 volumio volumio[835]: info: New Spotify access token = BQBu-s7G5h44XP6A-3kFkuUUgc6Ac3CDhzoUQxlTJzR6DZ-wyNnk0BB9QLi1mpnGHmzK05LihS_-r2EOXgXasJVU6_MsTcJnEWe6583TxUVj_gK_1QAWByJW_eGFbgBb7_UvpDo3IsL4GHC5N2BPfEqbd9XnvMdc_5sspC18YMCRkRkg65UgVvbGaTXe2Z-Hx1ifUxAAGVzCeT5YBVfXWgNrm6CaIsaJI9SFCUl0E0Mum6wjERyp6Djbcrg Nov 27 17:36:05 volumio volumio[835]: info: Spotify credentials grant success - running version from March 24, 2019 Nov 27 17:36:05 volumio volumio[835]: SPOTIFY: User informations: {"country":"DE","display_name":"Fabian","email":"fabihartmann@web.de","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/1121816780"},"followers":{"href":null,"total":2},"href":"https://api.spotify.com/v1/users/1121816780","id":"1121816780","images":[],"product":"premium","type":"user","uri":"spotify:user:1121816780"} Nov 27 17:36:05 volumio volumio[835]: info: Creating Spotify config file Nov 27 17:36:05 volumio volumio[835]: info: Spotify config file written Nov 27 17:36:05 volumio sudo[1725]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Nov 27 17:36:05 volumio sudo[1725]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 27 17:36:05 volumio systemd[1]: Stopping go-librespot Daemon... Nov 27 17:36:05 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=killed, status=15/TERM Nov 27 17:36:05 volumio systemd[1]: go-librespot-daemon.service: Succeeded. Nov 27 17:36:05 volumio systemd[1]: Stopped go-librespot Daemon. Nov 27 17:36:05 volumio volumio[835]: info: Connection to go-librespot Websocket closed Nov 27 17:36:05 volumio systemd[1]: Started go-librespot Daemon. Nov 27 17:36:05 volumio go-librespot[1727]: Librespot-go daemon starting... Nov 27 17:36:05 volumio sudo[1725]: pam_unix(sudo:session): session closed for user root Nov 27 17:36:05 volumio go-librespot[1727]: time="2024-11-27T17:36:05+01:00" level=info msg="generated new device id: 08344205199fb9d80b77fb0f0fea13e2cf14135c" Nov 27 17:36:05 volumio go-librespot[1727]: time="2024-11-27T17:36:05+01:00" level=debug msg="stored credentials found for 1121816780" Nov 27 17:36:05 volumio sudo[1736]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Nov 27 17:36:05 volumio sudo[1736]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 27 17:36:05 volumio sudo[1736]: pam_unix(sudo:session): session closed for user root Nov 27 17:36:05 volumio sudo[1739]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Nov 27 17:36:05 volumio sudo[1739]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 27 17:36:05 volumio sudo[1739]: pam_unix(sudo:session): session closed for user root Nov 27 17:36:05 volumio go-librespot[1727]: time="2024-11-27T17:36:05+01:00" level=debug msg="obtained new client token: AACP4u4BBUMS2TWBdW3ahjmT3b+GdwLLj80GLD3oX+4uCtkgJm5uciuq8zDWmXskSaUbjRlqiaEdDXhpCQ+jHphUxtj4cGNfYdZwAqsaeC7Mnks17tQqIPvTvhf5HXHzWHP9IPObz2ivvk6dmg/Rd+OB2lCZgyuv0UsY3O7RDsu9bEIf1gbfaPL/l5J67ei+dVXKojUjHlsPvs2qD+s4NU9CLdFbnVQ2tmmQ5qbugK5o6HYBkpm7+LT549PZA2k=" Nov 27 17:36:05 volumio volumio[835]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Nov 27 17:36:05 volumio volumio[835]: SPOTIFY: BQBKExpRZDSsfgeIU6yTrxZ4NsqcXgAqUxN9rlZMYvCWs94ICrsBqpRRdDYAXMA-BFkc7ay23jcjFrj-5naRQ5ceqsX4-BK1wnZEVVnxmUY-s9kLcukZEot8AfyX2eilUiG5qrczd69eKDoXXJyQS_mbWu6dXbY4xO1gWZ7L53onQHInFG5_1ofE4nbbyk3LT70A0UJNNWI5gGgoJ226dL1yTOewJXPLwMkonDsxgEVNHFZb3fya4OhZgFI Nov 27 17:36:05 volumio volumio[835]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Nov 27 17:36:05 volumio volumio[835]: info: New Spotify access token = BQBKExpRZDSsfgeIU6yTrxZ4NsqcXgAqUxN9rlZMYvCWs94ICrsBqpRRdDYAXMA-BFkc7ay23jcjFrj-5naRQ5ceqsX4-BK1wnZEVVnxmUY-s9kLcukZEot8AfyX2eilUiG5qrczd69eKDoXXJyQS_mbWu6dXbY4xO1gWZ7L53onQHInFG5_1ofE4nbbyk3LT70A0UJNNWI5gGgoJ226dL1yTOewJXPLwMkonDsxgEVNHFZb3fya4OhZgFI Nov 27 17:36:05 volumio volumio[835]: info: Spotify credentials grant success - running version from March 24, 2019 Nov 27 17:36:05 volumio go-librespot[1727]: time="2024-11-27T17:36:05+01: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]" Nov 27 17:36:05 volumio volumio[835]: verbose: New Socket.io Connection to 192.168.178.48 from 192.168.178.85 UA: Mozilla/5.0 (Linux; Android 15; Pixel 8 Pro Build/AP3A.241105.007; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/131.0.6778.39 Mobile Safari/537.36 Total Clients: 6 Nov 27 17:36:05 volumio volumio[835]: SPOTIFY: User informations: {"country":"DE","display_name":"Fabian","email":"fabihartmann@web.de","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/1121816780"},"followers":{"href":null,"total":2},"href":"https://api.spotify.com/v1/users/1121816780","id":"1121816780","images":[],"product":"premium","type":"user","uri":"spotify:user:1121816780"} Nov 27 17:36:05 volumio volumio[835]: info: Spotify Successfully logged in Nov 27 17:36:05 volumio volumio[835]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 27 17:36:05 volumio volumio[835]: info: [1732725365920] CoreMusicLibrary::Adding element Spotify Nov 27 17:36:05 volumio volumio[835]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 27 17:36:05 volumio volumio[835]: Cannot find translation for source Spotify Nov 27 17:36:05 volumio go-librespot[1727]: time="2024-11-27T17:36:05+01:00" level=debug msg="completed keyexchange" Nov 27 17:36:06 volumio volumio[835]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Nov 27 17:36:06 volumio volumio[835]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Nov 27 17:36:06 volumio volumio[835]: info: CoreCommandRouter::volumioGetVisibleSources Nov 27 17:36:06 volumio volumio[835]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 27 17:36:06 volumio volumio[835]: info: CoreCommandRouter::getUIConfigOnPlugin Nov 27 17:36:06 volumio volumio[835]: info: CoreCommandRouter::volumioGetState Nov 27 17:36:06 volumio volumio[835]: info: CorePlayQueue::getTrack 0 Nov 27 17:36:06 volumio volumio[835]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Nov 27 17:36:06 volumio volumio[835]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Nov 27 17:36:06 volumio volumio[835]: info: Received Get System Info Nov 27 17:36:06 volumio volumio[835]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 27 17:36:06 volumio volumio[835]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 27 17:36:06 volumio volumio[835]: info: Discovery: Getting this device information Nov 27 17:36:06 volumio volumio[835]: info: CoreCommandRouter::volumioGetState Nov 27 17:36:06 volumio volumio[835]: info: CorePlayQueue::getTrack 0 Nov 27 17:36:06 volumio volumio[835]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 27 17:36:06 volumio volumio[835]: info: CoreCommandRouter::volumioGetState Nov 27 17:36:06 volumio volumio[835]: info: CorePlayQueue::getTrack 0 Nov 27 17:36:06 volumio volumio[835]: info: Listing playlists Nov 27 17:36:06 volumio volumio[835]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Nov 27 17:36:06 volumio volumio[835]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Nov 27 17:36:06 volumio volumio[835]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Nov 27 17:36:06 volumio volumio[835]: info: CoreCommandRouter::getUIConfigOnPlugin Nov 27 17:36:06 volumio go-librespot[1727]: time="2024-11-27T17:36:06+01:00" level=debug msg="completed challenge" Nov 27 17:36:06 volumio go-librespot[1727]: time="2024-11-27T17:36:06+01:00" level=debug msg="authenticated as 1121816780" Nov 27 17:36:06 volumio go-librespot[1727]: time="2024-11-27T17:36:06+01:00" level=debug msg="authenticated as 1121816780" Nov 27 17:36:06 volumio go-librespot[1727]: time="2024-11-27T17:36:06+01:00" level=debug msg="fetched new spclients: [gew4-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gae2-spclient.spotify.com:443]" Nov 27 17:36:06 volumio go-librespot[1727]: time="2024-11-27T17:36:06+01:00" level=debug msg="fetched new dealers: [gew4-dealer.spotify.com:443 guc3-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gae2-dealer.spotify.com:443]" Nov 27 17:36:06 volumio go-librespot[1727]: time="2024-11-27T17:36:06+01:00" level=debug msg="dealer connection opened" Nov 27 17:36:06 volumio go-librespot[1727]: time="2024-11-27T17:36:06+01:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Nov 27 17:36:06 volumio go-librespot[1727]: time="2024-11-27T17:36:06+01:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Nov 27 17:36:06 volumio go-librespot[1727]: time="2024-11-27T17:36:06+01:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Nov 27 17:36:06 volumio go-librespot[1727]: time="2024-11-27T17:36:06+01:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Nov 27 17:36:06 volumio go-librespot[1727]: time="2024-11-27T17:36:06+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Nov 27 17:36:06 volumio go-librespot[1727]: time="2024-11-27T17:36:06+01:00" level=debug msg="received connection id: MDg4MmE1MDAtNTBkYi00NmI4LTk3YjktYTAzZjI2ZTk4NjljK2RlYWxlcit0Y3A6Ly8wYWNhNTljYS5pcC5nZXc0LnNwb3RpZnkubmV0OjU3MDArN0ZDQkM3NEUxMEYzN0I5OEEyQjNENjZFODBDNTFDMjMwQTQ1RUI0QkNENjUxRjI3RUJCNzdFNTA4MzE3N0IzOQ==" Nov 27 17:36:06 volumio go-librespot[1727]: time="2024-11-27T17:36:06+01:00" level=debug msg="put connect state because NEW_DEVICE" Nov 27 17:36:07 volumio volumio[835]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Nov 27 17:36:07 volumio volumio[835]: info: Received Get System Info Nov 27 17:36:07 volumio volumio[835]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 27 17:36:07 volumio volumio[835]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 27 17:36:07 volumio volumio[835]: info: Discovery: Getting this device information Nov 27 17:36:07 volumio volumio[835]: info: CoreCommandRouter::volumioGetState Nov 27 17:36:07 volumio volumio[835]: info: CorePlayQueue::getTrack 0 Nov 27 17:36:07 volumio volumio[835]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 27 17:36:08 volumio volumio[835]: info: Initializing connection to go-librespot Websocket Nov 27 17:36:08 volumio go-librespot[1727]: time="2024-11-27T17:36:08+01:00" level=debug msg="new websocket client" Nov 27 17:36:08 volumio volumio[835]: info: Connection to go-librespot Websocket established Nov 27 17:36:08 volumio volumio[835]: info: go-librespot daemon successfully initialized Nov 27 17:36:08 volumio volumio[835]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Nov 27 17:36:08 volumio volumio[835]: info: Received Get System Info Nov 27 17:36:08 volumio volumio[835]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 27 17:36:08 volumio volumio[835]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 27 17:36:08 volumio volumio[835]: info: Discovery: Getting this device information Nov 27 17:36:08 volumio volumio[835]: info: CoreCommandRouter::volumioGetState Nov 27 17:36:08 volumio volumio[835]: info: CorePlayQueue::getTrack 0 Nov 27 17:36:08 volumio volumio[835]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 27 17:36:11 volumio volumio[835]: info: Getting Spotify volume Nov 27 17:36:11 volumio volumio[835]: info: Spotify volume: 100 Nov 27 17:36:11 volumio volumio[835]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 7 Nov 27 17:36:11 volumio volumio[835]: info: Initializing connection to go-librespot Websocket Nov 27 17:36:11 volumio go-librespot[1727]: time="2024-11-27T17:36:11+01:00" level=debug msg="new websocket client" Nov 27 17:36:11 volumio volumio[835]: info: Connection to go-librespot Websocket established Nov 27 17:36:11 volumio volumio[835]: info: CoreCommandRouter::volumioGetState Nov 27 17:36:11 volumio volumio[835]: info: CorePlayQueue::getTrack 0 Nov 27 17:36:11 volumio volumio[835]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 Nov 27 17:36:11 volumio volumio[835]: SPOTIFY: SPOTIFY VOLUME 100 Nov 27 17:36:11 volumio volumio[835]: SPOTIFY: VOLUMIO VOLUME 50 Nov 27 17:36:11 volumio volumio[835]: SPOTIFY: DELTA VOLUME ENOUGH: true Nov 27 17:36:11 volumio volumio[835]: info: Setting Spotify Volume from Volumio: 50 Nov 27 17:36:12 volumio volumio[835]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Nov 27 17:36:12 volumio volumio[835]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Nov 27 17:36:12 volumio volumio[835]: info: CoreCommandRouter::getUIConfigOnPlugin Nov 27 17:36:13 volumio volumio[835]: SPOTIFY: SETTING SPOTIFY VOLUME 50 Nov 27 17:36:13 volumio volumio[835]: info: Sending Spotify command with payload to local API: /player/volume Nov 27 17:36:13 volumio go-librespot[1727]: time="2024-11-27T17:36:13+01:00" level=debug msg="update volume to 32767/65535" Nov 27 17:36:13 volumio go-librespot[1727]: time="2024-11-27T17:36:13+01:00" level=debug msg="put connect state because VOLUME_CHANGED" Nov 27 17:36:13 volumio go-librespot[1727]: time="2024-11-27T17:36:13+01:00" level=trace msg="emitting websocket event: volume" Nov 27 17:36:13 volumio volumio[835]: SPOTIFY: received: {"type":"volume","data":{"value":50,"max":100}} Nov 27 17:36:13 volumio volumio[835]: SPOTIFY: RECEIVED SPOTIFY VOLUME 50 Nov 27 17:36:13 volumio volumio[835]: SPOTIFY: received: {"type":"volume","data":{"value":50,"max":100}} Nov 27 17:36:13 volumio volumio[835]: SPOTIFY: RECEIVED SPOTIFY VOLUME 50 Nov 27 17:36:14 volumio volumio[835]: info: Getting Spotify volume Nov 27 17:36:14 volumio volumio[835]: info: Spotify volume: 50 Nov 27 17:36:14 volumio volumio[835]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 7 Nov 27 17:36:14 volumio volumio[835]: info: CoreCommandRouter::volumioGetState Nov 27 17:36:14 volumio volumio[835]: info: CorePlayQueue::getTrack 0 Nov 27 17:36:14 volumio volumio[835]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 Nov 27 17:36:14 volumio volumio[835]: info: CoreCommandRouter::getUIConfigOnPlugin Nov 27 17:36:24 volumio volumio[835]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Nov 27 17:36:24 volumio volumio[835]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Nov 27 17:36:24 volumio volumio[835]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Nov 27 17:36:24 volumio volumio[835]: info: Received Get System Version Nov 27 17:36:24 volumio volumio[835]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 27 17:36:24 volumio volumio[835]: info: Received Get System Info Nov 27 17:36:24 volumio volumio[835]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 27 17:36:24 volumio volumio[835]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 27 17:36:24 volumio volumio[835]: info: Discovery: Getting this device information Nov 27 17:36:24 volumio volumio[835]: info: CoreCommandRouter::volumioGetState Nov 27 17:36:24 volumio volumio[835]: info: CorePlayQueue::getTrack 0 Nov 27 17:36:24 volumio volumio[835]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 27 17:36:35 volumio go-librespot[1727]: time="2024-11-27T17:36:35+01:00" level=debug msg="handling transfer player command from 96fd8c4ec411c0000e44a3dc1fe7d49784c07a7d" Nov 27 17:36:35 volumio go-librespot[1727]: time="2024-11-27T17:36:35+01:00" level=debug msg="loading track spotify:track:6VV8EboIsnmgv8Yy11g6Ww (paused: true, position: 43291ms)" Nov 27 17:36:35 volumio go-librespot[1727]: time="2024-11-27T17:36:35+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 27 17:36:35 volumio go-librespot[1727]: time="2024-11-27T17:36:35+01:00" level=trace msg="emitting websocket event: will_play" Nov 27 17:36:35 volumio volumio[835]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:6VV8EboIsnmgv8Yy11g6Ww","play_origin":"playlist"}} Nov 27 17:36:35 volumio volumio[835]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:6VV8EboIsnmgv8Yy11g6Ww","play_origin":"playlist"}} Nov 27 17:36:35 volumio go-librespot[1727]: time="2024-11-27T17:36:35+01:00" level=debug msg="selected format OGG_VORBIS_320 for spotify:track:6VV8EboIsnmgv8Yy11g6Ww" Nov 27 17:36:35 volumio go-librespot[1727]: time="2024-11-27T17:36:35+01:00" level=debug msg="requested aes key for file 2bd09adc49b89cff7514e27d71a54532fffcfea5, gid: 6VV8EboIsnmgv8Yy11g6Ww" Nov 27 17:36:35 volumio go-librespot[1727]: time="2024-11-27T17:36:35+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 241" Nov 27 17:36:35 volumio go-librespot[1727]: time="2024-11-27T17:36:35+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1332" Nov 27 17:36:35 volumio go-librespot[1727]: time="2024-11-27T17:36:35+01:00" level=debug msg="fetched first chunk of 24, total size is 12195048 bytes" Nov 27 17:36:35 volumio go-librespot[1727]: time="2024-11-27T17:36:35+01:00" level=debug msg="fetched chunk 1/23, size: 524288" Nov 27 17:36:35 volumio go-librespot[1727]: time="2024-11-27T17:36:35+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1110" Nov 27 17:36:36 volumio go-librespot[1727]: time="2024-11-27T17:36:36+01:00" level=debug msg="fetched chunk 6/23, size: 524288" Nov 27 17:36:36 volumio go-librespot[1727]: time="2024-11-27T17:36:36+01:00" level=debug msg="fetched chunk 5/23, size: 524288" Nov 27 17:36:36 volumio go-librespot[1727]: time="2024-11-27T17:36:36+01:00" level=debug msg="fetched chunk 2/23, size: 524288" Nov 27 17:36:36 volumio go-librespot[1727]: time="2024-11-27T17:36:36+01:00" level=debug msg="fetched chunk 4/23, size: 524288" Nov 27 17:36:36 volumio go-librespot[1727]: time="2024-11-27T17:36:36+01:00" level=trace msg="seek to 43291ms (diff: 72ms, samples: 1909133, bytes: 2148758)" Nov 27 17:36:36 volumio go-librespot[1727]: time="2024-11-27T17:36:36+01:00" level=debug msg="fetched chunk 7/23, size: 524288" Nov 27 17:36:36 volumio go-librespot[1727]: time="2024-11-27T17:36:36+01:00" level=debug msg="fetched chunk 3/23, size: 524288" Nov 27 17:36:36 volumio go-librespot[1727]: time="2024-11-27T17:36:36+01:00" level=info msg="loaded track \"Last Christmas\" (uri: spotify:track:6VV8EboIsnmgv8Yy11g6Ww, paused: true, position: 43291ms, duration: 267773ms)" Nov 27 17:36:36 volumio volumio[835]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Nov 27 17:36:36 volumio volumio[835]: info: FusionDsp - ---- read samplerate from file: 44100 Nov 27 17:36:36 volumio volumio[835]: info: FusionDsp - If filter freq >samplerate/2 then disable it Nov 27 17:36:36 volumio volumio[835]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Nov 27 17:36:36 volumio volumio[835]: info: FusionDsp - ---- read samplerate from file: 44100 Nov 27 17:36:36 volumio volumio[835]: info: FusionDsp - If filter freq >samplerate/2 then disable it Nov 27 17:36:36 volumio volumio[835]: info: FusionDsp - Loudness is ON true Nov 27 17:36:36 volumio volumio[835]: info: FusionDsp - highshelf: Nov 27 17:36:36 volumio volumio[835]: type: Biquad Nov 27 17:36:36 volumio volumio[835]: parameters: Nov 27 17:36:36 volumio volumio[835]: type: Highshelf Nov 27 17:36:36 volumio volumio[835]: freq: 10620 Nov 27 17:36:36 volumio volumio[835]: q: 1.38 Nov 27 17:36:36 volumio volumio[835]: gain: 3.40 Nov 27 17:36:36 volumio volumio[835]: lowshelf: Nov 27 17:36:36 volumio volumio[835]: type: Biquad Nov 27 17:36:36 volumio volumio[835]: parameters: Nov 27 17:36:36 volumio volumio[835]: type: LowshelfFO Nov 27 17:36:36 volumio volumio[835]: freq: 120 Nov 27 17:36:36 volumio volumio[835]: gain: 12.11 Nov 27 17:36:36 volumio volumio[835]: peakloudness: Nov 27 17:36:36 volumio volumio[835]: type: Biquad Nov 27 17:36:36 volumio volumio[835]: parameters: Nov 27 17:36:36 volumio volumio[835]: type: Peaking Nov 27 17:36:36 volumio volumio[835]: freq: 2000 Nov 27 17:36:36 volumio volumio[835]: q: 0.6 Nov 27 17:36:36 volumio volumio[835]: gain: -0.74 Nov 27 17:36:36 volumio volumio[835]: peakloudness2: Nov 27 17:36:36 volumio volumio[835]: type: Biquad Nov 27 17:36:36 volumio volumio[835]: parameters: Nov 27 17:36:36 volumio volumio[835]: type: Peaking Nov 27 17:36:36 volumio volumio[835]: freq: 4000 Nov 27 17:36:36 volumio volumio[835]: q: 0.8 Nov 27 17:36:36 volumio volumio[835]: gain: -0.33 Nov 27 17:36:36 volumio volumio[835]: peakloudness3: Nov 27 17:36:36 volumio volumio[835]: type: Biquad Nov 27 17:36:36 volumio volumio[835]: parameters: Nov 27 17:36:36 volumio volumio[835]: type: Peaking Nov 27 17:36:36 volumio volumio[835]: freq: 8000 Nov 27 17:36:36 volumio volumio[835]: q: 2.13 Nov 27 17:36:36 volumio volumio[835]: gain: 0.86 Nov 27 17:36:36 volumio volumio[835]: eq1: Nov 27 17:36:36 volumio volumio[835]: type: Biquad Nov 27 17:36:36 volumio volumio[835]: parameters: Nov 27 17:36:36 volumio volumio[835]: type: Peaking Nov 27 17:36:36 volumio volumio[835]: freq: 147.0 Nov 27 17:36:36 volumio volumio[835]: q: 5.000 Nov 27 17:36:36 volumio volumio[835]: gain: -5.80 Nov 27 17:36:36 volumio volumio[835]: eq2: Nov 27 17:36:36 volumio volumio[835]: type: Biquad Nov 27 17:36:36 volumio volumio[835]: parameters: Nov 27 17:36:36 volumio volumio[835]: type: Peaking Nov 27 17:36:36 volumio volumio[835]: freq: 46.80 Nov 27 17:36:36 volumio volumio[835]: q: 5.000 Nov 27 17:36:36 volumio volumio[835]: gain: -5.10 Nov 27 17:36:36 volumio volumio[835]: eq3: Nov 27 17:36:36 volumio volumio[835]: type: Biquad Nov 27 17:36:36 volumio volumio[835]: parameters: Nov 27 17:36:36 volumio volumio[835]: type: Peaking Nov 27 17:36:36 volumio volumio[835]: freq: 842.0 Nov 27 17:36:36 volumio volumio[835]: q: 2.197 Nov 27 17:36:36 volumio volumio[835]: gain: -4.90 Nov 27 17:36:36 volumio volumio[835]: eq4: Nov 27 17:36:36 volumio volumio[835]: type: Biquad Nov 27 17:36:36 volumio volumio[835]: parameters: Nov 27 17:36:36 volumio volumio[835]: type: Peaking Nov 27 17:36:36 volumio volumio[835]: freq: 113.0 Nov 27 17:36:36 volumio volumio[835]: q: 14.348 Nov 27 17:36:36 volumio volumio[835]: gain: -13.30 Nov 27 17:36:36 volumio volumio[835]: eq5: Nov 27 17:36:36 volumio volumio[835]: type: Biquad Nov 27 17:36:36 volumio volumio[835]: parameters: Nov 27 17:36:36 volumio volumio[835]: type: Peaking Nov 27 17:36:36 volumio volumio[835]: freq: 68.40 Nov 27 17:36:36 volumio volumio[835]: q: 14.356 Nov 27 17:36:36 volumio volumio[835]: gain: -12.10 Nov 27 17:36:36 volumio volumio[835]: eq6: Nov 27 17:36:36 volumio volumio[835]: type: Biquad Nov 27 17:36:36 volumio volumio[835]: parameters: Nov 27 17:36:36 volumio volumio[835]: type: Peaking Nov 27 17:36:36 volumio volumio[835]: freq: 134.5 Nov 27 17:36:36 volumio volumio[835]: q: 16.130 Nov 27 17:36:36 volumio volumio[835]: gain: -8.20 Nov 27 17:36:36 volumio volumio[835]: eq7: Nov 27 17:36:36 volumio volumio[835]: type: Biquad Nov 27 17:36:36 volumio volumio[835]: parameters: Nov 27 17:36:36 volumio volumio[835]: type: Peaking Nov 27 17:36:36 volumio volumio[835]: freq: 93.00 Nov 27 17:36:36 volumio volumio[835]: q: 21.275 Nov 27 17:36:36 volumio volumio[835]: gain: -7.40 Nov 27 17:36:36 volumio volumio[835]: eq8: Nov 27 17:36:36 volumio volumio[835]: type: Biquad Nov 27 17:36:36 volumio volumio[835]: parameters: Nov 27 17:36:36 volumio volumio[835]: type: Peaking Nov 27 17:36:36 volumio volumio[835]: freq: 77.20 Nov 27 17:36:36 volumio volumio[835]: q: 11.330 Nov 27 17:36:36 volumio volumio[835]: gain: -7.20 Nov 27 17:36:36 volumio volumio[835]: eq9: Nov 27 17:36:36 volumio volumio[835]: type: Biquad Nov 27 17:36:36 volumio volumio[835]: parameters: Nov 27 17:36:36 volumio volumio[835]: type: Peaking Nov 27 17:36:36 volumio volumio[835]: freq: 144.0 Nov 27 17:36:36 volumio volumio[835]: q: 14.587 Nov 27 17:36:36 volumio volumio[835]: gain: -7.00 Nov 27 17:36:36 volumio volumio[835]: eq10: Nov 27 17:36:36 volumio volumio[835]: type: Biquad Nov 27 17:36:36 volumio volumio[835]: parameters: Nov 27 17:36:36 volumio volumio[835]: type: Peaking Nov 27 17:36:36 volumio volumio[835]: freq: 776.0 Nov 27 17:36:36 volumio volumio[835]: q: 2.588 Nov 27 17:36:36 volumio volumio[835]: gain: -4.50 Nov 27 17:36:36 volumio volumio[835]: eq11: Nov 27 17:36:36 volumio volumio[835]: type: Biquad Nov 27 17:36:36 volumio volumio[835]: parameters: Nov 27 17:36:36 volumio volumio[835]: type: Peaking Nov 27 17:36:36 volumio volumio[835]: freq: 492.0 Nov 27 17:36:36 volumio volumio[835]: q: 5.000 Nov 27 17:36:36 volumio volumio[835]: gain: -3.70 Nov 27 17:36:36 volumio volumio[835]: eq12: Nov 27 17:36:36 volumio volumio[835]: type: Biquad Nov 27 17:36:36 volumio volumio[835]: parameters: Nov 27 17:36:36 volumio volumio[835]: type: Peaking Nov 27 17:36:36 volumio volumio[835]: freq: 30.00 Nov 27 17:36:36 volumio volumio[835]: q: 2.000 Nov 27 17:36:36 volumio volumio[835]: gain: 3.00 Nov 27 17:36:36 volumio volumio[835]: info: FusionDsp - Loudness is ON true Nov 27 17:36:36 volumio volumio[835]: info: FusionDsp - highshelf: Nov 27 17:36:36 volumio volumio[835]: type: Biquad Nov 27 17:36:36 volumio volumio[835]: parameters: Nov 27 17:36:36 volumio volumio[835]: type: Highshelf Nov 27 17:36:36 volumio volumio[835]: freq: 10620 Nov 27 17:36:36 volumio volumio[835]: q: 1.38 Nov 27 17:36:36 volumio volumio[835]: gain: 3.40 Nov 27 17:36:36 volumio volumio[835]: lowshelf: Nov 27 17:36:36 volumio volumio[835]: type: Biquad Nov 27 17:36:36 volumio volumio[835]: parameters: Nov 27 17:36:36 volumio volumio[835]: type: LowshelfFO Nov 27 17:36:36 volumio volumio[835]: freq: 120 Nov 27 17:36:36 volumio volumio[835]: gain: 12.11 Nov 27 17:36:36 volumio volumio[835]: peakloudness: Nov 27 17:36:36 volumio volumio[835]: type: Biquad Nov 27 17:36:36 volumio volumio[835]: parameters: Nov 27 17:36:36 volumio volumio[835]: type: Peaking Nov 27 17:36:36 volumio volumio[835]: freq: 2000 Nov 27 17:36:36 volumio volumio[835]: q: 0.6 Nov 27 17:36:36 volumio volumio[835]: gain: -0.74 Nov 27 17:36:36 volumio volumio[835]: peakloudness2: Nov 27 17:36:36 volumio volumio[835]: type: Biquad Nov 27 17:36:36 volumio volumio[835]: parameters: Nov 27 17:36:36 volumio volumio[835]: type: Peaking Nov 27 17:36:36 volumio volumio[835]: freq: 4000 Nov 27 17:36:36 volumio volumio[835]: q: 0.8 Nov 27 17:36:36 volumio volumio[835]: gain: -0.33 Nov 27 17:36:36 volumio volumio[835]: peakloudness3: Nov 27 17:36:36 volumio volumio[835]: type: Biquad Nov 27 17:36:36 volumio volumio[835]: parameters: Nov 27 17:36:36 volumio volumio[835]: type: Peaking Nov 27 17:36:36 volumio volumio[835]: freq: 8000 Nov 27 17:36:36 volumio volumio[835]: q: 2.13 Nov 27 17:36:36 volumio volumio[835]: gain: 0.86 Nov 27 17:36:36 volumio volumio[835]: eq1: Nov 27 17:36:36 volumio volumio[835]: type: Biquad Nov 27 17:36:36 volumio volumio[835]: parameters: Nov 27 17:36:36 volumio volumio[835]: type: Peaking Nov 27 17:36:36 volumio volumio[835]: freq: 147.0 Nov 27 17:36:36 volumio volumio[835]: q: 5.000 Nov 27 17:36:36 volumio volumio[835]: gain: -5.80 Nov 27 17:36:36 volumio volumio[835]: eq2: Nov 27 17:36:36 volumio volumio[835]: type: Biquad Nov 27 17:36:36 volumio volumio[835]: parameters: Nov 27 17:36:36 volumio volumio[835]: type: Peaking Nov 27 17:36:36 volumio volumio[835]: freq: 46.80 Nov 27 17:36:36 volumio volumio[835]: q: 5.000 Nov 27 17:36:36 volumio volumio[835]: gain: -5.10 Nov 27 17:36:36 volumio volumio[835]: eq3: Nov 27 17:36:36 volumio volumio[835]: type: Biquad Nov 27 17:36:36 volumio volumio[835]: parameters: Nov 27 17:36:36 volumio volumio[835]: type: Peaking Nov 27 17:36:36 volumio volumio[835]: freq: 842.0 Nov 27 17:36:36 volumio volumio[835]: q: 2.197 Nov 27 17:36:36 volumio volumio[835]: gain: -4.90 Nov 27 17:36:36 volumio volumio[835]: eq4: Nov 27 17:36:36 volumio volumio[835]: type: Biquad Nov 27 17:36:36 volumio volumio[835]: parameters: Nov 27 17:36:36 volumio volumio[835]: type: Peaking Nov 27 17:36:36 volumio volumio[835]: freq: 113.0 Nov 27 17:36:36 volumio volumio[835]: q: 14.348 Nov 27 17:36:36 volumio volumio[835]: gain: -13.30 Nov 27 17:36:36 volumio volumio[835]: eq5: Nov 27 17:36:36 volumio volumio[835]: type: Biquad Nov 27 17:36:36 volumio volumio[835]: parameters: Nov 27 17:36:36 volumio volumio[835]: type: Peaking Nov 27 17:36:36 volumio volumio[835]: freq: 68.40 Nov 27 17:36:36 volumio volumio[835]: q: 14.356 Nov 27 17:36:36 volumio volumio[835]: gain: -12.10 Nov 27 17:36:36 volumio volumio[835]: eq6: Nov 27 17:36:36 volumio volumio[835]: type: Biquad Nov 27 17:36:36 volumio volumio[835]: parameters: Nov 27 17:36:36 volumio volumio[835]: type: Peaking Nov 27 17:36:36 volumio volumio[835]: freq: 134.5 Nov 27 17:36:36 volumio volumio[835]: q: 16.130 Nov 27 17:36:36 volumio volumio[835]: gain: -8.20 Nov 27 17:36:36 volumio volumio[835]: eq7: Nov 27 17:36:36 volumio volumio[835]: type: Biquad Nov 27 17:36:36 volumio volumio[835]: parameters: Nov 27 17:36:36 volumio volumio[835]: type: Peaking Nov 27 17:36:36 volumio volumio[835]: freq: 93.00 Nov 27 17:36:36 volumio volumio[835]: q: 21.275 Nov 27 17:36:36 volumio volumio[835]: gain: -7.40 Nov 27 17:36:36 volumio volumio[835]: eq8: Nov 27 17:36:36 volumio volumio[835]: type: Biquad Nov 27 17:36:36 volumio volumio[835]: parameters: Nov 27 17:36:36 volumio volumio[835]: type: Peaking Nov 27 17:36:36 volumio volumio[835]: freq: 77.20 Nov 27 17:36:36 volumio volumio[835]: q: 11.330 Nov 27 17:36:36 volumio volumio[835]: gain: -7.20 Nov 27 17:36:36 volumio volumio[835]: eq9: Nov 27 17:36:36 volumio volumio[835]: type: Biquad Nov 27 17:36:36 volumio volumio[835]: parameters: Nov 27 17:36:36 volumio volumio[835]: type: Peaking Nov 27 17:36:36 volumio volumio[835]: freq: 144.0 Nov 27 17:36:36 volumio volumio[835]: q: 14.587 Nov 27 17:36:36 volumio volumio[835]: gain: -7.00 Nov 27 17:36:36 volumio volumio[835]: eq10: Nov 27 17:36:36 volumio volumio[835]: type: Biquad Nov 27 17:36:36 volumio volumio[835]: parameters: Nov 27 17:36:36 volumio volumio[835]: type: Peaking Nov 27 17:36:36 volumio volumio[835]: freq: 776.0 Nov 27 17:36:36 volumio volumio[835]: q: 2.588 Nov 27 17:36:36 volumio volumio[835]: gain: -4.50 Nov 27 17:36:36 volumio volumio[835]: eq11: Nov 27 17:36:36 volumio volumio[835]: type: Biquad Nov 27 17:36:36 volumio volumio[835]: parameters: Nov 27 17:36:36 volumio volumio[835]: type: Peaking Nov 27 17:36:36 volumio volumio[835]: freq: 492.0 Nov 27 17:36:36 volumio volumio[835]: q: 5.000 Nov 27 17:36:36 volumio volumio[835]: gain: -3.70 Nov 27 17:36:36 volumio volumio[835]: eq12: Nov 27 17:36:36 volumio volumio[835]: type: Biquad Nov 27 17:36:36 volumio volumio[835]: parameters: Nov 27 17:36:36 volumio volumio[835]: type: Peaking Nov 27 17:36:36 volumio volumio[835]: freq: 30.00 Nov 27 17:36:36 volumio volumio[835]: q: 2.000 Nov 27 17:36:36 volumio volumio[835]: gain: 3.00 Nov 27 17:36:36 volumio volumio[835]: error: FusionDsp - WebSocket error: [object Object] Nov 27 17:36:36 volumio go-librespot[1727]: time="2024-11-27T17:36:36+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 27 17:36:36 volumio go-librespot[1727]: time="2024-11-27T17:36:36+01:00" level=trace msg="emitting websocket event: metadata" Nov 27 17:36:36 volumio go-librespot[1727]: time="2024-11-27T17:36:36+01:00" level=trace msg="emitting websocket event: active" Nov 27 17:36:36 volumio go-librespot[1727]: time="2024-11-27T17:36:36+01:00" level=debug msg="sending successful reply for delaer request" Nov 27 17:36:36 volumio volumio[835]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:6VV8EboIsnmgv8Yy11g6Ww","name":"Last Christmas","artist_names":["Jimmy Eat World"],"album_name":"Bleed American (Deluxe Edition)","album_cover_url":"https://i.scdn.co/image/ab67616d00001e022f0d89b1c4dcebefda07a959","position":43291,"duration":267773}} Nov 27 17:36:36 volumio go-librespot[1727]: time="2024-11-27T17:36:36+01:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Nov 27 17:36:36 volumio volumio[835]: SPOTIFY: received: {"type":"active","data":null} Nov 27 17:36:36 volumio go-librespot[1727]: time="2024-11-27T17:36:36+01:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Nov 27 17:36:36 volumio volumio[835]: info: Aligning Spotify Volume to Volumio Volume Nov 27 17:36:36 volumio volumio[835]: info: CoreCommandRouter::volumioGetState Nov 27 17:36:36 volumio go-librespot[1727]: time="2024-11-27T17:36:36+01:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Nov 27 17:36:36 volumio volumio[835]: info: CorePlayQueue::getTrack 0 Nov 27 17:36:36 volumio volumio[835]: info: Setting Spotify Volume from Volumio: 50 Nov 27 17:36:36 volumio volumio[835]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:6VV8EboIsnmgv8Yy11g6Ww","name":"Last Christmas","artist_names":["Jimmy Eat World"],"album_name":"Bleed American (Deluxe Edition)","album_cover_url":"https://i.scdn.co/image/ab67616d00001e022f0d89b1c4dcebefda07a959","position":43291,"duration":267773}} Nov 27 17:36:36 volumio volumio[835]: SPOTIFY: received: {"type":"active","data":null} Nov 27 17:36:36 volumio volumio[835]: info: Aligning Spotify Volume to Volumio Volume Nov 27 17:36:36 volumio volumio[835]: info: CoreCommandRouter::volumioGetState Nov 27 17:36:36 volumio volumio[835]: info: CorePlayQueue::getTrack 0 Nov 27 17:36:36 volumio volumio[835]: info: Setting Spotify Volume from Volumio: 50 Nov 27 17:36:36 volumio go-librespot[1727]: time="2024-11-27T17:36:36+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 27 17:36:36 volumio go-librespot[1727]: time="2024-11-27T17:36:36+01:00" level=trace msg="emitting websocket event: paused" Nov 27 17:36:36 volumio volumio[835]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:6VV8EboIsnmgv8Yy11g6Ww","play_origin":"playlist"}} Nov 27 17:36:36 volumio volumio[835]: info: Spotify is playing in volatile mode Nov 27 17:36:36 volumio volumio[835]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 27 17:36:36 volumio volumio[835]: SPOTIFY: UNSET VOLATILE Nov 27 17:36:36 volumio volumio[835]: SPOTIFY: {"status":"stop","position":0,"title":"","artist":"","album":"","albumart":"/albumart","duration":0,"uri":"","seek":0,"samplerate":"","channels":"","bitdepth":"","Streaming":false,"service":"mpd","volume":50,"dbVolume":null,"mute":false,"disableVolumeControl":false,"random":true,"repeat":null,"repeatSingle":false,"updatedb":false,"consume":false} Nov 27 17:36:36 volumio volumio[835]: SPOTIFY: PUSH STATE SPOTIFY Nov 27 17:36:36 volumio volumio[835]: SPOTIFY: {"status":"pause","service":"spop","title":"Last Christmas","artist":"Jimmy Eat World","album":"Bleed American (Deluxe Edition)","albumart":"https://i.scdn.co/image/ab67616d00001e022f0d89b1c4dcebefda07a959","uri":"spotify:track:6VV8EboIsnmgv8Yy11g6Ww","trackType":"spotify","seek":43291,"duration":267,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Nov 27 17:36:36 volumio volumio[835]: info: CoreCommandRouter::servicePushState Nov 27 17:36:36 volumio volumio[835]: info: CoreStateMachine::pushState Nov 27 17:36:36 volumio volumio[835]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 27 17:36:36 volumio volumio[835]: info: CoreCommandRouter::volumioPushState Nov 27 17:36:36 volumio volumio[835]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:6VV8EboIsnmgv8Yy11g6Ww","play_origin":"playlist"}} Nov 27 17:36:36 volumio volumio[835]: info: Spotify is playing in volatile mode Nov 27 17:36:36 volumio volumio[835]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 27 17:36:36 volumio volumio[835]: SPOTIFY: UNSET VOLATILE Nov 27 17:36:36 volumio volumio[835]: SPOTIFY: {"status":"stop","position":0,"title":"","artist":"","album":"","albumart":"/albumart","duration":0,"uri":"","seek":0,"samplerate":"","channels":"","bitdepth":"","Streaming":false,"service":"mpd","volume":50,"dbVolume":null,"mute":false,"disableVolumeControl":false,"random":true,"repeat":null,"repeatSingle":false,"updatedb":false,"consume":false} Nov 27 17:36:36 volumio volumio[835]: SPOTIFY: PUSH STATE SPOTIFY Nov 27 17:36:36 volumio volumio[835]: SPOTIFY: {"status":"pause","service":"spop","title":"Last Christmas","artist":"Jimmy Eat World","album":"Bleed American (Deluxe Edition)","albumart":"https://i.scdn.co/image/ab67616d00001e022f0d89b1c4dcebefda07a959","uri":"spotify:track:6VV8EboIsnmgv8Yy11g6Ww","trackType":"spotify","seek":43291,"duration":267,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Nov 27 17:36:36 volumio volumio[835]: info: CoreCommandRouter::servicePushState Nov 27 17:36:36 volumio volumio[835]: info: CoreStateMachine::pushState Nov 27 17:36:36 volumio volumio[835]: info: CoreCommandRouter::volumioPushState Nov 27 17:36:36 volumio volumio[835]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 Nov 27 17:36:36 volumio volumio[835]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 Nov 27 17:36:36 volumio go-librespot[1727]: time="2024-11-27T17:36:36+01:00" level=debug msg="handling resume player command from 96fd8c4ec411c0000e44a3dc1fe7d49784c07a7d" Nov 27 17:36:36 volumio go-librespot[1727]: time="2024-11-27T17:36:36+01:00" level=trace msg="seek to 43291ms (diff: 72ms, samples: 1909133, bytes: 2148758)" Nov 27 17:36:36 volumio volumio[835]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Nov 27 17:36:36 volumio volumio[835]: info: FusionDsp - ---- read samplerate from file: 44100 Nov 27 17:36:36 volumio volumio[835]: info: FusionDsp - If filter freq >samplerate/2 then disable it Nov 27 17:36:36 volumio volumio[835]: info: FusionDsp - ---- read samplerate, raw: 44100,S32_LE,2,32 Nov 27 17:36:36 volumio volumio[835]: info: FusionDsp - ---- read samplerate from file: 44100 Nov 27 17:36:36 volumio volumio[835]: info: FusionDsp - If filter freq >samplerate/2 then disable it Nov 27 17:36:36 volumio go-librespot[1727]: time="2024-11-27T17:36:36+01:00" level=debug msg="resume track at 43034ms" Nov 27 17:36:36 volumio volumio[835]: info: FusionDsp - Loudness is ON true Nov 27 17:36:36 volumio volumio[835]: info: FusionDsp - highshelf: Nov 27 17:36:36 volumio volumio[835]: type: Biquad Nov 27 17:36:36 volumio volumio[835]: parameters: Nov 27 17:36:36 volumio volumio[835]: type: Highshelf Nov 27 17:36:36 volumio volumio[835]: freq: 10620 Nov 27 17:36:36 volumio volumio[835]: q: 1.38 Nov 27 17:36:36 volumio volumio[835]: gain: 3.40 Nov 27 17:36:36 volumio volumio[835]: lowshelf: Nov 27 17:36:36 volumio volumio[835]: type: Biquad Nov 27 17:36:36 volumio volumio[835]: parameters: Nov 27 17:36:36 volumio volumio[835]: type: LowshelfFO Nov 27 17:36:36 volumio volumio[835]: freq: 120 Nov 27 17:36:36 volumio volumio[835]: gain: 12.11 Nov 27 17:36:36 volumio volumio[835]: peakloudness: Nov 27 17:36:36 volumio volumio[835]: type: Biquad Nov 27 17:36:36 volumio volumio[835]: parameters: Nov 27 17:36:36 volumio volumio[835]: type: Peaking Nov 27 17:36:36 volumio volumio[835]: freq: 2000 Nov 27 17:36:36 volumio volumio[835]: q: 0.6 Nov 27 17:36:36 volumio volumio[835]: gain: -0.74 Nov 27 17:36:36 volumio volumio[835]: peakloudness2: Nov 27 17:36:36 volumio volumio[835]: type: Biquad Nov 27 17:36:36 volumio volumio[835]: parameters: Nov 27 17:36:36 volumio volumio[835]: type: Peaking Nov 27 17:36:36 volumio volumio[835]: freq: 4000 Nov 27 17:36:36 volumio volumio[835]: q: 0.8 Nov 27 17:36:36 volumio volumio[835]: gain: -0.33 Nov 27 17:36:36 volumio volumio[835]: peakloudness3: Nov 27 17:36:36 volumio volumio[835]: type: Biquad Nov 27 17:36:36 volumio volumio[835]: parameters: Nov 27 17:36:36 volumio volumio[835]: type: Peaking Nov 27 17:36:36 volumio volumio[835]: freq: 8000 Nov 27 17:36:36 volumio volumio[835]: q: 2.13 Nov 27 17:36:36 volumio volumio[835]: gain: 0.86 Nov 27 17:36:36 volumio volumio[835]: eq1: Nov 27 17:36:36 volumio volumio[835]: type: Biquad Nov 27 17:36:36 volumio volumio[835]: parameters: Nov 27 17:36:36 volumio volumio[835]: type: Peaking Nov 27 17:36:36 volumio volumio[835]: freq: 147.0 Nov 27 17:36:36 volumio volumio[835]: q: 5.000 Nov 27 17:36:36 volumio volumio[835]: gain: -5.80 Nov 27 17:36:36 volumio volumio[835]: eq2: Nov 27 17:36:36 volumio volumio[835]: type: Biquad Nov 27 17:36:36 volumio volumio[835]: parameters: Nov 27 17:36:36 volumio volumio[835]: type: Peaking Nov 27 17:36:36 volumio volumio[835]: freq: 46.80 Nov 27 17:36:36 volumio volumio[835]: q: 5.000 Nov 27 17:36:36 volumio volumio[835]: gain: -5.10 Nov 27 17:36:36 volumio volumio[835]: eq3: Nov 27 17:36:36 volumio volumio[835]: type: Biquad Nov 27 17:36:36 volumio volumio[835]: parameters: Nov 27 17:36:36 volumio volumio[835]: type: Peaking Nov 27 17:36:36 volumio volumio[835]: freq: 842.0 Nov 27 17:36:36 volumio volumio[835]: q: 2.197 Nov 27 17:36:36 volumio volumio[835]: gain: -4.90 Nov 27 17:36:36 volumio volumio[835]: eq4: Nov 27 17:36:36 volumio volumio[835]: type: Biquad Nov 27 17:36:36 volumio volumio[835]: parameters: Nov 27 17:36:36 volumio volumio[835]: type: Peaking Nov 27 17:36:36 volumio volumio[835]: freq: 113.0 Nov 27 17:36:36 volumio volumio[835]: q: 14.348 Nov 27 17:36:36 volumio volumio[835]: gain: -13.30 Nov 27 17:36:36 volumio volumio[835]: eq5: Nov 27 17:36:36 volumio volumio[835]: type: Biquad Nov 27 17:36:36 volumio volumio[835]: parameters: Nov 27 17:36:36 volumio volumio[835]: type: Peaking Nov 27 17:36:36 volumio volumio[835]: freq: 68.40 Nov 27 17:36:36 volumio volumio[835]: q: 14.356 Nov 27 17:36:36 volumio volumio[835]: gain: -12.10 Nov 27 17:36:36 volumio volumio[835]: eq6: Nov 27 17:36:36 volumio volumio[835]: type: Biquad Nov 27 17:36:36 volumio volumio[835]: parameters: Nov 27 17:36:36 volumio volumio[835]: type: Peaking Nov 27 17:36:36 volumio volumio[835]: freq: 134.5 Nov 27 17:36:36 volumio volumio[835]: q: 16.130 Nov 27 17:36:36 volumio volumio[835]: gain: -8.20 Nov 27 17:36:36 volumio volumio[835]: eq7: Nov 27 17:36:36 volumio volumio[835]: type: Biquad Nov 27 17:36:36 volumio volumio[835]: parameters: Nov 27 17:36:36 volumio volumio[835]: type: Peaking Nov 27 17:36:36 volumio volumio[835]: freq: 93.00 Nov 27 17:36:36 volumio volumio[835]: q: 21.275 Nov 27 17:36:36 volumio volumio[835]: gain: -7.40 Nov 27 17:36:36 volumio volumio[835]: eq8: Nov 27 17:36:36 volumio volumio[835]: type: Biquad Nov 27 17:36:36 volumio volumio[835]: parameters: Nov 27 17:36:36 volumio volumio[835]: type: Peaking Nov 27 17:36:36 volumio volumio[835]: freq: 77.20 Nov 27 17:36:36 volumio volumio[835]: q: 11.330 Nov 27 17:36:36 volumio volumio[835]: gain: -7.20 Nov 27 17:36:36 volumio volumio[835]: eq9: Nov 27 17:36:36 volumio volumio[835]: type: Biquad Nov 27 17:36:36 volumio volumio[835]: parameters: Nov 27 17:36:36 volumio volumio[835]: type: Peaking Nov 27 17:36:36 volumio volumio[835]: freq: 144.0 Nov 27 17:36:36 volumio volumio[835]: q: 14.587 Nov 27 17:36:36 volumio volumio[835]: gain: -7.00 Nov 27 17:36:36 volumio volumio[835]: eq10: Nov 27 17:36:36 volumio volumio[835]: type: Biquad Nov 27 17:36:36 volumio volumio[835]: parameters: Nov 27 17:36:36 volumio volumio[835]: type: Peaking Nov 27 17:36:36 volumio volumio[835]: freq: 776.0 Nov 27 17:36:36 volumio volumio[835]: q: 2.588 Nov 27 17:36:36 volumio volumio[835]: gain: -4.50 Nov 27 17:36:36 volumio volumio[835]: eq11: Nov 27 17:36:36 volumio volumio[835]: type: Biquad Nov 27 17:36:36 volumio volumio[835]: parameters: Nov 27 17:36:36 volumio volumio[835]: type: Peaking Nov 27 17:36:36 volumio volumio[835]: freq: 492.0 Nov 27 17:36:36 volumio volumio[835]: q: 5.000 Nov 27 17:36:36 volumio volumio[835]: gain: -3.70 Nov 27 17:36:36 volumio volumio[835]: eq12: Nov 27 17:36:36 volumio volumio[835]: type: Biquad Nov 27 17:36:36 volumio volumio[835]: parameters: Nov 27 17:36:36 volumio volumio[835]: type: Peaking Nov 27 17:36:36 volumio volumio[835]: freq: 30.00 Nov 27 17:36:36 volumio volumio[835]: q: 2.000 Nov 27 17:36:36 volumio volumio[835]: gain: 3.00 Nov 27 17:36:36 volumio volumio[835]: info: FusionDsp - Loudness is ON true Nov 27 17:36:36 volumio volumio[835]: info: FusionDsp - highshelf: Nov 27 17:36:36 volumio volumio[835]: type: Biquad Nov 27 17:36:36 volumio volumio[835]: parameters: Nov 27 17:36:36 volumio volumio[835]: type: Highshelf Nov 27 17:36:36 volumio volumio[835]: freq: 10620 Nov 27 17:36:36 volumio volumio[835]: q: 1.38 Nov 27 17:36:36 volumio volumio[835]: gain: 3.40 Nov 27 17:36:36 volumio volumio[835]: lowshelf: Nov 27 17:36:36 volumio volumio[835]: type: Biquad Nov 27 17:36:36 volumio volumio[835]: parameters: Nov 27 17:36:36 volumio volumio[835]: type: LowshelfFO Nov 27 17:36:36 volumio volumio[835]: freq: 120 Nov 27 17:36:36 volumio volumio[835]: gain: 12.11 Nov 27 17:36:36 volumio volumio[835]: peakloudness: Nov 27 17:36:36 volumio volumio[835]: type: Biquad Nov 27 17:36:36 volumio volumio[835]: parameters: Nov 27 17:36:36 volumio volumio[835]: type: Peaking Nov 27 17:36:36 volumio volumio[835]: freq: 2000 Nov 27 17:36:36 volumio volumio[835]: q: 0.6 Nov 27 17:36:36 volumio volumio[835]: gain: -0.74 Nov 27 17:36:36 volumio volumio[835]: peakloudness2: Nov 27 17:36:36 volumio volumio[835]: type: Biquad Nov 27 17:36:36 volumio volumio[835]: parameters: Nov 27 17:36:36 volumio volumio[835]: type: Peaking Nov 27 17:36:36 volumio volumio[835]: freq: 4000 Nov 27 17:36:36 volumio volumio[835]: q: 0.8 Nov 27 17:36:36 volumio volumio[835]: gain: -0.33 Nov 27 17:36:36 volumio volumio[835]: peakloudness3: Nov 27 17:36:36 volumio volumio[835]: type: Biquad Nov 27 17:36:36 volumio volumio[835]: parameters: Nov 27 17:36:36 volumio volumio[835]: type: Peaking Nov 27 17:36:36 volumio volumio[835]: freq: 8000 Nov 27 17:36:36 volumio volumio[835]: q: 2.13 Nov 27 17:36:36 volumio volumio[835]: gain: 0.86 Nov 27 17:36:36 volumio volumio[835]: eq1: Nov 27 17:36:36 volumio volumio[835]: type: Biquad Nov 27 17:36:36 volumio volumio[835]: parameters: Nov 27 17:36:36 volumio volumio[835]: type: Peaking Nov 27 17:36:36 volumio volumio[835]: freq: 147.0 Nov 27 17:36:36 volumio volumio[835]: q: 5.000 Nov 27 17:36:36 volumio volumio[835]: gain: -5.80 Nov 27 17:36:36 volumio volumio[835]: eq2: Nov 27 17:36:36 volumio volumio[835]: type: Biquad Nov 27 17:36:36 volumio volumio[835]: parameters: Nov 27 17:36:36 volumio volumio[835]: type: Peaking Nov 27 17:36:36 volumio volumio[835]: freq: 46.80 Nov 27 17:36:36 volumio volumio[835]: q: 5.000 Nov 27 17:36:36 volumio volumio[835]: gain: -5.10 Nov 27 17:36:36 volumio volumio[835]: eq3: Nov 27 17:36:36 volumio volumio[835]: type: Biquad Nov 27 17:36:36 volumio volumio[835]: parameters: Nov 27 17:36:36 volumio volumio[835]: type: Peaking Nov 27 17:36:36 volumio volumio[835]: freq: 842.0 Nov 27 17:36:36 volumio volumio[835]: q: 2.197 Nov 27 17:36:36 volumio volumio[835]: gain: -4.90 Nov 27 17:36:36 volumio volumio[835]: eq4: Nov 27 17:36:36 volumio volumio[835]: type: Biquad Nov 27 17:36:36 volumio volumio[835]: parameters: Nov 27 17:36:36 volumio volumio[835]: type: Peaking Nov 27 17:36:36 volumio volumio[835]: freq: 113.0 Nov 27 17:36:36 volumio volumio[835]: q: 14.348 Nov 27 17:36:36 volumio volumio[835]: gain: -13.30 Nov 27 17:36:36 volumio volumio[835]: eq5: Nov 27 17:36:36 volumio volumio[835]: type: Biquad Nov 27 17:36:36 volumio volumio[835]: parameters: Nov 27 17:36:36 volumio volumio[835]: type: Peaking Nov 27 17:36:36 volumio volumio[835]: freq: 68.40 Nov 27 17:36:36 volumio volumio[835]: q: 14.356 Nov 27 17:36:36 volumio volumio[835]: gain: -12.10 Nov 27 17:36:36 volumio volumio[835]: eq6: Nov 27 17:36:36 volumio volumio[835]: type: Biquad Nov 27 17:36:36 volumio volumio[835]: parameters: Nov 27 17:36:36 volumio volumio[835]: type: Peaking Nov 27 17:36:36 volumio volumio[835]: freq: 134.5 Nov 27 17:36:36 volumio volumio[835]: q: 16.130 Nov 27 17:36:36 volumio volumio[835]: gain: -8.20 Nov 27 17:36:36 volumio volumio[835]: eq7: Nov 27 17:36:36 volumio volumio[835]: type: Biquad Nov 27 17:36:36 volumio volumio[835]: parameters: Nov 27 17:36:36 volumio volumio[835]: type: Peaking Nov 27 17:36:36 volumio volumio[835]: freq: 93.00 Nov 27 17:36:36 volumio volumio[835]: q: 21.275 Nov 27 17:36:36 volumio volumio[835]: gain: -7.40 Nov 27 17:36:36 volumio volumio[835]: eq8: Nov 27 17:36:36 volumio volumio[835]: type: Biquad Nov 27 17:36:36 volumio volumio[835]: parameters: Nov 27 17:36:36 volumio volumio[835]: type: Peaking Nov 27 17:36:36 volumio volumio[835]: freq: 77.20 Nov 27 17:36:36 volumio volumio[835]: q: 11.330 Nov 27 17:36:36 volumio volumio[835]: gain: -7.20 Nov 27 17:36:36 volumio volumio[835]: eq9: Nov 27 17:36:36 volumio volumio[835]: type: Biquad Nov 27 17:36:36 volumio volumio[835]: parameters: Nov 27 17:36:36 volumio volumio[835]: type: Peaking Nov 27 17:36:36 volumio volumio[835]: freq: 144.0 Nov 27 17:36:36 volumio volumio[835]: q: 14.587 Nov 27 17:36:36 volumio volumio[835]: gain: -7.00 Nov 27 17:36:36 volumio volumio[835]: eq10: Nov 27 17:36:36 volumio volumio[835]: type: Biquad Nov 27 17:36:36 volumio volumio[835]: parameters: Nov 27 17:36:36 volumio volumio[835]: type: Peaking Nov 27 17:36:36 volumio volumio[835]: freq: 776.0 Nov 27 17:36:36 volumio volumio[835]: q: 2.588 Nov 27 17:36:36 volumio volumio[835]: gain: -4.50 Nov 27 17:36:36 volumio volumio[835]: eq11: Nov 27 17:36:36 volumio volumio[835]: type: Biquad Nov 27 17:36:36 volumio volumio[835]: parameters: Nov 27 17:36:36 volumio volumio[835]: type: Peaking Nov 27 17:36:36 volumio volumio[835]: freq: 492.0 Nov 27 17:36:36 volumio volumio[835]: q: 5.000 Nov 27 17:36:36 volumio volumio[835]: gain: -3.70 Nov 27 17:36:36 volumio volumio[835]: eq12: Nov 27 17:36:36 volumio volumio[835]: type: Biquad Nov 27 17:36:36 volumio volumio[835]: parameters: Nov 27 17:36:36 volumio volumio[835]: type: Peaking Nov 27 17:36:36 volumio volumio[835]: freq: 30.00 Nov 27 17:36:36 volumio volumio[835]: q: 2.000 Nov 27 17:36:36 volumio volumio[835]: gain: 3.00 Nov 27 17:36:36 volumio volumio[835]: error: FusionDsp - WebSocket error: [object Object] Nov 27 17:36:37 volumio go-librespot[1727]: time="2024-11-27T17:36:37+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 27 17:36:37 volumio go-librespot[1727]: time="2024-11-27T17:36:37+01:00" level=debug msg="sending successful reply for delaer request" Nov 27 17:36:37 volumio go-librespot[1727]: time="2024-11-27T17:36:37+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Nov 27 17:36:37 volumio go-librespot[1727]: time="2024-11-27T17:36:37+01:00" level=trace msg="emitting websocket event: playing" Nov 27 17:36:37 volumio volumio[835]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:6VV8EboIsnmgv8Yy11g6Ww","play_origin":"playlist"}} Nov 27 17:36:37 volumio volumio[835]: SPOTIFY: PUSH STATE SPOTIFY Nov 27 17:36:37 volumio volumio[835]: SPOTIFY: {"status":"play","service":"spop","title":"Last Christmas","artist":"Jimmy Eat World","album":"Bleed American (Deluxe Edition)","albumart":"https://i.scdn.co/image/ab67616d00001e022f0d89b1c4dcebefda07a959","uri":"spotify:track:6VV8EboIsnmgv8Yy11g6Ww","trackType":"spotify","seek":43291,"duration":267,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Nov 27 17:36:37 volumio volumio[835]: info: CoreCommandRouter::servicePushState Nov 27 17:36:37 volumio volumio[835]: info: CoreStateMachine::pushState Nov 27 17:36:37 volumio volumio[835]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 27 17:36:37 volumio volumio[835]: info: CoreCommandRouter::volumioPushState Nov 27 17:36:37 volumio volumio[835]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:6VV8EboIsnmgv8Yy11g6Ww","play_origin":"playlist"}} Nov 27 17:36:37 volumio volumio[835]: SPOTIFY: PUSH STATE SPOTIFY Nov 27 17:36:37 volumio volumio[835]: SPOTIFY: {"status":"play","service":"spop","title":"Last Christmas","artist":"Jimmy Eat World","album":"Bleed American (Deluxe Edition)","albumart":"https://i.scdn.co/image/ab67616d00001e022f0d89b1c4dcebefda07a959","uri":"spotify:track:6VV8EboIsnmgv8Yy11g6Ww","trackType":"spotify","seek":43291,"duration":267,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Nov 27 17:36:37 volumio volumio[835]: info: CoreCommandRouter::servicePushState Nov 27 17:36:37 volumio volumio[835]: info: CoreStateMachine::pushState Nov 27 17:36:37 volumio volumio[835]: info: CoreCommandRouter::volumioPushState Nov 27 17:36:37 volumio volumio[835]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 Nov 27 17:36:37 volumio volumio[835]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 Nov 27 17:36:37 volumio volumio[835]: SPOTIFY: PUSH STATE SPOTIFY Nov 27 17:36:37 volumio volumio[835]: SPOTIFY: {"status":"play","service":"spop","title":"Last Christmas","artist":"Jimmy Eat World","album":"Bleed American (Deluxe Edition)","albumart":"https://i.scdn.co/image/ab67616d00001e022f0d89b1c4dcebefda07a959","uri":"spotify:track:6VV8EboIsnmgv8Yy11g6Ww","trackType":"spotify","seek":43291,"duration":267,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Nov 27 17:36:37 volumio volumio[835]: info: CoreCommandRouter::servicePushState Nov 27 17:36:37 volumio volumio[835]: info: CoreStateMachine::pushState Nov 27 17:36:37 volumio volumio[835]: info: CoreCommandRouter::volumioPushState Nov 27 17:36:37 volumio volumio[835]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 Nov 27 17:36:37 volumio volumio[835]: SPOTIFY: PUSH STATE SPOTIFY Nov 27 17:36:37 volumio volumio[835]: SPOTIFY: {"status":"play","service":"spop","title":"Last Christmas","artist":"Jimmy Eat World","album":"Bleed American (Deluxe Edition)","albumart":"https://i.scdn.co/image/ab67616d00001e022f0d89b1c4dcebefda07a959","uri":"spotify:track:6VV8EboIsnmgv8Yy11g6Ww","trackType":"spotify","seek":43291,"duration":267,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Nov 27 17:36:37 volumio volumio[835]: info: CoreCommandRouter::servicePushState Nov 27 17:36:37 volumio volumio[835]: info: CoreStateMachine::pushState Nov 27 17:36:37 volumio volumio[835]: info: CoreCommandRouter::volumioPushState Nov 27 17:36:37 volumio volumio[835]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 Nov 27 17:36:37 volumio volumio[835]: SPOTIFY: SETTING SPOTIFY VOLUME 50 Nov 27 17:36:37 volumio volumio[835]: info: Sending Spotify command with payload to local API: /player/volume Nov 27 17:36:37 volumio go-librespot[1727]: time="2024-11-27T17:36:37+01:00" level=debug msg="update volume to 32767/65535" Nov 27 17:36:37 volumio go-librespot[1727]: time="2024-11-27T17:36:37+01:00" level=debug msg="put connect state because VOLUME_CHANGED" Nov 27 17:36:37 volumio go-librespot[1727]: time="2024-11-27T17:36:37+01:00" level=trace msg="emitting websocket event: volume" Nov 27 17:36:37 volumio volumio[835]: SPOTIFY: received: {"type":"volume","data":{"value":50,"max":100}} Nov 27 17:36:37 volumio volumio[835]: SPOTIFY: RECEIVED SPOTIFY VOLUME 50 Nov 27 17:36:37 volumio volumio[835]: SPOTIFY: received: {"type":"volume","data":{"value":50,"max":100}} Nov 27 17:36:37 volumio volumio[835]: SPOTIFY: RECEIVED SPOTIFY VOLUME 50 Nov 27 17:36:43 volumio go-librespot[1727]: time="2024-11-27T17:36:43+01:00" level=debug msg="handling skip_next player command from 96fd8c4ec411c0000e44a3dc1fe7d49784c07a7d" Nov 27 17:36:43 volumio go-librespot[1727]: time="2024-11-27T17:36:43+01:00" level=debug msg="skip next track" Nov 27 17:36:49 volumio go-librespot[1727]: time="2024-11-27T17:36:49+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 250" Nov 27 17:36:49 volumio go-librespot[1727]: time="2024-11-27T17:36:49+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1310" Nov 27 17:36:50 volumio go-librespot[1727]: time="2024-11-27T17:36:50+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 341" Nov 27 17:36:57 volumio volumio[835]: verbose: New Socket.io Connection to 192.168.178.48 from 192.168.178.85 UA: Mozilla/5.0 (Linux; Android 15; Pixel 8 Pro Build/AP3A.241105.007; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/131.0.6778.39 Mobile Safari/537.36 Total Clients: 6 Nov 27 17:36:57 volumio volumio[835]: verbose: New Socket.io Connection to 192.168.178.48 from 192.168.178.85 UA: Mozilla/5.0 (Linux; Android 15; Pixel 8 Pro Build/AP3A.241105.007; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/131.0.6778.39 Mobile Safari/537.36 Total Clients: 7 Nov 27 17:36:57 volumio volumio[835]: verbose: New Socket.io Connection to 192.168.178.48 from 192.168.178.85 UA: Mozilla/5.0 (Linux; Android 15; Pixel 8 Pro Build/AP3A.241105.007; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/131.0.6778.39 Mobile Safari/537.36 Total Clients: 8 Nov 27 17:36:57 volumio volumio[835]: verbose: New Socket.io Connection to 192.168.178.48 from 192.168.178.85 UA: Mozilla/5.0 (Linux; Android 15; Pixel 8 Pro Build/AP3A.241105.007; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/131.0.6778.39 Mobile Safari/537.36 Total Clients: 9 Nov 27 17:36:57 volumio volumio[835]: verbose: New Socket.io Connection to 192.168.178.48 from 192.168.178.85 UA: Mozilla/5.0 (Linux; Android 15; Pixel 8 Pro Build/AP3A.241105.007; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/131.0.6778.39 Mobile Safari/537.36 Total Clients: 10 Nov 27 17:36:57 volumio volumio[835]: verbose: New Socket.io Connection to 192.168.178.48 from 192.168.178.85 UA: Mozilla/5.0 (Linux; Android 15; Pixel 8 Pro Build/AP3A.241105.007; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/131.0.6778.39 Mobile Safari/537.36 Total Clients: 11 Nov 27 17:37:00 volumio volumio[835]: verbose: New Socket.io Connection to 192.168.178.48 from 192.168.178.85 UA: Mozilla/5.0 (Linux; Android 15; Pixel 8 Pro Build/AP3A.241105.007; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/131.0.6778.39 Mobile Safari/537.36 Total Clients: 12 Nov 27 17:37:00 volumio volumio[835]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Nov 27 17:37:00 volumio volumio[835]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Nov 27 17:37:00 volumio volumio[835]: info: CoreCommandRouter::volumioGetVisibleSources Nov 27 17:37:00 volumio volumio[835]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 27 17:37:00 volumio volumio[835]: info: CoreCommandRouter::volumioGetState Nov 27 17:37:00 volumio volumio[835]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Nov 27 17:37:00 volumio volumio[835]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Nov 27 17:37:00 volumio volumio[835]: info: Received Get System Info Nov 27 17:37:00 volumio volumio[835]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 27 17:37:00 volumio volumio[835]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 27 17:37:00 volumio volumio[835]: info: Discovery: Getting this device information Nov 27 17:37:00 volumio volumio[835]: info: CoreCommandRouter::volumioGetState Nov 27 17:37:00 volumio volumio[835]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 27 17:37:00 volumio volumio[835]: info: CoreCommandRouter::volumioGetState Nov 27 17:37:00 volumio volumio[835]: info: Listing playlists Nov 27 17:37:00 volumio volumio[835]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Nov 27 17:37:00 volumio volumio[835]: info: CoreCommandRouter::getUIConfigOnPlugin Nov 27 17:37:09 volumio volumio[835]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Nov 27 17:37:09 volumio volumio[835]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Nov 27 17:37:09 volumio volumio[835]: info: CoreCommandRouter::getUIConfigOnPlugin Nov 27 17:37:14 volumio volumio[835]: info: Enabling plugin fusiondsp Nov 27 17:37:14 volumio volumio[835]: info: Loading plugin "fusiondsp"... Nov 27 17:37:14 volumio volumio[835]: info: Applying required configuration parameters for plugin fusiondsp Nov 27 17:37:14 volumio volumio[835]: info: Preparing to generate the ALSA configuration file Nov 27 17:37:14 volumio volumio[835]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Nov 27 17:37:14 volumio volumio[835]: info: Reading ALSA contributions from plugins. Nov 27 17:37:14 volumio volumio[835]: info: Asound.conf file unchanged, so no further update is needed Nov 27 17:37:14 volumio volumio[835]: info: Output device has changed, restarting MPD Nov 27 17:37:14 volumio sudo[1789]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Nov 27 17:37:14 volumio sudo[1789]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 27 17:37:14 volumio sudo[1789]: pam_unix(sudo:session): session closed for user root Nov 27 17:37:14 volumio volumio[835]: info: PLUGIN START: fusiondsp Nov 27 17:37:14 volumio volumio[835]: info: Loading i18n strings for locale de Nov 27 17:37:14 volumio volumio[835]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile Nov 27 17:37:14 volumio volumio[835]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 27 17:37:14 volumio volumio[835]: info: FusionDsp - mixtype--------------------- Hardware Nov 27 17:37:14 volumio sudo[1792]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Nov 27 17:37:14 volumio volumio[835]: info: Preparing to generate the ALSA configuration file Nov 27 17:37:14 volumio sudo[1792]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 27 17:37:14 volumio volumio[835]: info: Done. Nov 27 17:37:14 volumio volumio[835]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Nov 27 17:37:14 volumio volumio[835]: info: Reading ALSA contributions from plugins. Nov 27 17:37:14 volumio volumio[835]: info: MPD Permissions set Nov 27 17:37:14 volumio systemd[1]: Stopping Music Player Daemon... Nov 27 17:37:14 volumio volumio[835]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 27 17:37:14 volumio volumio[835]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 27 17:37:14 volumio volumio[835]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 27 17:37:14 volumio volumio[835]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 27 17:37:14 volumio volumio[835]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 27 17:37:14 volumio volumio[835]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 27 17:37:14 volumio volumio[835]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 27 17:37:14 volumio volumio[835]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 27 17:37:14 volumio volumio[835]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 27 17:37:14 volumio volumio[835]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 27 17:37:14 volumio volumio[835]: info: CoreCommandRouter::getUIConfigOnPlugin Nov 27 17:37:14 volumio volumio[835]: info: Asound.conf file unchanged, so no further update is needed Nov 27 17:37:14 volumio volumio[835]: info: Output device has changed, restarting MPD Nov 27 17:37:14 volumio sudo[1799]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Nov 27 17:37:14 volumio sudo[1799]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 27 17:37:14 volumio sudo[1799]: pam_unix(sudo:session): session closed for user root Nov 27 17:37:14 volumio systemd[1]: mpd.service: Succeeded. Nov 27 17:37:14 volumio systemd[1]: Stopped Music Player Daemon. Nov 27 17:37:14 volumio sudo[1802]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Nov 27 17:37:14 volumio systemd[1]: Starting Music Player Daemon... Nov 27 17:37:14 volumio sudo[1802]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 27 17:37:14 volumio systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM Nov 27 17:37:14 volumio systemd[1]: mpd.service: Succeeded. Nov 27 17:37:14 volumio systemd[1]: Stopped Music Player Daemon. Nov 27 17:37:14 volumio systemd[1]: Starting Music Player Daemon... Nov 27 17:37:14 volumio volumio[835]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 27 17:37:14 volumio volumio[835]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 27 17:37:14 volumio volumio[835]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 27 17:37:14 volumio volumio[835]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 27 17:37:14 volumio volumio[835]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 27 17:37:14 volumio volumio[835]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 27 17:37:14 volumio volumio[835]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 27 17:37:14 volumio volumio[835]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 27 17:37:14 volumio volumio[835]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 27 17:37:14 volumio volumio[835]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 27 17:37:14 volumio volumio[835]: info: MPD Permissions set Nov 27 17:37:15 volumio mpd[1805]: Nov 27 17:37 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Nov 27 17:37:15 volumio systemd[1]: Started Music Player Daemon. Nov 27 17:37:15 volumio sudo[1802]: pam_unix(sudo:session): session closed for user root Nov 27 17:37:15 volumio sudo[1792]: pam_unix(sudo:session): session closed for user root Nov 27 17:37:15 volumio volumio[835]: error: MPD error: The expression evaluated to a falsy value: Nov 27 17:37:15 volumio volumio[835]: assert.ok(self.idling) Nov 27 17:37:15 volumio volumio[835]: error: The expression evaluated to a falsy value: Nov 27 17:37:15 volumio volumio[835]: assert.ok(self.idling) Nov 27 17:37:15 volumio volumio[835]: error: updateQueue error: null Nov 27 17:37:15 volumio volumio[835]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 27 17:37:15 volumio volumio[835]: TypeError: Cannot read property 'off' of undefined Nov 27 17:37:15 volumio volumio[835]: at FusionDsp.onStop (/data/plugins/audio_interface/fusiondsp/index.js:106:15) Nov 27 17:37:15 volumio volumio[835]: at PluginManager.stopPlugin (/volumio/app/pluginmanager.js:460:30) Nov 27 17:37:15 volumio volumio[835]: at PluginManager.disableAndStopPlugin (/volumio/app/pluginmanager.js:1883:8) Nov 27 17:37:15 volumio volumio[835]: at CoreCommandRouter.disableAndStopPlugin (/volumio/app/index.js:1531:29) Nov 27 17:37:15 volumio volumio[835]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:1356:47) Nov 27 17:37:15 volumio volumio[835]: at Socket.emit (events.js:315:20) Nov 27 17:37:15 volumio volumio[835]: at /volumio/node_modules/socket.io/lib/socket.js:503:12 Nov 27 17:37:15 volumio volumio[835]: at processTicksAndRejections (internal/process/task_queues.js:75:11) Nov 27 17:37:15 volumio volumio[835]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 27 17:37:16 volumio sudo[1821]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-11-27 17:36 Nov 27 17:37:16 volumio sudo[1821]: 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"