-- Logs begin at Thu 2019-02-14 18:11:59 HKT, end at Sun 2024-11-24 03:40:59 HKT. -- Nov 24 03:39:06 volumio ntpd[783]: Soliciting pool server 2606:4700:f1::1 Nov 24 03:39:11 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 24 03:39:11 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 24 03:39:11 volumio volumio[1071]: info: Discovery: Getting this device information Nov 24 03:39:11 volumio volumio[1071]: info: CoreCommandRouter::volumioGetState Nov 24 03:39:11 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 24 03:39:20 volumio volumio[1071]: info: CorePlayQueue::getTrack 3 Nov 24 03:39:20 volumio volumio[1071]: info: CorePlayQueue::getTrack 4 Nov 24 03:39:20 volumio volumio[1071]: info: Prefetching next song Nov 24 03:39:20 volumio volumio[1071]: info: [1732390760642] ControllerTidal::prefetch Nov 24 03:39:20 volumio volumio[1071]: info: Getting stream with soundQuality HI_RES Nov 24 03:39:20 volumio volumio[1071]: verbose: ControllerMpd::sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/35060646&soundQuality=HI_RES" Nov 24 03:39:20 volumio volumio[1071]: info: Nov 24 03:39:20 volumio volumio[1071]: ---------------------------- MPD announces system playlist update Nov 24 03:39:20 volumio volumio[1071]: info: Ignoring MPD Status Update Nov 24 03:39:20 volumio volumio[1071]: info: sendMpdCommand add "http://127.0.0.1:3245?data=tidal://song/35060646&soundQuality=HI_RES" took 2 milliseconds Nov 24 03:39:20 volumio volumio[1071]: info: CoreStateMachine::setConsumeUpdateService mpd Nov 24 03:39:20 volumio volumio[1071]: STREAMING PROXY: Handling url /?data=tidal://song/35060646&soundQuality=HI_RES Nov 24 03:39:20 volumio volumio[1071]: verbose: ControllerMpd::sendMpdCommand consume 1 Nov 24 03:39:20 volumio volumio[1071]: info: ------------------------------ 3ms Nov 24 03:39:20 volumio volumio[1071]: info: Nov 24 03:39:20 volumio volumio[1071]: ---------------------------- MPD announces state update: options Nov 24 03:39:20 volumio volumio[1071]: info: sendMpdCommand consume 1 took 3 milliseconds Nov 24 03:39:20 volumio volumio[1071]: info: ControllerMpd::getState Nov 24 03:39:20 volumio volumio[1071]: verbose: ControllerMpd::sendMpdCommand status Nov 24 03:39:20 volumio volumio[1071]: info: sendMpdCommand status took 1 milliseconds Nov 24 03:39:20 volumio volumio[1071]: verbose: ControllerMpd::parseState Nov 24 03:39:20 volumio volumio[1071]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 24 03:39:20 volumio volumio[1071]: info: sendMpdCommand playlistinfo took 1 milliseconds Nov 24 03:39:20 volumio volumio[1071]: verbose: ControllerMpd::parseTrackInfo Nov 24 03:39:20 volumio volumio[1071]: info: ControllerMpd::pushState Nov 24 03:39:20 volumio volumio[1071]: info: CoreCommandRouter::servicePushState Nov 24 03:39:20 volumio volumio[1071]: info: CorePlayQueue::getTrack 3 Nov 24 03:39:20 volumio volumio[1071]: verbose: STATE SERVICE {"status":"play","position":0,"seek":216122,"duration":221,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1096 Kbps","isStreaming":false,"title":"35060645&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/35060645&soundQuality=HI_RES","trackType":"tidal"} Nov 24 03:39:20 volumio volumio[1071]: verbose: CURRENT POSITION 3 Nov 24 03:39:20 volumio volumio[1071]: info: CoreStateMachine::syncState stateService play Nov 24 03:39:20 volumio volumio[1071]: info: CoreStateMachine::syncState currentStatus play Nov 24 03:39:20 volumio volumio[1071]: info: Received an update from plugin. extracting info from payload Nov 24 03:39:20 volumio volumio[1071]: info: CoreStateMachine::pushState Nov 24 03:39:20 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 24 03:39:20 volumio volumio[1071]: info: CoreCommandRouter::volumioPushState Nov 24 03:39:20 volumio volumio[1071]: info: MRS: Pushing multiroomSync output update for this device Nov 24 03:39:20 volumio volumio[1071]: info: MRS: Pushing multiroomSync output Nov 24 03:39:20 volumio volumio[1071]: info: CoreStateMachine::pushState Nov 24 03:39:20 volumio volumio[1071]: info: CoreCommandRouter::volumioPushState Nov 24 03:39:20 volumio volumio[1071]: info: MRS: Pushing multiroomSync output update for this device Nov 24 03:39:20 volumio volumio[1071]: info: MRS: Pushing multiroomSync output Nov 24 03:39:20 volumio volumio[1071]: info: ------------------------------ 34ms Nov 24 03:39:20 volumio volumio[1071]: info: Executing endpoint getStreamUrltidal Nov 24 03:39:20 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: tidal , getStreamUrlAPI Nov 24 03:39:21 volumio volumio[1071]: info: getStreamUrl took 345 milliseconds Nov 24 03:39:21 volumio volumio[1071]: STREAMING PROXY: Got real url: http://sp-pr-cf.audio.tidal.com/mediatracks/CAEaKwgDEic1Njg3YTUxYTk0NzAyMWE1Y2NmNDcyOWE1MDM2NjE4Ml82MS5tcDQ/0.flac?Expires=1732394360&Signature=rSvfp0qKZuZ6tL7SICNcC~47vlMlQMprx9DqlOYsgVEIl~88WUbV7kn0CZ2yVql9GiPSR2g-1mYbSEi3ctlJTQozRah0GN0F5EbNUJ-nXZLufMXJQHXQTst8NOH31lUmhh0pWX~G-mX94zbst6ydmEfeSR1gCMEigQql90kc1PFVTVMA9zUkswfurQBfCIP4b-kIuj5kKIiK0eXSrNwWh7xBhIQu36rwy7JPxb5sj~4s0kSEAqMMmq6iUxUSxF00WkREz8SnX1a0RVW7Zoe~SUhKhK-KkfiZ~MF90Lnyh6VJ5~sYoefEnyfdH8MwlOM2D8DpKaHXjQvNvDDsS8-jHg__&Key-Pair-Id=K14LZCZ9QUI4JL Nov 24 03:39:21 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Nov 24 03:39:21 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Nov 24 03:39:21 volumio volumio[1071]: STREAMING PROXY: Response: 200, length: 28532837 Nov 24 03:39:24 volumio volumio[1071]: info: CoreCommandRouter::getUIConfigOnPlugin Nov 24 03:39:24 volumio volumio[1071]: STREAMING PROXY: Client dropped request, destroying Nov 24 03:39:25 volumio volumio[1071]: info: CoreStateMachine::startPlaybackTimer Nov 24 03:39:25 volumio volumio[1071]: info: CorePlayQueue::getTrack 4 Nov 24 03:39:25 volumio volumio[1071]: info: CoreStateMachine::pushState Nov 24 03:39:25 volumio volumio[1071]: info: CorePlayQueue::getTrack 4 Nov 24 03:39:25 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 24 03:39:25 volumio volumio[1071]: info: CoreCommandRouter::volumioPushState Nov 24 03:39:25 volumio volumio[1071]: info: MRS: Pushing multiroomSync output update for this device Nov 24 03:39:25 volumio volumio[1071]: info: MRS: Pushing multiroomSync output Nov 24 03:39:25 volumio volumio[1071]: info: Nov 24 03:39:25 volumio volumio[1071]: ---------------------------- MPD announces system playlist update Nov 24 03:39:25 volumio volumio[1071]: info: Ignoring MPD Status Update Nov 24 03:39:25 volumio volumio[1071]: info: Nov 24 03:39:25 volumio volumio[1071]: ---------------------------- MPD announces state update: player Nov 24 03:39:25 volumio volumio[1071]: info: ControllerMpd::getState Nov 24 03:39:25 volumio volumio[1071]: verbose: ControllerMpd::sendMpdCommand status Nov 24 03:39:25 volumio volumio[1071]: info: ------------------------------ 2ms Nov 24 03:39:25 volumio volumio[1071]: info: sendMpdCommand status took 3 milliseconds Nov 24 03:39:25 volumio volumio[1071]: verbose: ControllerMpd::parseState Nov 24 03:39:25 volumio volumio[1071]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 24 03:39:25 volumio volumio[1071]: info: sendMpdCommand playlistinfo took 1 milliseconds Nov 24 03:39:25 volumio volumio[1071]: verbose: ControllerMpd::parseTrackInfo Nov 24 03:39:25 volumio volumio[1071]: info: ControllerMpd::pushState Nov 24 03:39:25 volumio volumio[1071]: info: CoreCommandRouter::servicePushState Nov 24 03:39:25 volumio volumio[1071]: info: CorePlayQueue::getTrack 4 Nov 24 03:39:25 volumio volumio[1071]: verbose: STATE SERVICE {"status":"play","position":0,"seek":22,"duration":240,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"35060646&soundQuality=HI_RES","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=tidal://song/35060646&soundQuality=HI_RES","trackType":"tidal"} Nov 24 03:39:25 volumio volumio[1071]: verbose: CURRENT POSITION 4 Nov 24 03:39:25 volumio volumio[1071]: info: CoreStateMachine::syncState stateService play Nov 24 03:39:25 volumio volumio[1071]: info: CoreStateMachine::syncState currentStatus play Nov 24 03:39:25 volumio volumio[1071]: info: Received an update from plugin. extracting info from payload Nov 24 03:39:25 volumio volumio[1071]: info: CoreStateMachine::pushState Nov 24 03:39:25 volumio volumio[1071]: info: CorePlayQueue::getTrack 4 Nov 24 03:39:25 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 24 03:39:25 volumio volumio[1071]: info: CoreCommandRouter::volumioPushState Nov 24 03:39:25 volumio volumio[1071]: info: MRS: Pushing multiroomSync output update for this device Nov 24 03:39:25 volumio volumio[1071]: info: MRS: Pushing multiroomSync output Nov 24 03:39:25 volumio volumio[1071]: info: CoreStateMachine::pushState Nov 24 03:39:25 volumio volumio[1071]: info: CorePlayQueue::getTrack 4 Nov 24 03:39:25 volumio volumio[1071]: info: CoreCommandRouter::volumioPushState Nov 24 03:39:25 volumio volumio[1071]: info: MRS: Pushing multiroomSync output update for this device Nov 24 03:39:25 volumio volumio[1071]: info: MRS: Pushing multiroomSync output Nov 24 03:39:25 volumio volumio[1071]: info: ------------------------------ 37ms Nov 24 03:39:33 volumio volumio[1071]: info: Received OAUTH Data Nov 24 03:39:33 volumio volumio[1071]: info: Executing Spotify Oauth Login Nov 24 03:39:33 volumio volumio[1071]: info: Saving Spotify Refresh Token Nov 24 03:39:34 volumio sudo[2367]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Nov 24 03:39:34 volumio sudo[2367]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 24 03:39:34 volumio sudo[2367]: pam_unix(sudo:session): session closed for user root Nov 24 03:39:34 volumio sudo[2370]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Nov 24 03:39:34 volumio sudo[2370]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 24 03:39:34 volumio sudo[2370]: pam_unix(sudo:session): session closed for user root Nov 24 03:39:34 volumio volumio[1071]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Nov 24 03:39:34 volumio volumio[1071]: SPOTIFY: BQAxs0uMCd94ccswmrbCMW5Gi2H-zpW6QgznHMzRU7g5PPZ45hUg6IfEImHH1ODU7H_iCUo4xn9TO_wLib9ISsAdttcc12omhQSrkySFWixKa_ipvpZPTIBQTcVjn6EXBj_MXBLI5OlRRK0EkNjLmY_v-ORBdp4SpgLXZdQBcYiUEjrOHQm9oRHVkUR7jLCmJvUMjkRGsDE0q0XAHkzRz41CY0u4H2gtiFA38mS4ay18mCDCq0cDXPk2N0X5UQ Nov 24 03:39:34 volumio volumio[1071]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Nov 24 03:39:34 volumio volumio[1071]: info: New Spotify access token = BQAxs0uMCd94ccswmrbCMW5Gi2H-zpW6QgznHMzRU7g5PPZ45hUg6IfEImHH1ODU7H_iCUo4xn9TO_wLib9ISsAdttcc12omhQSrkySFWixKa_ipvpZPTIBQTcVjn6EXBj_MXBLI5OlRRK0EkNjLmY_v-ORBdp4SpgLXZdQBcYiUEjrOHQm9oRHVkUR7jLCmJvUMjkRGsDE0q0XAHkzRz41CY0u4H2gtiFA38mS4ay18mCDCq0cDXPk2N0X5UQ Nov 24 03:39:34 volumio volumio[1071]: info: Spotify credentials grant success - running version from March 24, 2019 Nov 24 03:39:34 volumio volumio[1071]: verbose: New Socket.io Connection to 192.168.68.58 from 192.168.68.54 UA: Mozilla/5.0 (Linux; Android 13; 23013PC75G Build/TKQ1.220905.001; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/133.0.6848.2 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 7 Nov 24 03:39:34 volumio volumio[1071]: SPOTIFY: User informations: {"country":"HK","display_name":"Alex Lai","email":"54091497alex@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/54091497alex"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/54091497alex","id":"54091497alex","images":[{"height":300,"url":"https://platform-lookaside.fbsbx.com/platform/profilepic/?asid=378048669603168&height=300&width=300&ext=1734965809&hash=AbYUg6nV0JU8CdAGztFglESP","width":300},{"height":64,"url":"https://platform-lookaside.fbsbx.com/platform/profilepic/?asid=378048669603168&height=50&width=50&ext=1734965809&hash=AbbIe5CCymSvJm7WavhgBgCL","width":64}],"product":"premium","type":"user","uri":"spotify:user:54091497alex"} Nov 24 03:39:34 volumio volumio[1071]: info: Creating Spotify config file Nov 24 03:39:34 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 24 03:39:34 volumio volumio[1071]: info: Spotify config file written Nov 24 03:39:34 volumio sudo[2373]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart go-librespot-daemon.service Nov 24 03:39:34 volumio sudo[2373]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 24 03:39:34 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Nov 24 03:39:34 volumio systemd[1]: Stopping go-librespot Daemon... Nov 24 03:39:34 volumio systemd[1]: go-librespot-daemon.service: Main process exited, code=killed, status=15/TERM Nov 24 03:39:34 volumio systemd[1]: go-librespot-daemon.service: Succeeded. Nov 24 03:39:34 volumio systemd[1]: Stopped go-librespot Daemon. Nov 24 03:39:34 volumio volumio[1071]: ------------------------------------ BT MESSAGE: BT STATUS: running Nov 24 03:39:34 volumio volumio[1071]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Nov 24 03:39:34 volumio volumio[1071]: info: Connection to go-librespot Websocket closed Nov 24 03:39:34 volumio volumio[1071]: info: CoreCommandRouter::volumioGetVisibleSources Nov 24 03:39:34 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 24 03:39:34 volumio volumio[1071]: info: CoreCommandRouter::volumioGetState Nov 24 03:39:34 volumio volumio[1071]: info: CorePlayQueue::getTrack 4 Nov 24 03:39:34 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Nov 24 03:39:34 volumio volumio[1071]: info: CoreCommandRouter::getUIConfigOnPlugin Nov 24 03:39:34 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Nov 24 03:39:34 volumio volumio[1071]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom Nov 24 03:39:34 volumio volumio[1071]: info: Received Get System Info Nov 24 03:39:34 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 24 03:39:34 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 24 03:39:34 volumio volumio[1071]: info: Discovery: Getting this device information Nov 24 03:39:34 volumio volumio[1071]: info: CoreCommandRouter::volumioGetState Nov 24 03:39:34 volumio volumio[1071]: info: CorePlayQueue::getTrack 4 Nov 24 03:39:34 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 24 03:39:34 volumio volumio[1071]: info: CoreCommandRouter::volumioGetState Nov 24 03:39:34 volumio volumio[1071]: info: CorePlayQueue::getTrack 4 Nov 24 03:39:34 volumio volumio[1071]: info: Listing playlists Nov 24 03:39:34 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Nov 24 03:39:34 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Nov 24 03:39:34 volumio systemd[1]: Started go-librespot Daemon. Nov 24 03:39:34 volumio go-librespot[2376]: Librespot-go daemon starting... Nov 24 03:39:34 volumio sudo[2373]: pam_unix(sudo:session): session closed for user root Nov 24 03:39:34 volumio go-librespot[2376]: time="2024-11-24T03:39:34+08:00" level=info msg="generated new device id: 615b162d3eb3d60ec2382a2c75ae9ac685387d47" Nov 24 03:39:34 volumio go-librespot[2376]: time="2024-11-24T03:39:34+08:00" level=debug msg="stored credentials not found" Nov 24 03:39:34 volumio volumio[1071]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Nov 24 03:39:34 volumio volumio[1071]: SPOTIFY: BQAxDj1f6n4AYc7CsL9O_w9oqP_6qOvLpMxDpYRjGrz__wuYs2gVI36Z40Al4LOWd4dV40cZ1L1U7xl1B2bM-YrBnYYXVSE6d_l8KOxOImhFt0LfDOdD5o1KSCP_l5VD-D8EwewJqpGhh6yDpVmOrPDGcyohOa4S5UsMcyvJgEp0WutLW_6QeKHw6kM75JXz6DqPi5s84GhMSLLJOnABR37KTFb5BHMHIXDGqgPnXoMs3rp7i2WWuOw_4cgvIA Nov 24 03:39:34 volumio volumio[1071]: SPOTIFY: ------------------------------------------------------ ACCESS TOKEN ------------------------------------------------------ Nov 24 03:39:34 volumio volumio[1071]: info: New Spotify access token = BQAxDj1f6n4AYc7CsL9O_w9oqP_6qOvLpMxDpYRjGrz__wuYs2gVI36Z40Al4LOWd4dV40cZ1L1U7xl1B2bM-YrBnYYXVSE6d_l8KOxOImhFt0LfDOdD5o1KSCP_l5VD-D8EwewJqpGhh6yDpVmOrPDGcyohOa4S5UsMcyvJgEp0WutLW_6QeKHw6kM75JXz6DqPi5s84GhMSLLJOnABR37KTFb5BHMHIXDGqgPnXoMs3rp7i2WWuOw_4cgvIA Nov 24 03:39:34 volumio volumio[1071]: info: Spotify credentials grant success - running version from March 24, 2019 Nov 24 03:39:34 volumio go-librespot[2376]: time="2024-11-24T03:39:34+08:00" level=debug msg="fetched new accesspoints: [ap-gae2.spotify.com:4070 ap-gae2.spotify.com:443 ap-gae2.spotify.com:80 ap-gue1.spotify.com:4070 ap-gew1.spotify.com:443 ap-gew4.spotify.com:80]" Nov 24 03:39:34 volumio go-librespot[2376]: time="2024-11-24T03:39:34+08:00" level=debug msg="fetched new dealers: [gae2-dealer.spotify.com:443 gue1-dealer.spotify.com:443 gew1-dealer.spotify.com:443 gew4-dealer.spotify.com:443]" Nov 24 03:39:34 volumio go-librespot[2376]: time="2024-11-24T03:39:34+08:00" level=debug msg="fetched new spclients: [gae2-spclient.spotify.com:443 gue1-spclient.spotify.com:443 gew1-spclient.spotify.com:443 gew4-spclient.spotify.com:443]" Nov 24 03:39:34 volumio go-librespot[2376]: time="2024-11-24T03:39:34+08:00" level=debug msg="zeroconf server listening on port 33887" Nov 24 03:39:34 volumio volumio[1071]: SPOTIFY: User informations: {"country":"HK","display_name":"Alex Lai","email":"54091497alex@gmail.com","explicit_content":{"filter_enabled":false,"filter_locked":false},"external_urls":{"spotify":"https://open.spotify.com/user/54091497alex"},"followers":{"href":null,"total":0},"href":"https://api.spotify.com/v1/users/54091497alex","id":"54091497alex","images":[{"height":300,"url":"https://platform-lookaside.fbsbx.com/platform/profilepic/?asid=378048669603168&height=300&width=300&ext=1734965809&hash=AbYUg6nV0JU8CdAGztFglESP","width":300},{"height":64,"url":"https://platform-lookaside.fbsbx.com/platform/profilepic/?asid=378048669603168&height=50&width=50&ext=1734965809&hash=AbbIe5CCymSvJm7WavhgBgCL","width":64}],"product":"premium","type":"user","uri":"spotify:user:54091497alex"} Nov 24 03:39:34 volumio volumio[1071]: info: Spotify Successfully logged in Nov 24 03:39:34 volumio volumio[1071]: info: CoreCommandRouter::volumioAddToBrowseSources[object Object] Nov 24 03:39:34 volumio volumio[1071]: info: [1732390774658] CoreMusicLibrary::Adding element Spotify Nov 24 03:39:34 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 24 03:39:34 volumio volumio[1071]: Cannot find translation for source TIDAL Nov 24 03:39:34 volumio volumio[1071]: Cannot find translation for source Spotify Nov 24 03:39:34 volumio go-librespot[2376]: time="2024-11-24T03:39:34+08:00" level=debug msg="obtained new client token: AADDEoalgg/3Kk7srI/vNkmca2cpt5RxHozNRjXlF9SztzOBRUoe+GwU+G+a4TsUvsihsHTjKCSfolSUlmIfelIu0XBJLhM1zlMZuwdY0dUSw0J7wZAilfK2+3rXp9YoENE4/WedO+e7jlqSzn7rUlrE2F1+jqxLSeethlnuEtbKqmZvZnlVTB4ToieCfiJZQnB2+jw/HOkc/XTzl/3tldfNq51w3lKq9GFkZuckWMjiX0nBxQBaatlPAj0TFRw=" Nov 24 03:39:34 volumio go-librespot[2376]: time="2024-11-24T03:39:34+08:00" level=info msg="connected to ap-gae2.spotify.com:4070" Nov 24 03:39:34 volumio go-librespot[2376]: time="2024-11-24T03:39:34+08:00" level=debug msg="completed keyexchange" Nov 24 03:39:35 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Nov 24 03:39:35 volumio go-librespot[2376]: time="2024-11-24T03:39:35+08:00" level=debug msg="completed challenge" Nov 24 03:39:35 volumio go-librespot[2376]: time="2024-11-24T03:39:35+08:00" level=debug msg="authenticated as 54091497alex" Nov 24 03:39:35 volumio go-librespot[2376]: time="2024-11-24T03:39:35+08:00" level=debug msg="authenticated as 54091497alex" Nov 24 03:39:35 volumio go-librespot[2376]: time="2024-11-24T03:39:35+08:00" level=debug msg="dealer connection opened" Nov 24 03:39:35 volumio go-librespot[2376]: time="2024-11-24T03:39:35+08:00" level=debug msg="stored credentials for 54091497alex" Nov 24 03:39:35 volumio go-librespot[2376]: time="2024-11-24T03:39:35+08:00" level=debug msg="initializing zeroconf session, username: 54091497alex" Nov 24 03:39:35 volumio go-librespot[2376]: time="2024-11-24T03:39:35+08:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Nov 24 03:39:35 volumio go-librespot[2376]: time="2024-11-24T03:39:35+08:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Nov 24 03:39:35 volumio go-librespot[2376]: time="2024-11-24T03:39:35+08:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Nov 24 03:39:35 volumio go-librespot[2376]: time="2024-11-24T03:39:35+08:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Nov 24 03:39:35 volumio go-librespot[2376]: time="2024-11-24T03:39:35+08:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Nov 24 03:39:35 volumio go-librespot[2376]: time="2024-11-24T03:39:35+08:00" level=debug msg="autoplay enabled: false" Nov 24 03:39:35 volumio go-librespot[2376]: time="2024-11-24T03:39:35+08:00" level=debug msg="received connection id: N2NlZDUxYTQtOGZkMy00YzA4LWExOTItNTMzNGFjZDdhNGU0K2RlYWxlcit0Y3A6Ly8wYWM5NDlmZi5pcC5nYWUyLnNwb3RpZnkubmV0OjU3MDArOTQzQzY5MDI5QThGODBBMTVCOEZBQTZCMDBFRDE0ODZEQTZBRUE3NDk1RjJFRTNDODJDMTAwODQ3OEM0RDEzQw==" Nov 24 03:39:35 volumio go-librespot[2376]: time="2024-11-24T03:39:35+08:00" level=debug msg="put connect state because NEW_DEVICE" Nov 24 03:39:36 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Nov 24 03:39:36 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Nov 24 03:39:36 volumio volumio[1071]: info: Received Get System Info Nov 24 03:39:36 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 24 03:39:36 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 24 03:39:36 volumio volumio[1071]: info: Discovery: Getting this device information Nov 24 03:39:36 volumio volumio[1071]: info: CoreCommandRouter::volumioGetState Nov 24 03:39:36 volumio volumio[1071]: info: CorePlayQueue::getTrack 4 Nov 24 03:39:36 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 24 03:39:37 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Nov 24 03:39:37 volumio volumio[1071]: info: Received Get System Info Nov 24 03:39:37 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 24 03:39:37 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 24 03:39:37 volumio volumio[1071]: info: Discovery: Getting this device information Nov 24 03:39:37 volumio volumio[1071]: info: CoreCommandRouter::volumioGetState Nov 24 03:39:37 volumio volumio[1071]: info: CorePlayQueue::getTrack 4 Nov 24 03:39:37 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 24 03:39:37 volumio volumio[1071]: info: Initializing connection to go-librespot Websocket Nov 24 03:39:37 volumio go-librespot[2376]: time="2024-11-24T03:39:37+08:00" level=debug msg="new websocket client" Nov 24 03:39:37 volumio volumio[1071]: info: Connection to go-librespot Websocket established Nov 24 03:39:37 volumio volumio[1071]: info: go-librespot daemon successfully initialized Nov 24 03:39:40 volumio volumio[1071]: info: Getting Spotify volume Nov 24 03:39:40 volumio volumio[1071]: info: Spotify volume: 100 Nov 24 03:39:40 volumio volumio[1071]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Nov 24 03:39:40 volumio volumio[1071]: info: CoreCommandRouter::volumioGetState Nov 24 03:39:40 volumio volumio[1071]: info: CorePlayQueue::getTrack 4 Nov 24 03:39:40 volumio volumio[1071]: info: Initializing connection to go-librespot Websocket Nov 24 03:39:40 volumio go-librespot[2376]: time="2024-11-24T03:39:40+08:00" level=debug msg="new websocket client" Nov 24 03:39:40 volumio volumio[1071]: info: Connection to go-librespot Websocket established Nov 24 03:39:41 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 24 03:39:41 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 24 03:39:41 volumio volumio[1071]: info: Discovery: Getting this device information Nov 24 03:39:41 volumio volumio[1071]: info: CoreCommandRouter::volumioGetState Nov 24 03:39:41 volumio volumio[1071]: info: CorePlayQueue::getTrack 4 Nov 24 03:39:41 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 24 03:39:43 volumio volumio[1071]: info: Getting Spotify volume Nov 24 03:39:43 volumio volumio[1071]: info: Spotify volume: 100 Nov 24 03:39:43 volumio volumio[1071]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 Nov 24 03:39:43 volumio volumio[1071]: info: CoreCommandRouter::volumioGetState Nov 24 03:39:43 volumio volumio[1071]: info: CorePlayQueue::getTrack 4 Nov 24 03:39:44 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Nov 24 03:39:49 volumio volumio[1071]: info: CoreCommandRouter::getUIConfigOnPlugin Nov 24 03:39:49 volumio volumio[1071]: xcb_connection_has_error() returned true Nov 24 03:39:49 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Nov 24 03:39:49 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 24 03:39:49 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Nov 24 03:39:49 volumio volumio[1071]: info: Getting Alsa Cards List without I2S DAC Nov 24 03:39:49 volumio volumio[1071]: xcb_connection_has_error() returned true Nov 24 03:39:49 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2SNumber Nov 24 03:39:49 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 24 03:39:49 volumio volumio[1071]: xcb_connection_has_error() returned true Nov 24 03:39:49 volumio volumio[1071]: xcb_connection_has_error() returned true Nov 24 03:39:49 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 24 03:39:49 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 24 03:39:49 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 24 03:39:49 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 24 03:39:49 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 24 03:39:49 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 24 03:39:49 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 24 03:39:49 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Nov 24 03:39:49 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Nov 24 03:39:53 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Nov 24 03:39:53 volumio volumio[1071]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Nov 24 03:39:53 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Nov 24 03:39:53 volumio volumio[1071]: info: Received Get System Version Nov 24 03:39:53 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 24 03:39:53 volumio volumio[1071]: info: Received Get System Info Nov 24 03:39:53 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 24 03:39:53 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 24 03:39:53 volumio volumio[1071]: info: Discovery: Getting this device information Nov 24 03:39:53 volumio volumio[1071]: info: CoreCommandRouter::volumioGetState Nov 24 03:39:53 volumio volumio[1071]: info: CorePlayQueue::getTrack 4 Nov 24 03:39:53 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 24 03:40:02 volumio volumio[1071]: info: CALLMETHOD: audio_interface alsa_controller saveVolumeOptions [object Object] Nov 24 03:40:02 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , saveVolumeOptions Nov 24 03:40:02 volumio volumio[1071]: info: CoreCommandRouter::volumioGetState Nov 24 03:40:02 volumio volumio[1071]: info: CorePlayQueue::getTrack 4 Nov 24 03:40:02 volumio volumio[1071]: info: Restoring Previous Volume level: 100 false true Nov 24 03:40:02 volumio volumio[1071]: info: VolumeController::SetAlsaVolume100 Nov 24 03:40:02 volumio volumio[1071]: info: Enable softmixer device for audio device number 2 Nov 24 03:40:02 volumio volumio[1071]: info: CoreCommandRouter::volumioStop Nov 24 03:40:02 volumio volumio[1071]: info: CoreStateMachine::stop Nov 24 03:40:02 volumio volumio[1071]: info: CoreStateMachine::setConsumeUpdateService undefined Nov 24 03:40:02 volumio volumio[1071]: info: CoreStateMachine::stPlaybackTimer Nov 24 03:40:02 volumio volumio[1071]: info: CoreStateMachine::updateTrackBlock Nov 24 03:40:02 volumio volumio[1071]: info: CorePlayQueue::getTrackBlock Nov 24 03:40:02 volumio volumio[1071]: info: CoreStateMachine::pushState Nov 24 03:40:02 volumio volumio[1071]: info: CorePlayQueue::getTrack 4 Nov 24 03:40:02 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 24 03:40:02 volumio volumio[1071]: info: CoreCommandRouter::volumioPushState Nov 24 03:40:02 volumio volumio[1071]: info: MRS: Pushing multiroomSync output update for this device Nov 24 03:40:02 volumio volumio[1071]: info: MRS: Pushing multiroomSync output Nov 24 03:40:02 volumio volumio[1071]: info: CoreStateMachine::serviceStop Nov 24 03:40:02 volumio volumio[1071]: info: CorePlayQueue::getTrack 4 Nov 24 03:40:02 volumio volumio[1071]: info: CoreCommandRouter::serviceStop Nov 24 03:40:02 volumio volumio[1071]: info: [1732390802156] ControllerTidal::stop Nov 24 03:40:02 volumio volumio[1071]: info: CoreStateMachine::setConsumeUpdateService mpd Nov 24 03:40:02 volumio volumio[1071]: info: ControllerMpd::stop Nov 24 03:40:02 volumio volumio[1071]: verbose: ControllerMpd::sendMpdCommand stop Nov 24 03:40:02 volumio volumio[1071]: info: Enable softmixer device for audio device undefined Nov 24 03:40:02 volumio volumio[1071]: xcb_connection_has_error() returned true Nov 24 03:40:02 volumio volumio[1071]: info: CoreCommandRouter::volumioUpdateVolumeSettings Nov 24 03:40:02 volumio volumio[1071]: info: Updating Volume Controller Parameters: Device: 2 Name: R-PI DAC Mixer: Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 Nov 24 03:40:02 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Nov 24 03:40:02 volumio volumio[1071]: info: Disabling external Volume Control Nov 24 03:40:02 volumio volumio[1071]: info: Output device has changed, restarting MPD Nov 24 03:40:02 volumio sudo[2450]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Nov 24 03:40:02 volumio sudo[2450]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 24 03:40:02 volumio sudo[2450]: pam_unix(sudo:session): session closed for user root Nov 24 03:40:02 volumio volumio[1071]: info: Output device has changed, restarting Shairport Sync Nov 24 03:40:02 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 24 03:40:02 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 24 03:40:02 volumio sudo[2453]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Nov 24 03:40:02 volumio sudo[2453]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 24 03:40:02 volumio systemd[1]: Stopping Music Player Daemon... Nov 24 03:40:02 volumio volumio[1071]: xcb_connection_has_error() returned true Nov 24 03:40:02 volumio volumio[1071]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Nov 24 03:40:02 volumio volumio[1071]: xcb_connection_has_error() returned true Nov 24 03:40:02 volumio volumio[1071]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Nov 24 03:40:02 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 24 03:40:02 volumio systemd[1]: mpd.service: Succeeded. Nov 24 03:40:02 volumio systemd[1]: Stopped Music Player Daemon. Nov 24 03:40:02 volumio vtcs[1514]: [2024-11-24 03:40:02.311] [tisoc] [error] [SpkconServer.cpp:381] recv error. client fd=8 errorno=104 error=Connection reset by peer Nov 24 03:40:02 volumio vtcs[1514]: [2024-11-24 03:40:02.311] [tisoc] [error] [SpkconServer.cpp:376] recv error. socket disconnected Nov 24 03:40:02 volumio vtcs[1514]: [2024-11-24 03:40:02.311] [tisoc] [warning] [SessionManagerImpl.cpp:243] Illegal State: IDLE Nov 24 03:40:02 volumio systemd[1]: Starting Music Player Daemon... Nov 24 03:40:02 volumio sudo[2465]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Nov 24 03:40:02 volumio volumio[1071]: info: Volume configurations have been set Nov 24 03:40:02 volumio sudo[2465]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 24 03:40:02 volumio sudo[2469]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Nov 24 03:40:02 volumio systemd[1]: Stopping Volumio Tidal Connect Service... Nov 24 03:40:02 volumio sudo[2469]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 24 03:40:02 volumio systemd[1]: vtcs.service: Main process exited, code=killed, status=15/TERM Nov 24 03:40:02 volumio systemd[1]: vtcs.service: Succeeded. Nov 24 03:40:02 volumio systemd[1]: Stopped Volumio Tidal Connect Service. Nov 24 03:40:02 volumio sudo[2465]: pam_unix(sudo:session): session closed for user root Nov 24 03:40:02 volumio volumio[1071]: xcb_connection_has_error() returned true Nov 24 03:40:02 volumio volumio[1071]: info: CoreCommandRouter::volumioUpdateVolumeSettings Nov 24 03:40:02 volumio volumio[1071]: info: Updating Volume Controller Parameters: Device: 2 Name: R-PI DAC Mixer: Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 Nov 24 03:40:02 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Nov 24 03:40:02 volumio volumio[1071]: info: Disabling external Volume Control Nov 24 03:40:02 volumio sudo[2469]: pam_unix(sudo:session): session closed for user root Nov 24 03:40:02 volumio sudo[2458]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Nov 24 03:40:02 volumio sudo[2458]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 24 03:40:02 volumio volumio[1071]: info: CoreCommandRouter::getUIConfigOnPlugin Nov 24 03:40:02 volumio sudo[2458]: pam_unix(sudo:session): session closed for user root Nov 24 03:40:02 volumio volumio[1071]: info: CoreStateMachine::pushState Nov 24 03:40:02 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 24 03:40:02 volumio volumio[1071]: info: CoreCommandRouter::volumioPushState Nov 24 03:40:02 volumio volumio[1071]: info: MRS: Pushing multiroomSync output update for this device Nov 24 03:40:02 volumio volumio[1071]: info: MRS: Pushing multiroomSync output Nov 24 03:40:02 volumio volumio[1071]: info: CoreStateMachine::pushState Nov 24 03:40:02 volumio volumio[1071]: info: CoreCommandRouter::volumioPushState Nov 24 03:40:02 volumio volumio[1071]: info: MRS: Pushing multiroomSync output update for this device Nov 24 03:40:02 volumio volumio[1071]: info: MRS: Pushing multiroomSync output Nov 24 03:40:02 volumio volumio[1071]: error: MPD error: Error: write EPIPE Nov 24 03:40:02 volumio volumio[1071]: error: write EPIPE {"errno":-32,"code":"EPIPE","syscall":"write"} Nov 24 03:40:02 volumio sudo[2484]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Nov 24 03:40:02 volumio sudo[2484]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 24 03:40:02 volumio sudo[2487]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Nov 24 03:40:02 volumio sudo[2487]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 24 03:40:02 volumio sudo[2484]: pam_unix(sudo:session): session closed for user root Nov 24 03:40:02 volumio volumio[1071]: ------------------------------------ BT MESSAGE: BT STATUS: running Nov 24 03:40:02 volumio volumio[1071]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Nov 24 03:40:02 volumio volumio[1071]: ------------------------------------ BT MESSAGE: BT STATUS: running Nov 24 03:40:02 volumio volumio[1071]: ------------------------------------ BT MESSAGE: BT STATUS: running Nov 24 03:40:02 volumio sudo[2487]: pam_unix(sudo:session): session closed for user root Nov 24 03:40:02 volumio volumio[1071]: info: CoreStateMachine::pushState Nov 24 03:40:02 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 24 03:40:02 volumio volumio[1071]: info: CoreCommandRouter::volumioPushState Nov 24 03:40:02 volumio volumio[1071]: info: MRS: Pushing multiroomSync output update for this device Nov 24 03:40:02 volumio volumio[1071]: info: MRS: Pushing multiroomSync output Nov 24 03:40:02 volumio volumio[1071]: info: MPD Permissions set Nov 24 03:40:02 volumio volumio[1071]: info: Software Volume ALSA configuration written Nov 24 03:40:02 volumio volumio[1071]: info: Preparing to generate the ALSA configuration file Nov 24 03:40:02 volumio volumio[1071]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Nov 24 03:40:02 volumio volumio[1071]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Nov 24 03:40:02 volumio volumio[1071]: info: Reading ALSA contributions from plugins. Nov 24 03:40:02 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 24 03:40:02 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 24 03:40:02 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 24 03:40:02 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 24 03:40:02 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 24 03:40:02 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 24 03:40:02 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 24 03:40:02 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 24 03:40:02 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 24 03:40:02 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 24 03:40:02 volumio volumio[1071]: xcb_connection_has_error() returned true Nov 24 03:40:02 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Nov 24 03:40:02 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 24 03:40:02 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Nov 24 03:40:02 volumio volumio[1071]: info: Getting Alsa Cards List without I2S DAC Nov 24 03:40:02 volumio volumio[1071]: xcb_connection_has_error() returned true Nov 24 03:40:02 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2SNumber Nov 24 03:40:02 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 24 03:40:02 volumio volumio[1071]: xcb_connection_has_error() returned true Nov 24 03:40:02 volumio volumio[1071]: xcb_connection_has_error() returned true Nov 24 03:40:02 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 24 03:40:02 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 24 03:40:02 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 24 03:40:02 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 24 03:40:02 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 24 03:40:02 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 24 03:40:02 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 24 03:40:02 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Nov 24 03:40:02 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Nov 24 03:40:02 volumio volumio[1071]: info: VolumeController::SetAlsaVolume0 Nov 24 03:40:02 volumio volumio[1071]: info: CoreStateMachine::pushState Nov 24 03:40:02 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 24 03:40:02 volumio volumio[1071]: info: CoreCommandRouter::volumioPushState Nov 24 03:40:02 volumio volumio[1071]: info: MRS: Pushing multiroomSync output update for this device Nov 24 03:40:02 volumio volumio[1071]: info: MRS: Pushing multiroomSync output Nov 24 03:40:02 volumio volumio[1071]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: xcb_connection_has_error() returned true Nov 24 03:40:02 volumio volumio[1071]: amixer: Unable to find simple control '',0 Nov 24 03:40:02 volumio volumio[1071]: info: Starting Shairport Sync Nov 24 03:40:02 volumio volumio[1071]: info: Asound.conf file written Nov 24 03:40:02 volumio sudo[2505]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Nov 24 03:40:02 volumio sudo[2505]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 24 03:40:03 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Nov 24 03:40:03 volumio systemd[1]: shairport-sync.service: Succeeded. Nov 24 03:40:03 volumio sudo[2508]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mv /home/volumio/.asoundrc /etc/asound.conf Nov 24 03:40:03 volumio sudo[2508]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 24 03:40:03 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Nov 24 03:40:03 volumio sudo[2508]: pam_unix(sudo:session): session closed for user root Nov 24 03:40:03 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Nov 24 03:40:03 volumio volumio[1071]: xcb_connection_has_error() returned true Nov 24 03:40:03 volumio volumio[1071]: info: Output device has changed, restarting MPD Nov 24 03:40:03 volumio sudo[2505]: pam_unix(sudo:session): session closed for user root Nov 24 03:40:03 volumio sudo[2518]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Nov 24 03:40:03 volumio volumio[1071]: info: Output device has changed, restarting Shairport Sync Nov 24 03:40:03 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 24 03:40:03 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 24 03:40:03 volumio sudo[2518]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 24 03:40:03 volumio sudo[2518]: pam_unix(sudo:session): session closed for user root Nov 24 03:40:03 volumio sudo[2522]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Nov 24 03:40:03 volumio sudo[2522]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 24 03:40:03 volumio systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM Nov 24 03:40:03 volumio systemd[1]: mpd.service: Succeeded. Nov 24 03:40:03 volumio systemd[1]: Stopped Music Player Daemon. Nov 24 03:40:03 volumio systemd[1]: Starting Music Player Daemon... Nov 24 03:40:03 volumio volumio[1071]: xcb_connection_has_error() returned true Nov 24 03:40:03 volumio volumio[1071]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Nov 24 03:40:03 volumio volumio[1071]: xcb_connection_has_error() returned true Nov 24 03:40:03 volumio volumio[1071]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Nov 24 03:40:03 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 24 03:40:03 volumio sudo[2532]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Nov 24 03:40:03 volumio sudo[2532]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 24 03:40:03 volumio sudo[2528]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Nov 24 03:40:03 volumio sudo[2528]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 24 03:40:03 volumio sudo[2528]: pam_unix(sudo:session): session closed for user root Nov 24 03:40:03 volumio sudo[2532]: pam_unix(sudo:session): session closed for user root Nov 24 03:40:03 volumio mpd[2537]: Nov 24 03:40 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Nov 24 03:40:03 volumio systemd[1]: Started Music Player Daemon. Nov 24 03:40:03 volumio sudo[2453]: pam_unix(sudo:session): session closed for user root Nov 24 03:40:03 volumio sudo[2522]: pam_unix(sudo:session): session closed for user root Nov 24 03:40:04 volumio volumio[1071]: xcb_connection_has_error() returned true Nov 24 03:40:04 volumio volumio[1071]: Playing WAVE '/volumio/app/silence.wav' : Signed 16 bit Little Endian, Rate 44100 Hz, Stereo Nov 24 03:40:04 volumio volumio[1071]: xcb_connection_has_error() returned true Nov 24 03:40:04 volumio volumio[1071]: info: Output device has changed, restarting MPD Nov 24 03:40:04 volumio sudo[2544]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Nov 24 03:40:04 volumio sudo[2544]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 24 03:40:04 volumio sudo[2547]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Nov 24 03:40:04 volumio sudo[2547]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 24 03:40:04 volumio sudo[2544]: pam_unix(sudo:session): session closed for user root Nov 24 03:40:04 volumio volumio[1071]: info: Output device has changed, restarting Shairport Sync Nov 24 03:40:04 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 24 03:40:04 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 24 03:40:04 volumio sudo[2547]: pam_unix(sudo:session): session closed for user root Nov 24 03:40:04 volumio sudo[2550]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Nov 24 03:40:04 volumio sudo[2550]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 24 03:40:04 volumio systemd[1]: Stopping Music Player Daemon... Nov 24 03:40:04 volumio volumio[1071]: xcb_connection_has_error() returned true Nov 24 03:40:04 volumio volumio[1071]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Nov 24 03:40:04 volumio volumio[1071]: xcb_connection_has_error() returned true Nov 24 03:40:04 volumio volumio[1071]: info: MRS: Audio Device Changed, rebuilding Multiroom Configuration Nov 24 03:40:04 volumio systemd[1]: mpd.service: Succeeded. Nov 24 03:40:04 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 24 03:40:04 volumio systemd[1]: Stopped Music Player Daemon. Nov 24 03:40:04 volumio sudo[2560]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Nov 24 03:40:04 volumio sudo[2560]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 24 03:40:04 volumio systemd[1]: Starting Music Player Daemon... Nov 24 03:40:04 volumio sudo[2560]: pam_unix(sudo:session): session closed for user root Nov 24 03:40:04 volumio volumio[1071]: xcb_connection_has_error() returned true Nov 24 03:40:04 volumio volumio[1071]: info: CoreCommandRouter::volumioUpdateVolumeSettings Nov 24 03:40:04 volumio volumio[1071]: info: Updating Volume Controller Parameters: Device: 2 Name: softvolume Mixer: SoftMaster Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 Nov 24 03:40:04 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Nov 24 03:40:04 volumio volumio[1071]: info: Disabling external Volume Control Nov 24 03:40:04 volumio sudo[2556]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Nov 24 03:40:04 volumio sudo[2556]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 24 03:40:04 volumio sudo[2556]: pam_unix(sudo:session): session closed for user root Nov 24 03:40:04 volumio sudo[2575]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Nov 24 03:40:04 volumio sudo[2575]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 24 03:40:04 volumio sudo[2578]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Nov 24 03:40:04 volumio sudo[2578]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 24 03:40:04 volumio sudo[2575]: pam_unix(sudo:session): session closed for user root Nov 24 03:40:04 volumio sudo[2581]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop vtcs.service Nov 24 03:40:04 volumio sudo[2578]: pam_unix(sudo:session): session closed for user root Nov 24 03:40:04 volumio sudo[2581]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 24 03:40:04 volumio volumio[1071]: ------------------------------------ BT MESSAGE: BT STATUS: running Nov 24 03:40:04 volumio volumio[1071]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Nov 24 03:40:04 volumio volumio[1071]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Nov 24 03:40:04 volumio volumio[1071]: ------------------------------------ BT MESSAGE: BT STATUS: running Nov 24 03:40:04 volumio volumio[1071]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Nov 24 03:40:04 volumio sudo[2581]: pam_unix(sudo:session): session closed for user root Nov 24 03:40:04 volumio volumio[1071]: ------------------------------------ BT MESSAGE: BT STATUS: running Nov 24 03:40:04 volumio volumio[1071]: ------------------------------------ BT MESSAGE: BT STATUS: running Nov 24 03:40:04 volumio volumio[1071]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Nov 24 03:40:04 volumio volumio[1071]: ------------------------------------ BT MESSAGE: BT STATUS: running Nov 24 03:40:04 volumio volumio[1071]: info: CoreStateMachine::pushState Nov 24 03:40:04 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 24 03:40:04 volumio volumio[1071]: info: CoreCommandRouter::volumioPushState Nov 24 03:40:04 volumio volumio[1071]: info: MRS: Pushing multiroomSync output update for this device Nov 24 03:40:04 volumio volumio[1071]: info: MRS: Pushing multiroomSync output Nov 24 03:40:04 volumio volumio[1071]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: xcb_connection_has_error() returned true Nov 24 03:40:04 volumio volumio[1071]: amixer: Unable to find simple control '',0 Nov 24 03:40:04 volumio volumio[1071]: info: MPD Permissions set Nov 24 03:40:04 volumio volumio[1071]: info: MPD Permissions set Nov 24 03:40:04 volumio volumio[1071]: info: Shairport-Sync Started Nov 24 03:40:04 volumio volumio[1071]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Nov 24 03:40:04 volumio volumio[1071]: SPOTIFY: SPOTIFY VOLUME 100 Nov 24 03:40:04 volumio volumio[1071]: SPOTIFY: VOLUMIO VOLUME 100 Nov 24 03:40:04 volumio volumio[1071]: SPOTIFY: DELTA VOLUME ENOUGH: false Nov 24 03:40:04 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 24 03:40:04 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 24 03:40:04 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 24 03:40:04 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 24 03:40:04 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 24 03:40:04 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 24 03:40:04 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 24 03:40:04 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 24 03:40:04 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 24 03:40:04 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 24 03:40:04 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 24 03:40:04 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 24 03:40:04 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 24 03:40:04 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 24 03:40:04 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 24 03:40:04 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 24 03:40:04 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 24 03:40:04 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 24 03:40:04 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 24 03:40:04 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 24 03:40:04 volumio volumio[1071]: info: Starting Shairport Sync Nov 24 03:40:04 volumio volumio[1071]: info: Starting Shairport Sync Nov 24 03:40:04 volumio sudo[2595]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Nov 24 03:40:04 volumio sudo[2595]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 24 03:40:04 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Nov 24 03:40:04 volumio systemd[1]: shairport-sync.service: Succeeded. Nov 24 03:40:04 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Nov 24 03:40:04 volumio volumio[1071]: ------------------------------------ BT MESSAGE: BT STATUS: running Nov 24 03:40:04 volumio volumio[1071]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Nov 24 03:40:04 volumio sudo[2598]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Nov 24 03:40:04 volumio sudo[2598]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 24 03:40:04 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Nov 24 03:40:04 volumio sudo[2595]: pam_unix(sudo:session): session closed for user root Nov 24 03:40:04 volumio volumio[1071]: info: Shairport-Sync Started Nov 24 03:40:04 volumio systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Nov 24 03:40:04 volumio systemd[1]: shairport-sync.service: Main process exited, code=killed, status=15/TERM Nov 24 03:40:04 volumio systemd[1]: shairport-sync.service: Succeeded. Nov 24 03:40:04 volumio systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Nov 24 03:40:04 volumio systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Nov 24 03:40:04 volumio volumio[1071]: ------------------------------------ BT MESSAGE: BT STATUS: running Nov 24 03:40:04 volumio volumio[1071]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Nov 24 03:40:04 volumio sudo[2598]: pam_unix(sudo:session): session closed for user root Nov 24 03:40:04 volumio volumio[1071]: info: Shairport-Sync Started Nov 24 03:40:05 volumio mpd[2574]: Nov 24 03:40 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Nov 24 03:40:05 volumio systemd[1]: Started Music Player Daemon. Nov 24 03:40:05 volumio sudo[2550]: pam_unix(sudo:session): session closed for user root Nov 24 03:40:05 volumio volumio[1071]: error: MPD error: The expression evaluated to a falsy value: Nov 24 03:40:05 volumio volumio[1071]: assert.ok(self.idling) Nov 24 03:40:05 volumio volumio[1071]: error: The expression evaluated to a falsy value: Nov 24 03:40:05 volumio volumio[1071]: assert.ok(self.idling) Nov 24 03:40:05 volumio volumio[1071]: error: updateQueue error: null Nov 24 03:40:05 volumio volumio[1071]: error: updateQueue error: null Nov 24 03:40:05 volumio volumio[1071]: info: TidalConnect service stoped! Nov 24 03:40:05 volumio volumio[1071]: info: TidalConnect service stoped! Nov 24 03:40:05 volumio volumio[1071]: info: TidalConnect service stoped! Nov 24 03:40:05 volumio volumio[1071]: info: TidalConnect service stoped! Nov 24 03:40:05 volumio volumio[1071]: info: Updating tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Nov 24 03:40:05 volumio volumio[1071]: info: Updating tc_connect REST Endpoint for plugin: music_service/tidalconnect Nov 24 03:40:05 volumio volumio[1071]: info: Updating tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Nov 24 03:40:05 volumio volumio[1071]: info: Updating tc_connect REST Endpoint for plugin: music_service/tidalconnect Nov 24 03:40:05 volumio sudo[2623]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Nov 24 03:40:05 volumio sudo[2623]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 24 03:40:05 volumio sudo[2626]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Nov 24 03:40:05 volumio sudo[2626]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 24 03:40:05 volumio systemd[1]: Started Volumio Tidal Connect Service. Nov 24 03:40:05 volumio sudo[2623]: pam_unix(sudo:session): session closed for user root Nov 24 03:40:05 volumio sudo[2626]: pam_unix(sudo:session): session closed for user root Nov 24 03:40:05 volumio volumio[1071]: info: Executing endpoint tc_getconfig Nov 24 03:40:05 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onGetConfig Nov 24 03:40:05 volumio vtcs[2627]: STARTING TidalConnect services, version: 1.4.0.34 Nov 24 03:40:05 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: mpd , restartMpd Nov 24 03:40:05 volumio sudo[2634]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Nov 24 03:40:05 volumio sudo[2634]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 24 03:40:05 volumio vtcs[2627]: STARTED TidalConnect services. Nov 24 03:40:05 volumio volumio[1071]: info: Executing endpoint tc_connect Nov 24 03:40:05 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: tidalconnect , onConnect Nov 24 03:40:05 volumio volumio[1071]: info: Connecting to TidalConnect Nov 24 03:40:05 volumio systemd[1]: Stopping Music Player Daemon... Nov 24 03:40:05 volumio volumio[1071]: ------------------------------------ BT MESSAGE: BT STATUS: running Nov 24 03:40:05 volumio volumio[1071]: info: CoreCommandRouter::servicePushState Nov 24 03:40:05 volumio volumio[1071]: info: CoreStateMachine::pushState Nov 24 03:40:05 volumio volumio[1071]: info: CoreCommandRouter::volumioPushState Nov 24 03:40:05 volumio systemd[1]: mpd.service: Succeeded. Nov 24 03:40:06 volumio systemd[1]: Stopped Music Player Daemon. Nov 24 03:40:06 volumio volumio[1071]: info: MRS: Pushing multiroomSync output update for this device Nov 24 03:40:06 volumio volumio[1071]: info: MRS: Pushing multiroomSync output Nov 24 03:40:06 volumio volumio[1071]: info: CorePlayQueue::getTrack 4 Nov 24 03:40:06 volumio volumio[1071]: info: CONSUME SERVICE: Received update from a service different from the one supposed to be playing music. Skipping notification. Current mpd Received tidalconnect Nov 24 03:40:06 volumio volumio[1071]: info: CoreCommandRouter::servicePushState Nov 24 03:40:06 volumio volumio[1071]: info: CoreStateMachine::pushState Nov 24 03:40:06 volumio volumio[1071]: info: CoreCommandRouter::volumioPushState Nov 24 03:40:06 volumio volumio[1071]: info: MRS: Pushing multiroomSync output update for this device Nov 24 03:40:06 volumio volumio[1071]: info: MRS: Pushing multiroomSync output Nov 24 03:40:06 volumio volumio[1071]: info: CorePlayQueue::getTrack 4 Nov 24 03:40:06 volumio volumio[1071]: info: CONSUME SERVICE: Received update from a service different from the one supposed to be playing music. Skipping notification. Current mpd Received tidalconnect Nov 24 03:40:06 volumio volumio[1071]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Nov 24 03:40:06 volumio volumio[1071]: SPOTIFY: SPOTIFY VOLUME 100 Nov 24 03:40:06 volumio volumio[1071]: SPOTIFY: VOLUMIO VOLUME 100 Nov 24 03:40:06 volumio volumio[1071]: SPOTIFY: DELTA VOLUME ENOUGH: false Nov 24 03:40:06 volumio volumio[1071]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Nov 24 03:40:06 volumio volumio[1071]: SPOTIFY: SPOTIFY VOLUME 100 Nov 24 03:40:06 volumio volumio[1071]: SPOTIFY: VOLUMIO VOLUME 100 Nov 24 03:40:06 volumio volumio[1071]: SPOTIFY: DELTA VOLUME ENOUGH: false Nov 24 03:40:06 volumio volumio[1071]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Nov 24 03:40:06 volumio systemd[1]: Starting Music Player Daemon... Nov 24 03:40:06 volumio volumio[1071]: ------------------------------------ BT MESSAGE: BT STATUS: running Nov 24 03:40:06 volumio sudo[2645]: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chown mpd:audio /var/log/mpd.log Nov 24 03:40:06 volumio sudo[2645]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 24 03:40:06 volumio sudo[2645]: pam_unix(sudo:session): session closed for user root Nov 24 03:40:06 volumio volumio[1071]: info: TidalConnect service stoped! Nov 24 03:40:06 volumio volumio[1071]: info: VolumeController::SetAlsaVolume100 Nov 24 03:40:06 volumio volumio[1071]: info: CoreStateMachine::pushState Nov 24 03:40:06 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 24 03:40:06 volumio volumio[1071]: info: CoreCommandRouter::volumioPushState Nov 24 03:40:06 volumio volumio[1071]: info: MRS: Pushing multiroomSync output update for this device Nov 24 03:40:06 volumio volumio[1071]: info: MRS: Pushing multiroomSync output Nov 24 03:40:06 volumio volumio[1071]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Nov 24 03:40:06 volumio mpd[2653]: Nov 24 03:40 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Nov 24 03:40:06 volumio systemd[1]: Started Music Player Daemon. Nov 24 03:40:06 volumio sudo[2634]: pam_unix(sudo:session): session closed for user root Nov 24 03:40:06 volumio volumio[1071]: error: updateQueue error: null Nov 24 03:40:07 volumio volumio[1071]: info: TidalConnect service stoped! Nov 24 03:40:07 volumio volumio[1071]: info: TidalConnect service stoped! Nov 24 03:40:07 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Nov 24 03:40:07 volumio volumio[1071]: info: TidalConnect service stoped! Nov 24 03:40:07 volumio volumio[1071]: info: TidalConnect service stoped! Nov 24 03:40:07 volumio volumio[1071]: info: TidalConnect service stoped! Nov 24 03:40:07 volumio volumio[1071]: info: Updating tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Nov 24 03:40:07 volumio volumio[1071]: info: Updating tc_connect REST Endpoint for plugin: music_service/tidalconnect Nov 24 03:40:07 volumio volumio[1071]: info: Updating tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Nov 24 03:40:07 volumio volumio[1071]: info: Updating tc_connect REST Endpoint for plugin: music_service/tidalconnect Nov 24 03:40:07 volumio sudo[2696]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Nov 24 03:40:07 volumio sudo[2696]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 24 03:40:07 volumio volumio[1071]: info: Updating tc_getconfig REST Endpoint for plugin: music_service/tidalconnect Nov 24 03:40:07 volumio volumio[1071]: info: Updating tc_connect REST Endpoint for plugin: music_service/tidalconnect Nov 24 03:40:07 volumio sudo[2699]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Nov 24 03:40:07 volumio sudo[2699]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 24 03:40:07 volumio sudo[2696]: pam_unix(sudo:session): session closed for user root Nov 24 03:40:07 volumio sudo[2699]: pam_unix(sudo:session): session closed for user root Nov 24 03:40:07 volumio sudo[2703]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start vtcs.service Nov 24 03:40:07 volumio sudo[2703]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 24 03:40:07 volumio sudo[2703]: pam_unix(sudo:session): session closed for user root Nov 24 03:40:08 volumio volumio[1071]: info: TidalConnect service started! Nov 24 03:40:08 volumio volumio[1071]: info: TidalConnect service started! Nov 24 03:40:10 volumio volumio[1071]: info: CoreCommandRouter::volumioNext Nov 24 03:40:10 volumio volumio[1071]: info: CoreStateMachine::next Nov 24 03:40:10 volumio volumio[1071]: info: ControllerMpd::next Nov 24 03:40:10 volumio volumio[1071]: verbose: ControllerMpd::sendMpdCommand next Nov 24 03:40:10 volumio ntpd[783]: Soliciting pool server 2001:ac8:a:23:0:1:0:14 Nov 24 03:40:10 volumio volumio[1071]: info: CoreCommandRouter::volumioPause Nov 24 03:40:10 volumio volumio[1071]: info: CoreStateMachine::pause Nov 24 03:40:10 volumio volumio[1071]: info: TidalConnect service started! Nov 24 03:40:10 volumio volumio[1071]: info: TidalConnect service started! Nov 24 03:40:10 volumio volumio[1071]: info: TidalConnect service started! Nov 24 03:40:11 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 24 03:40:11 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 24 03:40:11 volumio volumio[1071]: info: Discovery: Getting this device information Nov 24 03:40:11 volumio volumio[1071]: info: CoreCommandRouter::volumioGetState Nov 24 03:40:11 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 24 03:40:11 volumio volumio[1071]: info: CoreCommandRouter::volumioPause Nov 24 03:40:11 volumio volumio[1071]: info: CoreStateMachine::pause Nov 24 03:40:11 volumio volumio[1071]: info: CoreCommandRouter::volumioPause Nov 24 03:40:11 volumio volumio[1071]: info: CoreStateMachine::pause Nov 24 03:40:13 volumio volumio[1071]: info: CoreCommandRouter::volumioPause Nov 24 03:40:13 volumio volumio[1071]: info: CoreStateMachine::pause Nov 24 03:40:13 volumio volumio[1071]: info: CoreCommandRouter::volumioPause Nov 24 03:40:13 volumio volumio[1071]: info: CoreStateMachine::pause Nov 24 03:40:15 volumio volumio[1071]: info: CoreCommandRouter::volumioPause Nov 24 03:40:15 volumio volumio[1071]: info: CoreStateMachine::pause Nov 24 03:40:22 volumio sudo[2729]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Nov 24 03:40:22 volumio sudo[2729]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 24 03:40:22 volumio sudo[2729]: pam_unix(sudo:session): session closed for user root Nov 24 03:40:22 volumio sudo[2732]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Nov 24 03:40:22 volumio sudo[2732]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 24 03:40:22 volumio sudo[2732]: pam_unix(sudo:session): session closed for user root Nov 24 03:40:22 volumio volumio[1071]: verbose: New Socket.io Connection to 192.168.68.58 from 192.168.68.54 UA: Mozilla/5.0 (Linux; Android 13; 23013PC75G Build/TKQ1.220905.001; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/133.0.6848.2 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 8 Nov 24 03:40:22 volumio sudo[2735]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Nov 24 03:40:22 volumio sudo[2735]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 24 03:40:22 volumio sudo[2735]: pam_unix(sudo:session): session closed for user root Nov 24 03:40:22 volumio sudo[2738]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Nov 24 03:40:22 volumio sudo[2738]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 24 03:40:22 volumio sudo[2738]: pam_unix(sudo:session): session closed for user root Nov 24 03:40:22 volumio volumio[1071]: verbose: New Socket.io Connection to 192.168.68.58 from 192.168.68.54 UA: Mozilla/5.0 (Linux; Android 13; 23013PC75G Build/TKQ1.220905.001; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/133.0.6848.2 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 9 Nov 24 03:40:22 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Nov 24 03:40:22 volumio volumio[1071]: info: CoreCommandRouter::volumioGetVisibleSources Nov 24 03:40:22 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 24 03:40:22 volumio volumio[1071]: info: CoreCommandRouter::volumioGetState Nov 24 03:40:22 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Nov 24 03:40:22 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Nov 24 03:40:22 volumio volumio[1071]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom Nov 24 03:40:22 volumio volumio[1071]: info: Received Get System Info Nov 24 03:40:22 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 24 03:40:22 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 24 03:40:22 volumio volumio[1071]: info: Discovery: Getting this device information Nov 24 03:40:22 volumio volumio[1071]: info: CoreCommandRouter::volumioGetState Nov 24 03:40:22 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 24 03:40:22 volumio volumio[1071]: info: CoreCommandRouter::volumioGetState Nov 24 03:40:22 volumio volumio[1071]: info: Listing playlists Nov 24 03:40:22 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Nov 24 03:40:22 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Nov 24 03:40:23 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Nov 24 03:40:24 volumio volumio[1071]: info: CoreCommandRouter::volumioPause Nov 24 03:40:24 volumio volumio[1071]: info: CoreStateMachine::pause Nov 24 03:40:24 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Nov 24 03:40:24 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Nov 24 03:40:24 volumio volumio[1071]: info: Received Get System Info Nov 24 03:40:24 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 24 03:40:24 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 24 03:40:24 volumio volumio[1071]: info: Discovery: Getting this device information Nov 24 03:40:24 volumio volumio[1071]: info: CoreCommandRouter::volumioGetState Nov 24 03:40:24 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 24 03:40:25 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Nov 24 03:40:25 volumio volumio[1071]: info: Received Get System Info Nov 24 03:40:25 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 24 03:40:25 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 24 03:40:25 volumio volumio[1071]: info: Discovery: Getting this device information Nov 24 03:40:25 volumio volumio[1071]: info: CoreCommandRouter::volumioGetState Nov 24 03:40:25 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 24 03:40:26 volumio ntpd[783]: kernel reports TIME_ERROR: 0x41: Clock Unsynchronized Nov 24 03:40:28 volumio volumio[1071]: verbose: New Socket.io Connection to 192.168.68.58 from 192.168.68.54 UA: Mozilla/5.0 (Linux; Android 13; 23013PC75G Build/TKQ1.220905.001; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/133.0.6848.2 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 10 Nov 24 03:40:28 volumio volumio[1071]: info: Received Get System Info Nov 24 03:40:28 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 24 03:40:28 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 24 03:40:28 volumio volumio[1071]: info: Discovery: Getting this device information Nov 24 03:40:28 volumio volumio[1071]: info: CoreCommandRouter::volumioGetState Nov 24 03:40:28 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 24 03:40:28 volumio volumio[1071]: info: CoreCommandRouter::volumioGetState Nov 24 03:40:28 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Nov 24 03:40:28 volumio volumio[1071]: info: CoreCommandRouter::volumioGetVisibleSources Nov 24 03:40:28 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Nov 24 03:40:28 volumio volumio[1071]: info: CoreCommandRouter::volumioGetState Nov 24 03:40:28 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Nov 24 03:40:28 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Nov 24 03:40:28 volumio volumio[1071]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom Nov 24 03:40:28 volumio volumio[1071]: info: Received Get System Info Nov 24 03:40:28 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 24 03:40:28 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 24 03:40:28 volumio volumio[1071]: info: Discovery: Getting this device information Nov 24 03:40:28 volumio volumio[1071]: info: CoreCommandRouter::volumioGetState Nov 24 03:40:28 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 24 03:40:28 volumio volumio[1071]: info: CoreCommandRouter::volumioGetState Nov 24 03:40:28 volumio volumio[1071]: info: Listing playlists Nov 24 03:40:28 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Nov 24 03:40:30 volumio volumio[1071]: info: CoreCommandRouter::volumioGetQueue Nov 24 03:40:30 volumio volumio[1071]: info: CoreStateMachine::getQueue Nov 24 03:40:30 volumio volumio[1071]: info: CorePlayQueue::getQueue Nov 24 03:40:32 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Nov 24 03:40:32 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Nov 24 03:40:32 volumio volumio[1071]: info: CURURI: music-library Nov 24 03:40:32 volumio volumio[1071]: error: Failed LSINFO: null Nov 24 03:40:32 volumio volumio[1071]: info: Preload queue cleared Nov 24 03:40:37 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Nov 24 03:40:40 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Nov 24 03:40:40 volumio volumio[1071]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Nov 24 03:40:40 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Nov 24 03:40:40 volumio volumio[1071]: info: Received Get System Version Nov 24 03:40:40 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Nov 24 03:40:40 volumio volumio[1071]: info: Received Get System Info Nov 24 03:40:40 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 24 03:40:40 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 24 03:40:40 volumio volumio[1071]: info: Discovery: Getting this device information Nov 24 03:40:40 volumio volumio[1071]: info: CoreCommandRouter::volumioGetState Nov 24 03:40:40 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 24 03:40:41 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Nov 24 03:40:41 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Nov 24 03:40:41 volumio volumio[1071]: info: Discovery: Getting this device information Nov 24 03:40:41 volumio volumio[1071]: info: CoreCommandRouter::volumioGetState Nov 24 03:40:41 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Nov 24 03:40:48 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Nov 24 03:40:48 volumio volumio[1071]: info: Preload queue cleared Nov 24 03:40:49 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Nov 24 03:40:49 volumio volumio[1071]: info: Preload queue cleared Nov 24 03:40:55 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Nov 24 03:40:55 volumio volumio[1071]: info: Preload queue cleared Nov 24 03:40:59 volumio volumio[1071]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Nov 24 03:40:59 volumio volumio[1071]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 24 03:40:59 volumio volumio[1071]: TypeError: Cannot read property 'length' of undefined Nov 24 03:40:59 volumio volumio[1071]: at /volumio/app/plugins/music_service/upnp_browser/index.js:341:25 Nov 24 03:40:59 volumio volumio[1071]: at /volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:131:13 Nov 24 03:40:59 volumio volumio[1071]: at Parser. (/volumio/node_modules/xml2js/lib/parser.js:304:18) Nov 24 03:40:59 volumio volumio[1071]: at Parser.emit (events.js:315:20) Nov 24 03:40:59 volumio volumio[1071]: at SAXParser.onclosetag (/volumio/node_modules/xml2js/lib/parser.js:262:26) Nov 24 03:40:59 volumio volumio[1071]: at emit (/volumio/node_modules/sax/lib/sax.js:624:35) Nov 24 03:40:59 volumio volumio[1071]: at emitNode (/volumio/node_modules/sax/lib/sax.js:629:5) Nov 24 03:40:59 volumio volumio[1071]: at closeTag (/volumio/node_modules/sax/lib/sax.js:889:7) Nov 24 03:40:59 volumio volumio[1071]: at SAXParser.write (/volumio/node_modules/sax/lib/sax.js:1436:13) Nov 24 03:40:59 volumio volumio[1071]: at Parser.exports.Parser.Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:323:31) Nov 24 03:40:59 volumio volumio[1071]: at Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:5:59) Nov 24 03:40:59 volumio volumio[1071]: at Object.exports.parseString (/volumio/node_modules/xml2js/lib/parser.js:369:19) Nov 24 03:40:59 volumio volumio[1071]: at IncomingMessage. (/volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:92:15) Nov 24 03:40:59 volumio volumio[1071]: at IncomingMessage.emit (events.js:327:22) Nov 24 03:40:59 volumio volumio[1071]: at endReadableNT (internal/streams/readable.js:1327:12) Nov 24 03:40:59 volumio volumio[1071]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Nov 24 03:40:59 volumio volumio[1071]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 24 03:40:59 volumio sudo[2860]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-11-24 03:39 Nov 24 03:40:59 volumio sudo[2860]: 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="70bcab5180cf11352f5a5197ade215ea8ee93db0" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="678d37490b3eb2102ce7c6d7a6dc3cf042ff2347" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri 08 Nov 2024 06:51:56 PM CET" VOLUMIO_VERSION="3.779" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="b9009e0280f50389e80a537357ff3961"