-- Logs begin at Thu 2019-02-14 11:12:00 CET, end at Sun 2024-12-01 18:11:51 CET. -- Dec 01 18:10:01 volumio volumio[901]: info: Starting Streaming Service Transparent Proxy Dec 01 18:10:01 volumio volumio[901]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Dec 01 18:10:01 volumio volumio[901]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Dec 01 18:10:01 volumio volumio[901]: info: Streaming services startup Dec 01 18:10:01 volumio volumio[901]: info: Starting Streaming Daemon Dec 01 18:10:01 volumio sudo[1284]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Dec 01 18:10:01 volumio sudo[1284]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 01 18:10:01 volumio volumio[901]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Dec 01 18:10:01 volumio sudo[1284]: pam_unix(sudo:session): session closed for user root Dec 01 18:10:01 volumio volumio[901]: SPOTIFY: SETTING SPOTIFY VOLUME 100 Dec 01 18:10:01 volumio volumio[901]: info: Sending Spotify command with payload to local API: /player/volume Dec 01 18:10:01 volumio volumio[901]: error: Cannot start Volumio Streaming Daemon Dec 01 18:10:01 volumio volumio[901]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Dec 01 18:10:01 volumio volumio[901]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Dec 01 18:10:01 volumio volumio[901]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Dec 01 18:10:01 volumio volumio[901]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Dec 01 18:10:01 volumio volumio[1074]: ..............................++++ Dec 01 18:10:01 volumio volumio[1074]: e is 65537 (0x010001) Dec 01 18:10:01 volumio volumio[1074]: writing RSA key Dec 01 18:10:02 volumio volumio[901]: info: Preload queue cleared Dec 01 18:10:02 volumio volumio[901]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Dec 01 18:10:03 volumio volumio[901]: info: MyVolumio token set successfully Dec 01 18:10:03 volumio volumio[901]: info: MYVOLUMIO: Adding device Dec 01 18:10:03 volumio volumio[901]: info: MYVOLUMIO: Evaluating Server Dec 01 18:10:03 volumio volumio[901]: STREAMING PROXY: Starting server on port 3245 Dec 01 18:10:03 volumio volumio[901]: Node JS runtime: 14 Dec 01 18:10:03 volumio volumio[901]: info: MyVolumio status changed Dec 01 18:10:03 volumio volumio[901]: info: Streaming services startup Dec 01 18:10:03 volumio volumio[901]: info: Starting Streaming Daemon Dec 01 18:10:03 volumio volumio[901]: info: Removing browser output: myVolumio user plan is not superstar Dec 01 18:10:03 volumio volumio[901]: info: Removing audio output: Dec 01 18:10:03 volumio volumio[901]: info: Stoppping Tunnel 1 Dec 01 18:10:03 volumio sudo[1333]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Dec 01 18:10:03 volumio sudo[1333]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 01 18:10:03 volumio sudo[1335]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Dec 01 18:10:03 volumio sudo[1335]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 01 18:10:03 volumio sudo[1333]: pam_unix(sudo:session): session closed for user root Dec 01 18:10:04 volumio volumio[901]: error: Cannot start Volumio Streaming Daemon Dec 01 18:10:04 volumio volumio[901]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Dec 01 18:10:04 volumio volumio[901]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Dec 01 18:10:04 volumio sudo[1335]: pam_unix(sudo:session): session closed for user root Dec 01 18:10:04 volumio volumio[901]: info: Remote SSH Stopped Dec 01 18:10:04 volumio volumio[901]: info: Setting Geolocation for MyVolumio to eu4 Dec 01 18:10:04 volumio volumio[901]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 01 18:10:04 volumio volumio[901]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 01 18:10:04 volumio volumio[901]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 01 18:10:05 volumio volumio[901]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Dec 01 18:10:05 volumio volumio[901]: info: Updating MyVolumio device info Dec 01 18:10:05 volumio volumio[901]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 01 18:10:05 volumio volumio[901]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 01 18:10:05 volumio volumio[901]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 01 18:10:05 volumio volumio[901]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Dec 01 18:10:05 volumio volumio[901]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Dec 01 18:10:05 volumio volumio[901]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Dec 01 18:10:05 volumio volumio[901]: info: Received Get System Version Dec 01 18:10:05 volumio volumio[901]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 01 18:10:05 volumio volumio[901]: info: Received Get System Info Dec 01 18:10:05 volumio volumio[901]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 01 18:10:05 volumio volumio[901]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 01 18:10:05 volumio volumio[901]: info: Discovery: Getting this device information Dec 01 18:10:05 volumio volumio[901]: info: CoreCommandRouter::volumioGetState Dec 01 18:10:05 volumio volumio[901]: info: CorePlayQueue::getTrack 0 Dec 01 18:10:05 volumio volumio[901]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 01 18:10:05 volumio volumio[901]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Dec 01 18:10:06 volumio ntpd[676]: Soliciting pool server 217.61.62.224 Dec 01 18:10:06 volumio volumio[901]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Dec 01 18:10:07 volumio ntpd[676]: Soliciting pool server 151.22.209.90 Dec 01 18:10:07 volumio ntpd[676]: Soliciting pool server 212.45.144.88 Dec 01 18:10:08 volumio ntpd[676]: Soliciting pool server 212.45.144.206 Dec 01 18:10:08 volumio ntpd[676]: Soliciting pool server 188.213.165.209 Dec 01 18:10:08 volumio ntpd[676]: Soliciting pool server 162.159.200.1 Dec 01 18:10:09 volumio volumio[901]: info: MYVOLUMIO: Adding device Dec 01 18:10:09 volumio volumio[901]: info: MYVOLUMIO: Evaluating Server Dec 01 18:10:09 volumio volumio[901]: info: Preload queue cleared Dec 01 18:10:09 volumio ntpd[676]: Soliciting pool server 185.19.184.35 Dec 01 18:10:09 volumio ntpd[676]: Soliciting pool server 212.6.50.243 Dec 01 18:10:09 volumio ntpd[676]: Soliciting pool server 93.94.88.51 Dec 01 18:10:10 volumio volumio[901]: info: Setting Geolocation for MyVolumio to eu7 Dec 01 18:10:10 volumio volumio[901]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 01 18:10:10 volumio volumio[901]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 01 18:10:10 volumio volumio[901]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 01 18:10:10 volumio ntpd[676]: Soliciting pool server 93.94.88.50 Dec 01 18:10:10 volumio ntpd[676]: Soliciting pool server 37.247.53.178 Dec 01 18:10:10 volumio volumio[901]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Dec 01 18:10:11 volumio volumio[901]: info: Updating MyVolumio device info Dec 01 18:10:11 volumio volumio[901]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 01 18:10:11 volumio volumio[901]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 01 18:10:11 volumio volumio[901]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 01 18:10:11 volumio ntpd[676]: Soliciting pool server 85.199.214.99 Dec 01 18:10:11 volumio ntpd[676]: Soliciting pool server 185.157.229.254 Dec 01 18:10:11 volumio volumio[901]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Dec 01 18:10:12 volumio ntpd[676]: Soliciting pool server 162.159.200.123 Dec 01 18:10:12 volumio ntpd[676]: Soliciting pool server 2a03:b020:0:403::254 Dec 01 18:10:12 volumio wpa_supplicant[798]: wlan0: WPA: Group rekeying completed with 7c:ff:4d:ea:e6:08 [GTK=CCMP] Dec 01 18:10:13 volumio volumio[901]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Dec 01 18:10:13 volumio volumio[901]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Dec 01 18:10:13 volumio ntpd[676]: Soliciting pool server 89.46.74.148 Dec 01 18:10:13 volumio volumio[901]: info: CoreCommandRouter::volumioGetState Dec 01 18:10:13 volumio volumio[901]: info: CorePlayQueue::getTrack 0 Dec 01 18:10:13 volumio volumio[901]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 01 18:10:13 volumio volumio[901]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 01 18:10:13 volumio volumio[901]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Dec 01 18:10:13 volumio volumio-remote-updater[528]: No test mode Dec 01 18:10:13 volumio volumio-remote-updater[528]: No alpha test mode Dec 01 18:10:13 volumio volumio[901]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Dec 01 18:10:14 volumio volumio[901]: info: Update Ready: {"changeLogLink":"","description":"You're already on the latest version","title":"No Updates Available","updateavailable":false} Dec 01 18:10:14 volumio volumio[901]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Dec 01 18:10:14 volumio volumio[901]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Dec 01 18:10:14 volumio ntpd[676]: Soliciting pool server 95.110.254.234 Dec 01 18:10:14 volumio volumio[901]: info: Preload queue cleared Dec 01 18:10:14 volumio volumio[901]: info: Preloading song: upnp/http://192.168.178.105:32469/ContentDirectory/7b58d976-c6f9-40f7-d1b0-54c9905d45f9/control.xml@c28c1fb2cdf27935656b Dec 01 18:10:14 volumio volumio[901]: info: Preloading song: upnp/http://192.168.178.105:32469/ContentDirectory/7b58d976-c6f9-40f7-d1b0-54c9905d45f9/control.xml@4ee73fbfb08dac495040 Dec 01 18:10:14 volumio volumio[901]: info: Preloading song: upnp/http://192.168.178.105:32469/ContentDirectory/7b58d976-c6f9-40f7-d1b0-54c9905d45f9/control.xml@6620825594e75a5874ec Dec 01 18:10:14 volumio volumio[901]: info: Preloading song: upnp/http://192.168.178.105:32469/ContentDirectory/7b58d976-c6f9-40f7-d1b0-54c9905d45f9/control.xml@ceae6c894ce4a0b3d924 Dec 01 18:10:14 volumio volumio[901]: info: Preloading song: upnp/http://192.168.178.105:32469/ContentDirectory/7b58d976-c6f9-40f7-d1b0-54c9905d45f9/control.xml@a3ef18468ac2a2c65bfb Dec 01 18:10:14 volumio volumio[901]: info: Preloading song: upnp/http://192.168.178.105:32469/ContentDirectory/7b58d976-c6f9-40f7-d1b0-54c9905d45f9/control.xml@673c67aece3ec11bff25 Dec 01 18:10:14 volumio volumio[901]: info: Preloading song: upnp/http://192.168.178.105:32469/ContentDirectory/7b58d976-c6f9-40f7-d1b0-54c9905d45f9/control.xml@77812f7867d22f7cde3b Dec 01 18:10:14 volumio volumio[901]: info: Preloading song: upnp/http://192.168.178.105:32469/ContentDirectory/7b58d976-c6f9-40f7-d1b0-54c9905d45f9/control.xml@ef5b3df89e6985cc40be Dec 01 18:10:14 volumio volumio[901]: info: Preloading song: upnp/http://192.168.178.105:32469/ContentDirectory/7b58d976-c6f9-40f7-d1b0-54c9905d45f9/control.xml@2badf568f9a2a87595b5 Dec 01 18:10:14 volumio volumio[901]: info: Preloading song: upnp/http://192.168.178.105:32469/ContentDirectory/7b58d976-c6f9-40f7-d1b0-54c9905d45f9/control.xml@4817e24e980816b55333 Dec 01 18:10:14 volumio volumio[901]: info: Preloading song: upnp/http://192.168.178.105:32469/ContentDirectory/7b58d976-c6f9-40f7-d1b0-54c9905d45f9/control.xml@e009e9d24a6acccfb858 Dec 01 18:10:14 volumio volumio[901]: info: Preloading song: upnp/http://192.168.178.105:32469/ContentDirectory/7b58d976-c6f9-40f7-d1b0-54c9905d45f9/control.xml@10d3ac5f133a68a4757d Dec 01 18:10:14 volumio volumio[901]: info: Preloading song: upnp/http://192.168.178.105:32469/ContentDirectory/7b58d976-c6f9-40f7-d1b0-54c9905d45f9/control.xml@fd112c887b172ab773c6 Dec 01 18:10:14 volumio volumio[901]: info: Preloading song: upnp/http://192.168.178.105:32469/ContentDirectory/7b58d976-c6f9-40f7-d1b0-54c9905d45f9/control.xml@0ee27187d5b23cbbc651 Dec 01 18:10:14 volumio volumio[901]: info: Preloading song: upnp/http://192.168.178.105:32469/ContentDirectory/7b58d976-c6f9-40f7-d1b0-54c9905d45f9/control.xml@70178e7c5a64e7bd52a4 Dec 01 18:10:14 volumio volumio[901]: info: Preloading song: upnp/http://192.168.178.105:32469/ContentDirectory/7b58d976-c6f9-40f7-d1b0-54c9905d45f9/control.xml@4fe4f201a965230b42ac Dec 01 18:10:14 volumio volumio[901]: info: Preloading song: upnp/http://192.168.178.105:32469/ContentDirectory/7b58d976-c6f9-40f7-d1b0-54c9905d45f9/control.xml@56803142e16ea78341be Dec 01 18:10:14 volumio volumio[901]: info: Preloading song: upnp/http://192.168.178.105:32469/ContentDirectory/7b58d976-c6f9-40f7-d1b0-54c9905d45f9/control.xml@e5e371e2859a99fd56af Dec 01 18:10:14 volumio volumio[901]: info: Preloading song: upnp/http://192.168.178.105:32469/ContentDirectory/7b58d976-c6f9-40f7-d1b0-54c9905d45f9/control.xml@1fe278e3525618620212 Dec 01 18:10:14 volumio volumio[901]: info: Preloading song: upnp/http://192.168.178.105:32469/ContentDirectory/7b58d976-c6f9-40f7-d1b0-54c9905d45f9/control.xml@b977ad47447e54638d05 Dec 01 18:10:14 volumio volumio[901]: info: Exploding uri upnp/http://192.168.178.105:32469/ContentDirectory/7b58d976-c6f9-40f7-d1b0-54c9905d45f9/control.xml@c28c1fb2cdf27935656b in service upnp_browser Dec 01 18:10:14 volumio volumio[901]: info: No valid Plugin REST Endpoint Dec 01 18:10:14 volumio volumio[901]: info: Exploding uri upnp/http://192.168.178.105:32469/ContentDirectory/7b58d976-c6f9-40f7-d1b0-54c9905d45f9/control.xml@4ee73fbfb08dac495040 in service upnp_browser Dec 01 18:10:14 volumio volumio[901]: info: Exploding uri upnp/http://192.168.178.105:32469/ContentDirectory/7b58d976-c6f9-40f7-d1b0-54c9905d45f9/control.xml@6620825594e75a5874ec in service upnp_browser Dec 01 18:10:14 volumio volumio[901]: info: Exploding uri upnp/http://192.168.178.105:32469/ContentDirectory/7b58d976-c6f9-40f7-d1b0-54c9905d45f9/control.xml@ceae6c894ce4a0b3d924 in service upnp_browser Dec 01 18:10:14 volumio volumio[901]: info: Exploding uri upnp/http://192.168.178.105:32469/ContentDirectory/7b58d976-c6f9-40f7-d1b0-54c9905d45f9/control.xml@a3ef18468ac2a2c65bfb in service upnp_browser Dec 01 18:10:14 volumio volumio[901]: info: Exploding uri upnp/http://192.168.178.105:32469/ContentDirectory/7b58d976-c6f9-40f7-d1b0-54c9905d45f9/control.xml@673c67aece3ec11bff25 in service upnp_browser Dec 01 18:10:14 volumio volumio[901]: info: Exploding uri upnp/http://192.168.178.105:32469/ContentDirectory/7b58d976-c6f9-40f7-d1b0-54c9905d45f9/control.xml@77812f7867d22f7cde3b in service upnp_browser Dec 01 18:10:14 volumio volumio[901]: info: Exploding uri upnp/http://192.168.178.105:32469/ContentDirectory/7b58d976-c6f9-40f7-d1b0-54c9905d45f9/control.xml@ef5b3df89e6985cc40be in service upnp_browser Dec 01 18:10:14 volumio volumio[901]: info: Exploding uri upnp/http://192.168.178.105:32469/ContentDirectory/7b58d976-c6f9-40f7-d1b0-54c9905d45f9/control.xml@2badf568f9a2a87595b5 in service upnp_browser Dec 01 18:10:15 volumio volumio[901]: info: Exploding uri upnp/http://192.168.178.105:32469/ContentDirectory/7b58d976-c6f9-40f7-d1b0-54c9905d45f9/control.xml@4817e24e980816b55333 in service upnp_browser Dec 01 18:10:15 volumio volumio[901]: info: Exploding uri upnp/http://192.168.178.105:32469/ContentDirectory/7b58d976-c6f9-40f7-d1b0-54c9905d45f9/control.xml@e009e9d24a6acccfb858 in service upnp_browser Dec 01 18:10:15 volumio volumio[901]: info: Exploding uri upnp/http://192.168.178.105:32469/ContentDirectory/7b58d976-c6f9-40f7-d1b0-54c9905d45f9/control.xml@10d3ac5f133a68a4757d in service upnp_browser Dec 01 18:10:15 volumio volumio[901]: info: Exploding uri upnp/http://192.168.178.105:32469/ContentDirectory/7b58d976-c6f9-40f7-d1b0-54c9905d45f9/control.xml@fd112c887b172ab773c6 in service upnp_browser Dec 01 18:10:15 volumio volumio[901]: info: Exploding uri upnp/http://192.168.178.105:32469/ContentDirectory/7b58d976-c6f9-40f7-d1b0-54c9905d45f9/control.xml@0ee27187d5b23cbbc651 in service upnp_browser Dec 01 18:10:15 volumio volumio[901]: info: Exploding uri upnp/http://192.168.178.105:32469/ContentDirectory/7b58d976-c6f9-40f7-d1b0-54c9905d45f9/control.xml@70178e7c5a64e7bd52a4 in service upnp_browser Dec 01 18:10:15 volumio volumio[901]: info: Exploding uri upnp/http://192.168.178.105:32469/ContentDirectory/7b58d976-c6f9-40f7-d1b0-54c9905d45f9/control.xml@4fe4f201a965230b42ac in service upnp_browser Dec 01 18:10:15 volumio volumio[901]: info: Exploding uri upnp/http://192.168.178.105:32469/ContentDirectory/7b58d976-c6f9-40f7-d1b0-54c9905d45f9/control.xml@56803142e16ea78341be in service upnp_browser Dec 01 18:10:15 volumio volumio[901]: info: Exploding uri upnp/http://192.168.178.105:32469/ContentDirectory/7b58d976-c6f9-40f7-d1b0-54c9905d45f9/control.xml@e5e371e2859a99fd56af in service upnp_browser Dec 01 18:10:16 volumio ntpd[676]: receive: Unexpected origin timestamp 0xeaf716f7.72e571a3 does not match aorg 0000000000.00000000 from server@162.159.200.1 xmt 0xeaf716f8.76ff3f7c Dec 01 18:10:16 volumio ntpd[676]: receive: Unexpected origin timestamp 0xeaf716f7.72d77511 does not match aorg 0000000000.00000000 from server@37.247.53.178 xmt 0xeaf716f8.7700479c Dec 01 18:10:16 volumio ntpd[676]: receive: Unexpected origin timestamp 0xeaf716f7.72ea8b8f does not match aorg 0000000000.00000000 from server@188.213.165.209 xmt 0xeaf716f8.776e04b3 Dec 01 18:10:16 volumio ntpd[676]: receive: Unexpected origin timestamp 0xeaf716f7.72f4f43b does not match aorg 0000000000.00000000 from server@217.61.62.224 xmt 0xeaf716f8.794a5f80 Dec 01 18:10:16 volumio ntpd[676]: receive: Unexpected origin timestamp 0xeaf716f7.72c33d63 does not match aorg 0000000000.00000000 from server@93.94.88.50 xmt 0xeaf716f8.785f5e65 Dec 01 18:10:16 volumio ntpd[676]: receive: Unexpected origin timestamp 0xeaf716f7.72dff906 does not match aorg 0000000000.00000000 from server@93.94.88.51 xmt 0xeaf716f8.78d592a3 Dec 01 18:10:16 volumio volumio[901]: info: Exploding uri upnp/http://192.168.178.105:32469/ContentDirectory/7b58d976-c6f9-40f7-d1b0-54c9905d45f9/control.xml@1fe278e3525618620212 in service upnp_browser Dec 01 18:10:16 volumio volumio[901]: info: Exploding uri upnp/http://192.168.178.105:32469/ContentDirectory/7b58d976-c6f9-40f7-d1b0-54c9905d45f9/control.xml@b977ad47447e54638d05 in service upnp_browser Dec 01 18:10:19 volumio volumio[901]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 01 18:10:19 volumio volumio[901]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 01 18:10:19 volumio volumio[901]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Dec 01 18:10:19 volumio volumio[901]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Dec 01 18:10:19 volumio volumio[901]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Dec 01 18:10:19 volumio volumio[901]: info: CoreCommandRouter::volumioGetBrowseSources Dec 01 18:10:19 volumio volumio[901]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 01 18:10:20 volumio volumio[901]: info: Preload queue cleared Dec 01 18:10:20 volumio volumio[901]: info: CoreCommandRouter::volumioReplaceandPlayItems Dec 01 18:10:20 volumio volumio[901]: info: CoreStateMachine::ClearQueue Dec 01 18:10:20 volumio volumio[901]: info: CoreStateMachine::stop Dec 01 18:10:20 volumio volumio[901]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 01 18:10:20 volumio volumio[901]: info: CorePlayQueue::clearPlayQueue Dec 01 18:10:20 volumio volumio[901]: info: CorePlayQueue::saveQueue Dec 01 18:10:20 volumio volumio[901]: info: CoreCommandRouter::volumioPushQueue Dec 01 18:10:20 volumio volumio[901]: info: CoreStateMachine::addQueueItems Dec 01 18:10:20 volumio volumio[901]: info: CorePlayQueue::addQueueItems Dec 01 18:10:20 volumio volumio[901]: info: Preload queue cleared Dec 01 18:10:20 volumio volumio[901]: info: Adding Item to queue: upnp/folder/http://192.168.178.105:32469/ContentDirectory/7b58d976-c6f9-40f7-d1b0-54c9905d45f9/control.xml@a12aa1e226f095ae61c5 Dec 01 18:10:20 volumio volumio[901]: info: Exploding uri upnp/folder/http://192.168.178.105:32469/ContentDirectory/7b58d976-c6f9-40f7-d1b0-54c9905d45f9/control.xml@a12aa1e226f095ae61c5 in service upnp_browser Dec 01 18:10:20 volumio volumio[901]: info: CoreCommandRouter::volumioPushQueue Dec 01 18:10:20 volumio volumio[901]: info: CorePlayQueue::saveQueue Dec 01 18:10:20 volumio volumio[901]: info: CoreStateMachine::updateTrackBlock Dec 01 18:10:20 volumio volumio[901]: info: CorePlayQueue::getTrackBlock Dec 01 18:10:20 volumio volumio[901]: info: CoreCommandRouter::volumioPlay Dec 01 18:10:20 volumio volumio[901]: info: CoreStateMachine::play index 0 Dec 01 18:10:20 volumio volumio[901]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 01 18:10:20 volumio volumio[901]: info: CoreStateMachine::stop Dec 01 18:10:20 volumio volumio[901]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 01 18:10:20 volumio volumio[901]: info: CoreStateMachine::play index undefined Dec 01 18:10:20 volumio volumio[901]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 01 18:10:20 volumio volumio[901]: info: CorePlayQueue::getTrack 0 Dec 01 18:10:20 volumio volumio[901]: info: CoreStateMachine::startPlaybackTimer Dec 01 18:10:20 volumio volumio[901]: info: CorePlayQueue::getTrack 0 Dec 01 18:10:20 volumio volumio[901]: info: [1733073020463] ControllerUPNPBrowser::clearAddPlayTrack Dec 01 18:10:20 volumio volumio[901]: verbose: ControllerMpd::sendMpdCommand stop Dec 01 18:10:20 volumio volumio[901]: info: sendMpdCommand stop took 22 milliseconds Dec 01 18:10:20 volumio volumio[901]: verbose: ControllerMpd::sendMpdCommand clear Dec 01 18:10:20 volumio volumio[901]: info: Dec 01 18:10:20 volumio volumio[901]: ---------------------------- MPD announces system playlist update Dec 01 18:10:20 volumio volumio[901]: info: Ignoring MPD Status Update Dec 01 18:10:20 volumio volumio[901]: info: sendMpdCommand clear took 8 milliseconds Dec 01 18:10:20 volumio volumio[901]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.178.105:32469/object/c28c1fb2cdf27935656b/file.mp3" Dec 01 18:10:20 volumio volumio[901]: info: Dec 01 18:10:20 volumio volumio[901]: ---------------------------- MPD announces system playlist update Dec 01 18:10:20 volumio volumio[901]: info: Ignoring MPD Status Update Dec 01 18:10:20 volumio volumio[901]: info: Dec 01 18:10:20 volumio volumio[901]: ---------------------------- MPD announces system playlist update Dec 01 18:10:20 volumio volumio[901]: info: Ignoring MPD Status Update Dec 01 18:10:20 volumio volumio[901]: error: updateQueue error: null Dec 01 18:10:20 volumio volumio[901]: info: ------------------------------ 17ms Dec 01 18:10:20 volumio volumio[901]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.178.105:32469/object/c28c1fb2cdf27935656b/file.mp3" Dec 01 18:10:20 volumio volumio[901]: error: updateQueue error: null Dec 01 18:10:20 volumio volumio[901]: error: updateQueue error: null Dec 01 18:10:20 volumio volumio[901]: info: Dec 01 18:10:20 volumio volumio[901]: ---------------------------- MPD announces system playlist update Dec 01 18:10:20 volumio volumio[901]: info: Ignoring MPD Status Update Dec 01 18:10:20 volumio volumio[901]: info: ------------------------------ 76ms Dec 01 18:10:20 volumio volumio[901]: info: ------------------------------ 74ms Dec 01 18:10:20 volumio volumio[901]: info: sendMpdCommand add "http://192.168.178.105:32469/object/c28c1fb2cdf27935656b/file.mp3" took 14 milliseconds Dec 01 18:10:20 volumio volumio[901]: info: CoreStateMachine::setConsumeUpdateService mpd Dec 01 18:10:20 volumio volumio[901]: verbose: ControllerMpd::sendMpdCommand play Dec 01 18:10:20 volumio volumio[901]: info: Dec 01 18:10:20 volumio volumio[901]: ---------------------------- MPD announces system playlist update Dec 01 18:10:20 volumio volumio[901]: info: Ignoring MPD Status Update Dec 01 18:10:20 volumio volumio[901]: info: Dec 01 18:10:20 volumio volumio[901]: ---------------------------- MPD announces system playlist update Dec 01 18:10:20 volumio volumio[901]: info: Ignoring MPD Status Update Dec 01 18:10:20 volumio volumio[901]: info: ------------------------------ 20ms Dec 01 18:10:20 volumio volumio[901]: info: sendMpdCommand play took 15 milliseconds Dec 01 18:10:20 volumio volumio[901]: info: ------------------------------ 14ms Dec 01 18:10:20 volumio volumio[901]: info: ------------------------------ 12ms Dec 01 18:10:20 volumio volumio[901]: info: Dec 01 18:10:20 volumio volumio[901]: ---------------------------- MPD announces state update: player Dec 01 18:10:20 volumio volumio[901]: info: ControllerMpd::getState Dec 01 18:10:20 volumio volumio[901]: verbose: ControllerMpd::sendMpdCommand status Dec 01 18:10:20 volumio volumio[901]: info: Dec 01 18:10:20 volumio volumio[901]: ---------------------------- MPD announces state update: player Dec 01 18:10:20 volumio volumio[901]: info: ControllerMpd::getState Dec 01 18:10:20 volumio volumio[901]: verbose: ControllerMpd::sendMpdCommand status Dec 01 18:10:20 volumio volumio[901]: info: Dec 01 18:10:20 volumio volumio[901]: ---------------------------- MPD announces state update: player Dec 01 18:10:20 volumio volumio[901]: info: ControllerMpd::getState Dec 01 18:10:20 volumio volumio[901]: verbose: ControllerMpd::sendMpdCommand status Dec 01 18:10:20 volumio volumio[901]: info: Dec 01 18:10:20 volumio volumio[901]: ---------------------------- MPD announces state update: player Dec 01 18:10:20 volumio volumio[901]: info: sendMpdCommand status took 37 milliseconds Dec 01 18:10:20 volumio volumio[901]: info: ControllerMpd::getState Dec 01 18:10:20 volumio volumio[901]: verbose: ControllerMpd::sendMpdCommand status Dec 01 18:10:20 volumio volumio[901]: verbose: ControllerMpd::parseState Dec 01 18:10:20 volumio volumio[901]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 01 18:10:20 volumio volumio[901]: info: sendMpdCommand status took 43 milliseconds Dec 01 18:10:20 volumio volumio[901]: info: sendMpdCommand status took 40 milliseconds Dec 01 18:10:20 volumio volumio[901]: info: sendMpdCommand status took 11 milliseconds Dec 01 18:10:20 volumio volumio[901]: info: sendMpdCommand playlistinfo took 6 milliseconds Dec 01 18:10:20 volumio volumio[901]: verbose: ControllerMpd::parseState Dec 01 18:10:20 volumio volumio[901]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 01 18:10:20 volumio volumio[901]: verbose: ControllerMpd::parseState Dec 01 18:10:20 volumio volumio[901]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 01 18:10:20 volumio volumio[901]: verbose: ControllerMpd::parseState Dec 01 18:10:20 volumio volumio[901]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 01 18:10:20 volumio volumio[901]: verbose: ControllerMpd::parseTrackInfo Dec 01 18:10:20 volumio volumio[901]: info: ControllerMpd::pushState Dec 01 18:10:20 volumio volumio[901]: info: CoreCommandRouter::servicePushState Dec 01 18:10:20 volumio volumio[901]: info: CorePlayQueue::getTrack 0 Dec 01 18:10:20 volumio volumio[901]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":58,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"file.mp3","artist":null,"album":null,"uri":"http://192.168.178.105:32469/object/c28c1fb2cdf27935656b/file.mp3","trackType":"mp3"} Dec 01 18:10:20 volumio volumio[901]: verbose: CURRENT POSITION 0 Dec 01 18:10:20 volumio volumio[901]: info: CoreStateMachine::syncState stateService play Dec 01 18:10:20 volumio volumio[901]: info: CoreStateMachine::syncState currentStatus stop Dec 01 18:10:20 volumio volumio[901]: info: ------------------------------ 79ms Dec 01 18:10:20 volumio volumio[901]: info: Dec 01 18:10:20 volumio volumio[901]: ---------------------------- MPD announces state update: player Dec 01 18:10:20 volumio volumio[901]: info: ControllerMpd::getState Dec 01 18:10:20 volumio volumio[901]: verbose: ControllerMpd::sendMpdCommand status Dec 01 18:10:20 volumio volumio[901]: info: Dec 01 18:10:20 volumio volumio[901]: ---------------------------- MPD announces state update: player Dec 01 18:10:20 volumio volumio[901]: info: ControllerMpd::getState Dec 01 18:10:20 volumio volumio[901]: verbose: ControllerMpd::sendMpdCommand status Dec 01 18:10:20 volumio volumio[901]: info: sendMpdCommand playlistinfo took 34 milliseconds Dec 01 18:10:20 volumio volumio[901]: info: sendMpdCommand playlistinfo took 33 milliseconds Dec 01 18:10:20 volumio volumio[901]: info: sendMpdCommand playlistinfo took 32 milliseconds Dec 01 18:10:20 volumio volumio[901]: info: sendMpdCommand status took 11 milliseconds Dec 01 18:10:20 volumio volumio[901]: verbose: ControllerMpd::parseTrackInfo Dec 01 18:10:20 volumio volumio[901]: verbose: ControllerMpd::parseTrackInfo Dec 01 18:10:20 volumio volumio[901]: verbose: ControllerMpd::parseTrackInfo Dec 01 18:10:20 volumio volumio[901]: verbose: ControllerMpd::parseState Dec 01 18:10:20 volumio volumio[901]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 01 18:10:20 volumio volumio[901]: info: ControllerMpd::pushState Dec 01 18:10:20 volumio volumio[901]: info: CoreCommandRouter::servicePushState Dec 01 18:10:20 volumio volumio[901]: info: CorePlayQueue::getTrack 0 Dec 01 18:10:20 volumio volumio[901]: verbose: STATE SERVICE {"status":"play","position":0,"seek":377,"duration":58,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"file.mp3","artist":null,"album":null,"uri":"http://192.168.178.105:32469/object/c28c1fb2cdf27935656b/file.mp3","trackType":"mp3"} Dec 01 18:10:20 volumio volumio[901]: verbose: CURRENT POSITION 0 Dec 01 18:10:20 volumio volumio[901]: info: CoreStateMachine::syncState stateService play Dec 01 18:10:20 volumio volumio[901]: info: CoreStateMachine::syncState currentStatus play Dec 01 18:10:20 volumio volumio[901]: info: Received an update from plugin. extracting info from payload Dec 01 18:10:20 volumio volumio[901]: info: CoreStateMachine::pushState Dec 01 18:10:20 volumio volumio[901]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 01 18:10:20 volumio volumio[901]: info: CoreCommandRouter::volumioPushState Dec 01 18:10:20 volumio volumio[901]: info: CoreStateMachine::pushState Dec 01 18:10:20 volumio volumio[901]: info: CoreCommandRouter::volumioPushState Dec 01 18:10:20 volumio volumio[901]: info: ControllerMpd::pushState Dec 01 18:10:20 volumio volumio[901]: info: CoreCommandRouter::servicePushState Dec 01 18:10:20 volumio volumio[901]: info: CorePlayQueue::getTrack 0 Dec 01 18:10:20 volumio volumio[901]: verbose: STATE SERVICE {"status":"play","position":0,"seek":880,"duration":58,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"file.mp3","artist":null,"album":null,"uri":"http://192.168.178.105:32469/object/c28c1fb2cdf27935656b/file.mp3","trackType":"mp3"} Dec 01 18:10:20 volumio volumio[901]: verbose: CURRENT POSITION 0 Dec 01 18:10:20 volumio volumio[901]: info: CoreStateMachine::syncState stateService play Dec 01 18:10:20 volumio volumio[901]: info: CoreStateMachine::syncState currentStatus play Dec 01 18:10:20 volumio volumio[901]: info: Received an update from plugin. extracting info from payload Dec 01 18:10:20 volumio volumio[901]: info: CoreStateMachine::pushState Dec 01 18:10:20 volumio volumio[901]: info: CoreCommandRouter::volumioPushState Dec 01 18:10:20 volumio volumio[901]: info: CoreStateMachine::pushState Dec 01 18:10:20 volumio volumio[901]: info: CoreCommandRouter::volumioPushState Dec 01 18:10:20 volumio volumio[901]: info: ControllerMpd::pushState Dec 01 18:10:20 volumio volumio[901]: info: CoreCommandRouter::servicePushState Dec 01 18:10:20 volumio volumio[901]: info: CorePlayQueue::getTrack 0 Dec 01 18:10:20 volumio volumio[901]: verbose: STATE SERVICE {"status":"play","position":0,"seek":880,"duration":58,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"file.mp3","artist":null,"album":null,"uri":"http://192.168.178.105:32469/object/c28c1fb2cdf27935656b/file.mp3","trackType":"mp3"} Dec 01 18:10:20 volumio volumio[901]: verbose: CURRENT POSITION 0 Dec 01 18:10:20 volumio volumio[901]: info: CoreStateMachine::syncState stateService play Dec 01 18:10:20 volumio volumio[901]: info: CoreStateMachine::syncState currentStatus play Dec 01 18:10:20 volumio volumio[901]: info: Received an update from plugin. extracting info from payload Dec 01 18:10:20 volumio volumio[901]: info: CoreStateMachine::pushState Dec 01 18:10:20 volumio volumio[901]: info: CoreCommandRouter::volumioPushState Dec 01 18:10:20 volumio volumio[901]: info: CoreStateMachine::pushState Dec 01 18:10:20 volumio volumio[901]: info: CoreCommandRouter::volumioPushState Dec 01 18:10:20 volumio volumio[901]: info: ------------------------------ 257ms Dec 01 18:10:20 volumio volumio[901]: info: ------------------------------ 254ms Dec 01 18:10:20 volumio volumio[901]: info: ------------------------------ 230ms Dec 01 18:10:20 volumio volumio[901]: info: sendMpdCommand status took 188 milliseconds Dec 01 18:10:20 volumio volumio[901]: info: sendMpdCommand playlistinfo took 174 milliseconds Dec 01 18:10:20 volumio volumio[901]: verbose: ControllerMpd::parseState Dec 01 18:10:20 volumio volumio[901]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 01 18:10:20 volumio volumio[901]: verbose: ControllerMpd::parseTrackInfo Dec 01 18:10:20 volumio volumio[901]: info: ControllerMpd::pushState Dec 01 18:10:20 volumio volumio[901]: info: CoreCommandRouter::servicePushState Dec 01 18:10:20 volumio volumio[901]: info: CorePlayQueue::getTrack 0 Dec 01 18:10:20 volumio volumio[901]: verbose: STATE SERVICE {"status":"play","position":0,"seek":880,"duration":58,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"file.mp3","artist":null,"album":null,"uri":"http://192.168.178.105:32469/object/c28c1fb2cdf27935656b/file.mp3","trackType":"mp3"} Dec 01 18:10:20 volumio volumio[901]: verbose: CURRENT POSITION 0 Dec 01 18:10:20 volumio volumio[901]: info: CoreStateMachine::syncState stateService play Dec 01 18:10:20 volumio volumio[901]: info: CoreStateMachine::syncState currentStatus play Dec 01 18:10:20 volumio volumio[901]: info: Received an update from plugin. extracting info from payload Dec 01 18:10:20 volumio volumio[901]: info: CoreStateMachine::pushState Dec 01 18:10:20 volumio volumio[901]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 01 18:10:20 volumio volumio[901]: info: CoreCommandRouter::volumioPushState Dec 01 18:10:20 volumio volumio[901]: info: CoreStateMachine::pushState Dec 01 18:10:20 volumio volumio[901]: info: CoreCommandRouter::volumioPushState Dec 01 18:10:20 volumio volumio[901]: info: ------------------------------ 262ms Dec 01 18:10:20 volumio volumio[901]: info: [ASDebug] CurState: play PrevState: stop Dec 01 18:10:20 volumio volumio[901]: info: [ASDebug] Togle GPIO: ON Dec 01 18:10:20 volumio volumio[901]: info: [ASDebug] CurState: play PrevState: play Dec 01 18:10:20 volumio volumio[901]: info: [ASDebug] CurState: play PrevState: play Dec 01 18:10:20 volumio volumio[901]: info: [ASDebug] CurState: play PrevState: play Dec 01 18:10:20 volumio volumio[901]: info: [ASDebug] CurState: play PrevState: play Dec 01 18:10:20 volumio volumio[901]: info: [ASDebug] CurState: play PrevState: play Dec 01 18:10:20 volumio volumio[901]: info: [ASDebug] CurState: play PrevState: play Dec 01 18:10:20 volumio volumio[901]: info: [ASDebug] CurState: play PrevState: play Dec 01 18:10:21 volumio volumio[901]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Dec 01 18:10:21 volumio volumio[901]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Dec 01 18:10:21 volumio volumio[901]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Dec 01 18:10:21 volumio volumio[901]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Dec 01 18:10:21 volumio volumio[901]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Dec 01 18:10:21 volumio volumio[901]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Dec 01 18:10:21 volumio volumio[901]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Dec 01 18:10:21 volumio volumio[901]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Dec 01 18:10:21 volumio volumio[901]: info: sendMpdCommand playlistinfo took 142 milliseconds Dec 01 18:10:21 volumio volumio[901]: verbose: ControllerMpd::parseTrackInfo Dec 01 18:10:21 volumio volumio[901]: info: ControllerMpd::pushState Dec 01 18:10:21 volumio volumio[901]: info: CoreCommandRouter::servicePushState Dec 01 18:10:21 volumio volumio[901]: info: CorePlayQueue::getTrack 0 Dec 01 18:10:21 volumio volumio[901]: verbose: STATE SERVICE {"status":"play","position":0,"seek":880,"duration":58,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"128 Kbps","isStreaming":false,"title":"file.mp3","artist":null,"album":null,"uri":"http://192.168.178.105:32469/object/c28c1fb2cdf27935656b/file.mp3","trackType":"mp3"} Dec 01 18:10:21 volumio volumio[901]: verbose: CURRENT POSITION 0 Dec 01 18:10:21 volumio volumio[901]: info: CoreStateMachine::syncState stateService play Dec 01 18:10:21 volumio volumio[901]: info: CoreStateMachine::syncState currentStatus play Dec 01 18:10:21 volumio volumio[901]: info: Received an update from plugin. extracting info from payload Dec 01 18:10:21 volumio volumio[901]: info: CoreStateMachine::pushState Dec 01 18:10:21 volumio volumio[901]: info: CoreCommandRouter::volumioPushState Dec 01 18:10:21 volumio volumio[901]: info: CoreStateMachine::pushState Dec 01 18:10:21 volumio volumio[901]: info: CoreCommandRouter::volumioPushState Dec 01 18:10:21 volumio volumio[901]: info: ------------------------------ 393ms Dec 01 18:10:21 volumio volumio[901]: info: [ASDebug] CurState: play PrevState: play Dec 01 18:10:21 volumio volumio[901]: info: [ASDebug] CurState: play PrevState: play Dec 01 18:10:21 volumio volumio[901]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Dec 01 18:10:21 volumio volumio[901]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Dec 01 18:10:22 volumio volumio[901]: error: MyVolumio Plugin failed to authenticate in a timely fashion Dec 01 18:10:22 volumio volumio[901]: info: Completed starting MyVolumio Plugin Dec 01 18:10:22 volumio volumio[901]: [Metrics] CommandRouter: 57s 85.61ms Dec 01 18:10:22 volumio volumio[901]: info: CoreCommandRouter::volumiosetStartupVolume Dec 01 18:10:22 volumio volumio[901]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 01 18:10:22 volumio volumio[901]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 01 18:10:22 volumio volumio[901]: info: CoreCommandRouter::Close All Modals sent Dec 01 18:10:22 volumio volumio[901]: info: CoreCommandRouter::Close All Modals sent Dec 01 18:10:22 volumio volumio[901]: info: Cannot play startup sound: Error: Command failed: /usr/bin/aplay -D volumio /volumio/app/startup.wav Dec 01 18:10:22 volumio volumio[901]: aplay: main:828: audio open error: Device or resource busy Dec 01 18:10:23 volumio volumio[901]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Dec 01 18:10:23 volumio volumio[901]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Dec 01 18:10:23 volumio volumio[901]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Dec 01 18:10:29 volumio volumio[901]: info: BOOT COMPLETED Dec 01 18:10:38 volumio volumio[901]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Dec 01 18:10:39 volumio volumio[901]: info: Preload queue cleared Dec 01 18:10:39 volumio volumio[901]: info: Preloading song: upnp/http://192.168.178.105:32469/ContentDirectory/7b58d976-c6f9-40f7-d1b0-54c9905d45f9/control.xml@386b97769451d75a75b6 Dec 01 18:10:39 volumio volumio[901]: info: Preloading song: upnp/http://192.168.178.105:32469/ContentDirectory/7b58d976-c6f9-40f7-d1b0-54c9905d45f9/control.xml@4327abc0a5920e022f4a Dec 01 18:10:39 volumio volumio[901]: info: Preloading song: upnp/http://192.168.178.105:32469/ContentDirectory/7b58d976-c6f9-40f7-d1b0-54c9905d45f9/control.xml@bc7001e9cb634f1bed23 Dec 01 18:10:39 volumio volumio[901]: info: Exploding uri upnp/http://192.168.178.105:32469/ContentDirectory/7b58d976-c6f9-40f7-d1b0-54c9905d45f9/control.xml@386b97769451d75a75b6 in service upnp_browser Dec 01 18:10:39 volumio volumio[901]: info: No valid Plugin REST Endpoint Dec 01 18:10:39 volumio volumio[901]: info: Exploding uri upnp/http://192.168.178.105:32469/ContentDirectory/7b58d976-c6f9-40f7-d1b0-54c9905d45f9/control.xml@4327abc0a5920e022f4a in service upnp_browser Dec 01 18:10:39 volumio volumio[901]: info: Exploding uri upnp/http://192.168.178.105:32469/ContentDirectory/7b58d976-c6f9-40f7-d1b0-54c9905d45f9/control.xml@bc7001e9cb634f1bed23 in service upnp_browser Dec 01 18:10:43 volumio volumio[901]: info: Preload queue cleared Dec 01 18:10:43 volumio volumio[901]: info: CoreCommandRouter::volumioReplaceandPlayItems Dec 01 18:10:43 volumio volumio[901]: info: CoreStateMachine::ClearQueue Dec 01 18:10:43 volumio volumio[901]: info: CoreStateMachine::stop Dec 01 18:10:43 volumio volumio[901]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 01 18:10:43 volumio volumio[901]: info: CoreStateMachine::stPlaybackTimer Dec 01 18:10:43 volumio volumio[901]: info: CoreStateMachine::updateTrackBlock Dec 01 18:10:43 volumio volumio[901]: info: CorePlayQueue::getTrackBlock Dec 01 18:10:43 volumio volumio[901]: info: CoreStateMachine::pushState Dec 01 18:10:43 volumio volumio[901]: info: CorePlayQueue::getTrack 0 Dec 01 18:10:43 volumio volumio[901]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 01 18:10:43 volumio volumio[901]: info: CoreCommandRouter::volumioPushState Dec 01 18:10:43 volumio volumio[901]: info: CoreStateMachine::serviceStop Dec 01 18:10:43 volumio volumio[901]: info: CorePlayQueue::getTrack 0 Dec 01 18:10:43 volumio volumio[901]: info: CoreCommandRouter::serviceStop Dec 01 18:10:43 volumio volumio[901]: info: [1733073043947] ControllerUPNPBrowser::stop Dec 01 18:10:43 volumio volumio[901]: verbose: ControllerMpd::sendMpdCommand stop Dec 01 18:10:43 volumio volumio[901]: info: CorePlayQueue::clearPlayQueue Dec 01 18:10:43 volumio volumio[901]: info: CorePlayQueue::saveQueue Dec 01 18:10:43 volumio volumio[901]: info: CoreCommandRouter::volumioPushQueue Dec 01 18:10:43 volumio volumio[901]: info: CoreStateMachine::addQueueItems Dec 01 18:10:43 volumio volumio[901]: info: CorePlayQueue::addQueueItems Dec 01 18:10:43 volumio volumio[901]: info: Preload queue cleared Dec 01 18:10:43 volumio volumio[901]: info: Adding Item to queue: upnp/http://192.168.178.105:32469/ContentDirectory/7b58d976-c6f9-40f7-d1b0-54c9905d45f9/control.xml@386b97769451d75a75b6 Dec 01 18:10:43 volumio volumio[901]: info: Using cached record of: upnp/http://192.168.178.105:32469/ContentDirectory/7b58d976-c6f9-40f7-d1b0-54c9905d45f9/control.xml@386b97769451d75a75b6 Dec 01 18:10:43 volumio volumio[901]: info: CoreCommandRouter::volumioPushQueue Dec 01 18:10:43 volumio volumio[901]: info: CorePlayQueue::saveQueue Dec 01 18:10:43 volumio volumio[901]: info: CoreStateMachine::updateTrackBlock Dec 01 18:10:43 volumio volumio[901]: info: CorePlayQueue::getTrackBlock Dec 01 18:10:43 volumio volumio[901]: info: CoreCommandRouter::volumioPlay Dec 01 18:10:43 volumio volumio[901]: info: CoreStateMachine::play index 0 Dec 01 18:10:43 volumio volumio[901]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 01 18:10:43 volumio volumio[901]: info: CoreStateMachine::addQueueItems Dec 01 18:10:43 volumio volumio[901]: info: CorePlayQueue::addQueueItems Dec 01 18:10:43 volumio volumio[901]: info: Preload queue cleared Dec 01 18:10:43 volumio volumio[901]: info: Adding Item to queue: upnp/http://192.168.178.105:32469/ContentDirectory/7b58d976-c6f9-40f7-d1b0-54c9905d45f9/control.xml@4327abc0a5920e022f4a Dec 01 18:10:43 volumio volumio[901]: info: Using cached record of: upnp/http://192.168.178.105:32469/ContentDirectory/7b58d976-c6f9-40f7-d1b0-54c9905d45f9/control.xml@4327abc0a5920e022f4a Dec 01 18:10:43 volumio volumio[901]: info: Adding Item to queue: upnp/http://192.168.178.105:32469/ContentDirectory/7b58d976-c6f9-40f7-d1b0-54c9905d45f9/control.xml@bc7001e9cb634f1bed23 Dec 01 18:10:43 volumio volumio[901]: info: Using cached record of: upnp/http://192.168.178.105:32469/ContentDirectory/7b58d976-c6f9-40f7-d1b0-54c9905d45f9/control.xml@bc7001e9cb634f1bed23 Dec 01 18:10:43 volumio volumio[901]: info: CoreStateMachine::stop Dec 01 18:10:43 volumio volumio[901]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 01 18:10:43 volumio volumio[901]: info: CoreCommandRouter::volumioPushQueue Dec 01 18:10:44 volumio volumio[901]: info: CorePlayQueue::saveQueue Dec 01 18:10:44 volumio volumio[901]: info: CoreStateMachine::play index undefined Dec 01 18:10:44 volumio volumio[901]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 01 18:10:44 volumio volumio[901]: info: CoreStateMachine::updateTrackBlock Dec 01 18:10:44 volumio volumio[901]: info: CorePlayQueue::getTrackBlock Dec 01 18:10:44 volumio volumio[901]: info: CorePlayQueue::getTrack 0 Dec 01 18:10:44 volumio volumio[901]: info: CoreStateMachine::startPlaybackTimer Dec 01 18:10:44 volumio volumio[901]: info: CorePlayQueue::getTrack 0 Dec 01 18:10:44 volumio volumio[901]: info: [1733073044015] ControllerUPNPBrowser::clearAddPlayTrack Dec 01 18:10:44 volumio volumio[901]: verbose: ControllerMpd::sendMpdCommand stop Dec 01 18:10:44 volumio volumio[901]: info: [ASDebug] CurState: stop PrevState: play Dec 01 18:10:44 volumio volumio[901]: info: [ASDebug] InitTimeout - Amp off in: 720 ms Dec 01 18:10:44 volumio volumio[901]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Dec 01 18:10:44 volumio volumio[901]: info: Dec 01 18:10:44 volumio volumio[901]: ---------------------------- MPD announces state update: player Dec 01 18:10:44 volumio volumio[901]: info: sendMpdCommand stop took 98 milliseconds Dec 01 18:10:44 volumio volumio[901]: info: ControllerMpd::getState Dec 01 18:10:44 volumio volumio[901]: verbose: ControllerMpd::sendMpdCommand status Dec 01 18:10:44 volumio volumio[901]: info: sendMpdCommand stop took 32 milliseconds Dec 01 18:10:44 volumio volumio[901]: verbose: ControllerMpd::sendMpdCommand clear Dec 01 18:10:44 volumio volumio[901]: info: Dec 01 18:10:44 volumio volumio[901]: ---------------------------- MPD announces state update: player Dec 01 18:10:44 volumio volumio[901]: info: ControllerMpd::getState Dec 01 18:10:44 volumio volumio[901]: verbose: ControllerMpd::sendMpdCommand status Dec 01 18:10:44 volumio volumio[901]: info: Dec 01 18:10:44 volumio volumio[901]: ---------------------------- MPD announces state update: player Dec 01 18:10:44 volumio volumio[901]: info: ControllerMpd::getState Dec 01 18:10:44 volumio volumio[901]: verbose: ControllerMpd::sendMpdCommand status Dec 01 18:10:44 volumio volumio[901]: info: Dec 01 18:10:44 volumio volumio[901]: ---------------------------- MPD announces system playlist update Dec 01 18:10:44 volumio volumio[901]: info: Ignoring MPD Status Update Dec 01 18:10:44 volumio volumio[901]: info: sendMpdCommand status took 25 milliseconds Dec 01 18:10:44 volumio volumio[901]: info: sendMpdCommand clear took 24 milliseconds Dec 01 18:10:44 volumio volumio[901]: info: sendMpdCommand status took 21 milliseconds Dec 01 18:10:44 volumio volumio[901]: info: sendMpdCommand status took 14 milliseconds Dec 01 18:10:44 volumio volumio[901]: verbose: ControllerMpd::parseState Dec 01 18:10:44 volumio volumio[901]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 01 18:10:44 volumio volumio[901]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.178.105:32469/object/386b97769451d75a75b6/file.mp3" Dec 01 18:10:44 volumio volumio[901]: verbose: ControllerMpd::parseState Dec 01 18:10:44 volumio volumio[901]: verbose: ControllerMpd::parseState Dec 01 18:10:44 volumio volumio[901]: info: ControllerMpd::pushState Dec 01 18:10:44 volumio volumio[901]: info: CoreCommandRouter::servicePushState Dec 01 18:10:44 volumio volumio[901]: info: CoreStateMachine::pushState Dec 01 18:10:44 volumio volumio[901]: info: CorePlayQueue::getTrack 0 Dec 01 18:10:44 volumio volumio[901]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 01 18:10:44 volumio volumio[901]: info: CoreCommandRouter::volumioPushState Dec 01 18:10:44 volumio volumio[901]: info: CorePlayQueue::getTrack 0 Dec 01 18:10:44 volumio volumio[901]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Dec 01 18:10:44 volumio volumio[901]: verbose: CURRENT POSITION 0 Dec 01 18:10:44 volumio volumio[901]: info: CoreStateMachine::syncState stateService stop Dec 01 18:10:44 volumio volumio[901]: info: CoreStateMachine::syncState currentStatus stop Dec 01 18:10:44 volumio volumio[901]: info: CoreStateMachine::pushState Dec 01 18:10:44 volumio volumio[901]: info: CorePlayQueue::getTrack 0 Dec 01 18:10:44 volumio volumio[901]: info: CoreCommandRouter::volumioPushState Dec 01 18:10:44 volumio volumio[901]: info: No code Dec 01 18:10:44 volumio volumio[901]: info: CoreStateMachine::pushState Dec 01 18:10:44 volumio volumio[901]: info: CorePlayQueue::getTrack 0 Dec 01 18:10:44 volumio volumio[901]: info: CoreCommandRouter::volumioPushState Dec 01 18:10:44 volumio volumio[901]: info: ControllerMpd::pushState Dec 01 18:10:44 volumio volumio[901]: info: CoreCommandRouter::servicePushState Dec 01 18:10:44 volumio volumio[901]: info: CoreStateMachine::pushState Dec 01 18:10:44 volumio volumio[901]: info: CorePlayQueue::getTrack 0 Dec 01 18:10:44 volumio volumio[901]: info: CoreCommandRouter::volumioPushState Dec 01 18:10:44 volumio volumio[901]: info: CorePlayQueue::getTrack 0 Dec 01 18:10:44 volumio volumio[901]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Dec 01 18:10:44 volumio volumio[901]: verbose: CURRENT POSITION 0 Dec 01 18:10:44 volumio volumio[901]: info: CoreStateMachine::syncState stateService stop Dec 01 18:10:44 volumio volumio[901]: info: CoreStateMachine::syncState currentStatus stop Dec 01 18:10:44 volumio volumio[901]: info: CoreStateMachine::pushState Dec 01 18:10:44 volumio volumio[901]: info: CorePlayQueue::getTrack 0 Dec 01 18:10:44 volumio volumio[901]: info: CoreCommandRouter::volumioPushState Dec 01 18:10:44 volumio volumio[901]: info: No code Dec 01 18:10:44 volumio volumio[901]: info: CoreStateMachine::pushState Dec 01 18:10:44 volumio volumio[901]: info: CorePlayQueue::getTrack 0 Dec 01 18:10:44 volumio volumio[901]: info: CoreCommandRouter::volumioPushState Dec 01 18:10:44 volumio volumio[901]: info: ------------------------------ 252ms Dec 01 18:10:44 volumio volumio[901]: info: ------------------------------ 245ms Dec 01 18:10:44 volumio volumio[901]: info: Dec 01 18:10:44 volumio volumio[901]: ---------------------------- MPD announces system playlist update Dec 01 18:10:44 volumio volumio[901]: info: Ignoring MPD Status Update Dec 01 18:10:44 volumio volumio[901]: info: Dec 01 18:10:44 volumio volumio[901]: ---------------------------- MPD announces system playlist update Dec 01 18:10:44 volumio volumio[901]: info: Ignoring MPD Status Update Dec 01 18:10:44 volumio volumio[901]: error: updateQueue error: null Dec 01 18:10:44 volumio volumio[901]: error: updateQueue error: null Dec 01 18:10:44 volumio volumio[901]: error: updateQueue error: null Dec 01 18:10:44 volumio volumio[901]: info: ------------------------------ 254ms Dec 01 18:10:44 volumio volumio[901]: info: sendMpdCommand playlistinfo took 246 milliseconds Dec 01 18:10:44 volumio volumio[901]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.178.105:32469/object/386b97769451d75a75b6/file.mp3" Dec 01 18:10:44 volumio volumio[901]: info: ------------------------------ 17ms Dec 01 18:10:44 volumio volumio[901]: info: ------------------------------ 15ms Dec 01 18:10:44 volumio volumio[901]: verbose: ControllerMpd::parseTrackInfo Dec 01 18:10:44 volumio volumio[901]: error: ControllerMpd::pushError: TypeError: Cannot read property 'split' of undefined Dec 01 18:10:44 volumio volumio[901]: info: ------------------------------ 286ms Dec 01 18:10:44 volumio volumio[901]: info: [ASDebug] CurState: stop PrevState: play Dec 01 18:10:44 volumio volumio[901]: info: [ASDebug] InitTimeout - Amp off in: 720 ms Dec 01 18:10:44 volumio volumio[901]: info: [ASDebug] CurState: stop PrevState: play Dec 01 18:10:44 volumio volumio[901]: info: [ASDebug] InitTimeout - Amp off in: 720 ms Dec 01 18:10:44 volumio volumio[901]: info: [ASDebug] CurState: stop PrevState: play Dec 01 18:10:44 volumio volumio[901]: info: [ASDebug] InitTimeout - Amp off in: 720 ms Dec 01 18:10:44 volumio volumio[901]: info: [ASDebug] CurState: stop PrevState: play Dec 01 18:10:44 volumio volumio[901]: info: [ASDebug] InitTimeout - Amp off in: 720 ms Dec 01 18:10:44 volumio volumio[901]: info: [ASDebug] CurState: stop PrevState: play Dec 01 18:10:44 volumio volumio[901]: info: [ASDebug] InitTimeout - Amp off in: 720 ms Dec 01 18:10:44 volumio volumio[901]: info: [ASDebug] CurState: stop PrevState: play Dec 01 18:10:44 volumio volumio[901]: info: [ASDebug] InitTimeout - Amp off in: 720 ms Dec 01 18:10:44 volumio volumio[901]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Dec 01 18:10:44 volumio volumio[901]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Dec 01 18:10:44 volumio volumio[901]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Dec 01 18:10:44 volumio volumio[901]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Dec 01 18:10:44 volumio volumio[901]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Dec 01 18:10:44 volumio volumio[901]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Dec 01 18:10:44 volumio volumio[901]: info: Dec 01 18:10:44 volumio volumio[901]: ---------------------------- MPD announces system playlist update Dec 01 18:10:44 volumio volumio[901]: info: Ignoring MPD Status Update Dec 01 18:10:44 volumio volumio[901]: info: sendMpdCommand add "http://192.168.178.105:32469/object/386b97769451d75a75b6/file.mp3" took 211 milliseconds Dec 01 18:10:44 volumio volumio[901]: info: CoreStateMachine::setConsumeUpdateService mpd Dec 01 18:10:44 volumio volumio[901]: verbose: ControllerMpd::sendMpdCommand play Dec 01 18:10:44 volumio volumio[901]: info: Dec 01 18:10:44 volumio volumio[901]: ---------------------------- MPD announces system playlist update Dec 01 18:10:44 volumio volumio[901]: info: Ignoring MPD Status Update Dec 01 18:10:44 volumio volumio[901]: info: Dec 01 18:10:44 volumio volumio[901]: ---------------------------- MPD announces system playlist update Dec 01 18:10:44 volumio volumio[901]: info: Ignoring MPD Status Update Dec 01 18:10:44 volumio volumio[901]: info: ------------------------------ 25ms Dec 01 18:10:44 volumio volumio[901]: info: sendMpdCommand play took 20 milliseconds Dec 01 18:10:44 volumio volumio[901]: info: ------------------------------ 17ms Dec 01 18:10:44 volumio volumio[901]: info: ------------------------------ 15ms Dec 01 18:10:44 volumio volumio[901]: info: Dec 01 18:10:44 volumio volumio[901]: ---------------------------- MPD announces state update: player Dec 01 18:10:44 volumio volumio[901]: info: ControllerMpd::getState Dec 01 18:10:44 volumio volumio[901]: verbose: ControllerMpd::sendMpdCommand status Dec 01 18:10:44 volumio volumio[901]: info: Dec 01 18:10:44 volumio volumio[901]: ---------------------------- MPD announces state update: player Dec 01 18:10:44 volumio volumio[901]: info: ControllerMpd::getState Dec 01 18:10:44 volumio volumio[901]: verbose: ControllerMpd::sendMpdCommand status Dec 01 18:10:44 volumio volumio[901]: info: Dec 01 18:10:44 volumio volumio[901]: ---------------------------- MPD announces state update: player Dec 01 18:10:44 volumio volumio[901]: info: ControllerMpd::getState Dec 01 18:10:44 volumio volumio[901]: verbose: ControllerMpd::sendMpdCommand status Dec 01 18:10:44 volumio volumio[901]: info: Dec 01 18:10:44 volumio volumio[901]: ---------------------------- MPD announces state update: player Dec 01 18:10:44 volumio volumio[901]: info: sendMpdCommand status took 37 milliseconds Dec 01 18:10:44 volumio volumio[901]: info: ControllerMpd::getState Dec 01 18:10:44 volumio volumio[901]: verbose: ControllerMpd::sendMpdCommand status Dec 01 18:10:44 volumio volumio[901]: info: sendMpdCommand status took 38 milliseconds Dec 01 18:10:44 volumio volumio[901]: info: sendMpdCommand status took 23 milliseconds Dec 01 18:10:44 volumio volumio[901]: verbose: ControllerMpd::parseState Dec 01 18:10:44 volumio volumio[901]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 01 18:10:44 volumio volumio[901]: verbose: ControllerMpd::parseState Dec 01 18:10:44 volumio volumio[901]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 01 18:10:44 volumio volumio[901]: verbose: ControllerMpd::parseState Dec 01 18:10:44 volumio volumio[901]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 01 18:10:44 volumio volumio[901]: info: Dec 01 18:10:44 volumio volumio[901]: ---------------------------- MPD announces state update: player Dec 01 18:10:44 volumio volumio[901]: info: ControllerMpd::getState Dec 01 18:10:44 volumio volumio[901]: verbose: ControllerMpd::sendMpdCommand status Dec 01 18:10:44 volumio volumio[901]: info: Dec 01 18:10:44 volumio volumio[901]: ---------------------------- MPD announces state update: player Dec 01 18:10:44 volumio volumio[901]: info: ControllerMpd::getState Dec 01 18:10:44 volumio volumio[901]: verbose: ControllerMpd::sendMpdCommand status Dec 01 18:10:44 volumio volumio[901]: info: Dec 01 18:10:44 volumio volumio[901]: ---------------------------- MPD announces system playlist update Dec 01 18:10:44 volumio volumio[901]: info: Ignoring MPD Status Update Dec 01 18:10:44 volumio volumio[901]: info: Dec 01 18:10:44 volumio volumio[901]: ---------------------------- MPD announces state update: player Dec 01 18:10:44 volumio volumio[901]: info: sendMpdCommand status took 48 milliseconds Dec 01 18:10:44 volumio volumio[901]: info: ControllerMpd::getState Dec 01 18:10:44 volumio volumio[901]: verbose: ControllerMpd::sendMpdCommand status Dec 01 18:10:44 volumio volumio[901]: info: sendMpdCommand playlistinfo took 46 milliseconds Dec 01 18:10:44 volumio volumio[901]: info: sendMpdCommand playlistinfo took 42 milliseconds Dec 01 18:10:44 volumio volumio[901]: info: sendMpdCommand playlistinfo took 37 milliseconds Dec 01 18:10:44 volumio volumio[901]: info: sendMpdCommand status took 28 milliseconds Dec 01 18:10:44 volumio volumio[901]: info: sendMpdCommand status took 23 milliseconds Dec 01 18:10:44 volumio volumio[901]: verbose: ControllerMpd::parseState Dec 01 18:10:44 volumio volumio[901]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 01 18:10:44 volumio volumio[901]: verbose: ControllerMpd::parseTrackInfo Dec 01 18:10:44 volumio volumio[901]: verbose: ControllerMpd::parseTrackInfo Dec 01 18:10:44 volumio volumio[901]: verbose: ControllerMpd::parseTrackInfo Dec 01 18:10:44 volumio volumio[901]: verbose: ControllerMpd::parseState Dec 01 18:10:44 volumio volumio[901]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 01 18:10:44 volumio volumio[901]: verbose: ControllerMpd::parseState Dec 01 18:10:44 volumio volumio[901]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 01 18:10:44 volumio volumio[901]: info: ControllerMpd::pushState Dec 01 18:10:44 volumio volumio[901]: info: CoreCommandRouter::servicePushState Dec 01 18:10:44 volumio volumio[901]: info: CorePlayQueue::getTrack 0 Dec 01 18:10:44 volumio volumio[901]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":211,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Autobahn (Single Version)","artist":"Kraftwerk","album":"1974-2004","uri":"http://192.168.178.105:32469/object/386b97769451d75a75b6/file.mp3","trackType":"mp3"} Dec 01 18:10:44 volumio volumio[901]: verbose: CURRENT POSITION 0 Dec 01 18:10:44 volumio volumio[901]: info: CoreStateMachine::syncState stateService play Dec 01 18:10:44 volumio volumio[901]: info: CoreStateMachine::syncState currentStatus stop Dec 01 18:10:44 volumio volumio[901]: info: ControllerMpd::pushState Dec 01 18:10:44 volumio volumio[901]: info: CoreCommandRouter::servicePushState Dec 01 18:10:44 volumio volumio[901]: info: CorePlayQueue::getTrack 0 Dec 01 18:10:44 volumio volumio[901]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":211,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Autobahn (Single Version)","artist":"Kraftwerk","album":"1974-2004","uri":"http://192.168.178.105:32469/object/386b97769451d75a75b6/file.mp3","trackType":"mp3"} Dec 01 18:10:44 volumio volumio[901]: verbose: CURRENT POSITION 0 Dec 01 18:10:44 volumio volumio[901]: info: CoreStateMachine::syncState stateService play Dec 01 18:10:44 volumio volumio[901]: info: CoreStateMachine::syncState currentStatus play Dec 01 18:10:44 volumio volumio[901]: info: Received an update from plugin. extracting info from payload Dec 01 18:10:44 volumio volumio[901]: info: CoreStateMachine::pushState Dec 01 18:10:44 volumio volumio[901]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 01 18:10:44 volumio volumio[901]: info: CoreCommandRouter::volumioPushState Dec 01 18:10:44 volumio volumio[901]: info: CoreStateMachine::pushState Dec 01 18:10:44 volumio volumio[901]: info: CoreCommandRouter::volumioPushState Dec 01 18:10:44 volumio volumio[901]: info: ControllerMpd::pushState Dec 01 18:10:44 volumio volumio[901]: info: CoreCommandRouter::servicePushState Dec 01 18:10:44 volumio volumio[901]: info: CorePlayQueue::getTrack 0 Dec 01 18:10:44 volumio volumio[901]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":211,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"Autobahn (Single Version)","artist":"Kraftwerk","album":"1974-2004","uri":"http://192.168.178.105:32469/object/386b97769451d75a75b6/file.mp3","trackType":"mp3"} Dec 01 18:10:44 volumio volumio[901]: verbose: CURRENT POSITION 0 Dec 01 18:10:44 volumio volumio[901]: info: CoreStateMachine::syncState stateService play Dec 01 18:10:44 volumio volumio[901]: info: CoreStateMachine::syncState currentStatus play Dec 01 18:10:44 volumio volumio[901]: info: Received an update from plugin. extracting info from payload Dec 01 18:10:44 volumio volumio[901]: info: CoreStateMachine::pushState Dec 01 18:10:44 volumio volumio[901]: info: CoreCommandRouter::volumioPushState Dec 01 18:10:44 volumio volumio[901]: info: CoreStateMachine::pushState Dec 01 18:10:44 volumio volumio[901]: info: CoreCommandRouter::volumioPushState Dec 01 18:10:44 volumio volumio[901]: info: ------------------------------ 246ms Dec 01 18:10:44 volumio volumio[901]: info: ------------------------------ 338ms Dec 01 18:10:44 volumio volumio[901]: info: ------------------------------ 330ms Dec 01 18:10:44 volumio volumio[901]: info: Dec 01 18:10:44 volumio volumio[901]: ---------------------------- MPD announces system playlist update Dec 01 18:10:44 volumio volumio[901]: info: Ignoring MPD Status Update Dec 01 18:10:44 volumio volumio[901]: info: Dec 01 18:10:44 volumio volumio[901]: ---------------------------- MPD announces state update: player Dec 01 18:10:44 volumio volumio[901]: info: ControllerMpd::getState Dec 01 18:10:44 volumio volumio[901]: verbose: ControllerMpd::sendMpdCommand status Dec 01 18:10:44 volumio volumio[901]: info: Dec 01 18:10:44 volumio volumio[901]: ---------------------------- MPD announces system playlist update Dec 01 18:10:44 volumio volumio[901]: info: Ignoring MPD Status Update Dec 01 18:10:44 volumio volumio[901]: info: Dec 01 18:10:44 volumio volumio[901]: ---------------------------- MPD announces state update: player Dec 01 18:10:44 volumio volumio[901]: info: ControllerMpd::getState Dec 01 18:10:44 volumio volumio[901]: verbose: ControllerMpd::sendMpdCommand status Dec 01 18:10:44 volumio volumio[901]: info: ------------------------------ 273ms Dec 01 18:10:44 volumio volumio[901]: info: sendMpdCommand status took 264 milliseconds Dec 01 18:10:44 volumio volumio[901]: info: sendMpdCommand playlistinfo took 257 milliseconds Dec 01 18:10:44 volumio volumio[901]: info: sendMpdCommand playlistinfo took 250 milliseconds Dec 01 18:10:44 volumio volumio[901]: info: sendMpdCommand playlistinfo took 243 milliseconds Dec 01 18:10:44 volumio volumio[901]: info: ------------------------------ 19ms Dec 01 18:10:44 volumio volumio[901]: info: sendMpdCommand status took 15 milliseconds Dec 01 18:10:44 volumio volumio[901]: info: ------------------------------ 15ms Dec 01 18:10:44 volumio volumio[901]: info: sendMpdCommand status took 12 milliseconds Dec 01 18:10:44 volumio volumio[901]: verbose: ControllerMpd::parseState Dec 01 18:10:44 volumio volumio[901]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 01 18:10:44 volumio volumio[901]: verbose: ControllerMpd::parseTrackInfo Dec 01 18:10:44 volumio volumio[901]: verbose: ControllerMpd::parseTrackInfo Dec 01 18:10:44 volumio volumio[901]: verbose: ControllerMpd::parseTrackInfo Dec 01 18:10:44 volumio volumio[901]: verbose: ControllerMpd::parseState Dec 01 18:10:44 volumio volumio[901]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 01 18:10:44 volumio volumio[901]: verbose: ControllerMpd::parseState Dec 01 18:10:44 volumio volumio[901]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 01 18:10:44 volumio volumio[901]: info: ControllerMpd::pushState Dec 01 18:10:44 volumio volumio[901]: info: CoreCommandRouter::servicePushState Dec 01 18:10:44 volumio volumio[901]: info: CorePlayQueue::getTrack 0 Dec 01 18:10:44 volumio volumio[901]: verbose: STATE SERVICE {"status":"play","position":0,"seek":377,"duration":211,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"160 Kbps","isStreaming":false,"title":"Autobahn (Single Version)","artist":"Kraftwerk","album":"1974-2004","uri":"http://192.168.178.105:32469/object/386b97769451d75a75b6/file.mp3","trackType":"mp3"} Dec 01 18:10:44 volumio volumio[901]: verbose: CURRENT POSITION 0 Dec 01 18:10:44 volumio volumio[901]: info: CoreStateMachine::syncState stateService play Dec 01 18:10:44 volumio volumio[901]: info: CoreStateMachine::syncState currentStatus play Dec 01 18:10:44 volumio volumio[901]: info: Received an update from plugin. extracting info from payload Dec 01 18:10:44 volumio volumio[901]: info: CoreStateMachine::pushState Dec 01 18:10:44 volumio volumio[901]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 01 18:10:44 volumio volumio[901]: info: CoreCommandRouter::volumioPushState Dec 01 18:10:44 volumio volumio[901]: info: CoreStateMachine::pushState Dec 01 18:10:44 volumio volumio[901]: info: CoreCommandRouter::volumioPushState Dec 01 18:10:44 volumio volumio[901]: info: ControllerMpd::pushState Dec 01 18:10:44 volumio volumio[901]: info: CoreCommandRouter::servicePushState Dec 01 18:10:44 volumio volumio[901]: info: CorePlayQueue::getTrack 0 Dec 01 18:10:44 volumio volumio[901]: verbose: STATE SERVICE {"status":"play","position":0,"seek":880,"duration":211,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"160 Kbps","isStreaming":false,"title":"Autobahn (Single Version)","artist":"Kraftwerk","album":"1974-2004","uri":"http://192.168.178.105:32469/object/386b97769451d75a75b6/file.mp3","trackType":"mp3"} Dec 01 18:10:44 volumio volumio[901]: verbose: CURRENT POSITION 0 Dec 01 18:10:44 volumio volumio[901]: info: CoreStateMachine::syncState stateService play Dec 01 18:10:44 volumio volumio[901]: info: CoreStateMachine::syncState currentStatus play Dec 01 18:10:44 volumio volumio[901]: info: Received an update from plugin. extracting info from payload Dec 01 18:10:44 volumio volumio[901]: info: CoreStateMachine::pushState Dec 01 18:10:44 volumio volumio[901]: info: CoreCommandRouter::volumioPushState Dec 01 18:10:44 volumio volumio[901]: info: CoreStateMachine::pushState Dec 01 18:10:44 volumio volumio[901]: info: CoreCommandRouter::volumioPushState Dec 01 18:10:44 volumio volumio[901]: info: ControllerMpd::pushState Dec 01 18:10:44 volumio volumio[901]: info: CoreCommandRouter::servicePushState Dec 01 18:10:44 volumio volumio[901]: info: CorePlayQueue::getTrack 0 Dec 01 18:10:44 volumio volumio[901]: verbose: STATE SERVICE {"status":"play","position":0,"seek":880,"duration":211,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"Autobahn (Single Version)","artist":"Kraftwerk","album":"1974-2004","uri":"http://192.168.178.105:32469/object/386b97769451d75a75b6/file.mp3","trackType":"mp3"} Dec 01 18:10:44 volumio volumio[901]: verbose: CURRENT POSITION 0 Dec 01 18:10:44 volumio volumio[901]: info: CoreStateMachine::syncState stateService play Dec 01 18:10:44 volumio volumio[901]: info: CoreStateMachine::syncState currentStatus play Dec 01 18:10:44 volumio volumio[901]: info: Received an update from plugin. extracting info from payload Dec 01 18:10:44 volumio volumio[901]: info: CoreStateMachine::pushState Dec 01 18:10:44 volumio volumio[901]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 01 18:10:44 volumio volumio[901]: info: CoreCommandRouter::volumioPushState Dec 01 18:10:44 volumio volumio[901]: info: CoreStateMachine::pushState Dec 01 18:10:44 volumio volumio[901]: info: CoreCommandRouter::volumioPushState Dec 01 18:10:45 volumio volumio[901]: info: ------------------------------ 473ms Dec 01 18:10:45 volumio volumio[901]: info: ------------------------------ 441ms Dec 01 18:10:45 volumio volumio[901]: info: ------------------------------ 436ms Dec 01 18:10:45 volumio volumio[901]: info: [ASDebug] CurState: play PrevState: play Dec 01 18:10:45 volumio volumio[901]: info: [ASDebug] CurState: play PrevState: play Dec 01 18:10:45 volumio volumio[901]: info: [ASDebug] CurState: play PrevState: play Dec 01 18:10:45 volumio volumio[901]: info: [ASDebug] CurState: play PrevState: play Dec 01 18:10:45 volumio volumio[901]: info: [ASDebug] CurState: play PrevState: play Dec 01 18:10:45 volumio volumio[901]: info: [ASDebug] CurState: play PrevState: play Dec 01 18:10:45 volumio volumio[901]: info: [ASDebug] CurState: play PrevState: play Dec 01 18:10:45 volumio volumio[901]: info: [ASDebug] CurState: play PrevState: play Dec 01 18:10:45 volumio volumio[901]: info: [ASDebug] CurState: play PrevState: play Dec 01 18:10:45 volumio volumio[901]: info: [ASDebug] CurState: play PrevState: play Dec 01 18:10:45 volumio volumio[901]: info: CoreCommandRouter::volumioGetQueue Dec 01 18:10:45 volumio volumio[901]: info: CoreStateMachine::getQueue Dec 01 18:10:45 volumio volumio[901]: info: CorePlayQueue::getQueue Dec 01 18:10:45 volumio volumio[901]: info: CoreCommandRouter::volumioGetQueue Dec 01 18:10:45 volumio volumio[901]: info: CoreStateMachine::getQueue Dec 01 18:10:45 volumio volumio[901]: info: CorePlayQueue::getQueue Dec 01 18:10:45 volumio volumio[901]: info: CoreCommandRouter::volumioGetQueue Dec 01 18:10:45 volumio volumio[901]: info: CoreStateMachine::getQueue Dec 01 18:10:45 volumio volumio[901]: info: CorePlayQueue::getQueue Dec 01 18:10:45 volumio volumio[901]: info: CoreCommandRouter::volumioGetQueue Dec 01 18:10:45 volumio volumio[901]: info: CoreStateMachine::getQueue Dec 01 18:10:45 volumio volumio[901]: info: CorePlayQueue::getQueue Dec 01 18:10:45 volumio volumio[901]: info: CoreCommandRouter::volumioGetQueue Dec 01 18:10:45 volumio volumio[901]: info: CoreStateMachine::getQueue Dec 01 18:10:45 volumio volumio[901]: info: CorePlayQueue::getQueue Dec 01 18:10:45 volumio volumio[901]: info: CoreCommandRouter::volumioGetQueue Dec 01 18:10:45 volumio volumio[901]: info: CoreStateMachine::getQueue Dec 01 18:10:45 volumio volumio[901]: info: CorePlayQueue::getQueue Dec 01 18:10:45 volumio volumio[901]: info: CoreCommandRouter::volumioGetQueue Dec 01 18:10:45 volumio volumio[901]: info: CoreStateMachine::getQueue Dec 01 18:10:45 volumio volumio[901]: info: CorePlayQueue::getQueue Dec 01 18:10:45 volumio volumio[901]: info: CoreCommandRouter::volumioGetQueue Dec 01 18:10:45 volumio volumio[901]: info: CoreStateMachine::getQueue Dec 01 18:10:45 volumio volumio[901]: info: CorePlayQueue::getQueue Dec 01 18:10:45 volumio volumio[901]: info: CoreCommandRouter::volumioGetQueue Dec 01 18:10:45 volumio volumio[901]: info: CoreStateMachine::getQueue Dec 01 18:10:45 volumio volumio[901]: info: CorePlayQueue::getQueue Dec 01 18:10:45 volumio volumio[901]: info: CoreCommandRouter::volumioGetQueue Dec 01 18:10:45 volumio volumio[901]: info: CoreStateMachine::getQueue Dec 01 18:10:45 volumio volumio[901]: info: CorePlayQueue::getQueue Dec 01 18:10:45 volumio volumio[901]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Dec 01 18:10:45 volumio volumio[901]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Dec 01 18:10:45 volumio volumio[901]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Dec 01 18:10:45 volumio volumio[901]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Dec 01 18:10:45 volumio volumio[901]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Dec 01 18:10:45 volumio volumio[901]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Dec 01 18:10:45 volumio volumio[901]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Dec 01 18:10:45 volumio volumio[901]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Dec 01 18:10:45 volumio volumio[901]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Dec 01 18:10:45 volumio volumio[901]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Dec 01 18:10:45 volumio volumio[901]: info: sendMpdCommand playlistinfo took 350 milliseconds Dec 01 18:10:45 volumio volumio[901]: info: sendMpdCommand playlistinfo took 343 milliseconds Dec 01 18:10:45 volumio volumio[901]: info: sendMpdCommand playlistinfo took 342 milliseconds Dec 01 18:10:45 volumio volumio[901]: verbose: ControllerMpd::parseTrackInfo Dec 01 18:10:45 volumio volumio[901]: verbose: ControllerMpd::parseTrackInfo Dec 01 18:10:45 volumio volumio[901]: verbose: ControllerMpd::parseTrackInfo Dec 01 18:10:45 volumio volumio[901]: info: ControllerMpd::pushState Dec 01 18:10:45 volumio volumio[901]: info: CoreCommandRouter::servicePushState Dec 01 18:10:45 volumio volumio[901]: info: CorePlayQueue::getTrack 0 Dec 01 18:10:45 volumio volumio[901]: verbose: STATE SERVICE {"status":"play","position":0,"seek":880,"duration":211,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"Autobahn (Single Version)","artist":"Kraftwerk","album":"1974-2004","uri":"http://192.168.178.105:32469/object/386b97769451d75a75b6/file.mp3","trackType":"mp3"} Dec 01 18:10:45 volumio volumio[901]: verbose: CURRENT POSITION 0 Dec 01 18:10:45 volumio volumio[901]: info: CoreStateMachine::syncState stateService play Dec 01 18:10:45 volumio volumio[901]: info: CoreStateMachine::syncState currentStatus play Dec 01 18:10:45 volumio volumio[901]: info: Received an update from plugin. extracting info from payload Dec 01 18:10:45 volumio volumio[901]: info: CoreStateMachine::pushState Dec 01 18:10:45 volumio volumio[901]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 01 18:10:45 volumio volumio[901]: info: CoreCommandRouter::volumioPushState Dec 01 18:10:45 volumio volumio[901]: info: CoreStateMachine::pushState Dec 01 18:10:45 volumio volumio[901]: info: CoreCommandRouter::volumioPushState Dec 01 18:10:45 volumio volumio[901]: info: ControllerMpd::pushState Dec 01 18:10:45 volumio volumio[901]: info: CoreCommandRouter::servicePushState Dec 01 18:10:45 volumio volumio[901]: info: CorePlayQueue::getTrack 0 Dec 01 18:10:45 volumio volumio[901]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1085,"duration":211,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"Autobahn (Single Version)","artist":"Kraftwerk","album":"1974-2004","uri":"http://192.168.178.105:32469/object/386b97769451d75a75b6/file.mp3","trackType":"mp3"} Dec 01 18:10:45 volumio volumio[901]: verbose: CURRENT POSITION 0 Dec 01 18:10:45 volumio volumio[901]: info: CoreStateMachine::syncState stateService play Dec 01 18:10:45 volumio volumio[901]: info: CoreStateMachine::syncState currentStatus play Dec 01 18:10:45 volumio volumio[901]: info: Received an update from plugin. extracting info from payload Dec 01 18:10:45 volumio volumio[901]: info: CoreStateMachine::pushState Dec 01 18:10:45 volumio volumio[901]: info: CoreCommandRouter::volumioPushState Dec 01 18:10:45 volumio volumio[901]: info: CoreStateMachine::pushState Dec 01 18:10:45 volumio volumio[901]: info: CoreCommandRouter::volumioPushState Dec 01 18:10:45 volumio volumio[901]: info: ControllerMpd::pushState Dec 01 18:10:45 volumio volumio[901]: info: CoreCommandRouter::servicePushState Dec 01 18:10:45 volumio volumio[901]: info: CorePlayQueue::getTrack 0 Dec 01 18:10:45 volumio volumio[901]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1085,"duration":211,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"Autobahn (Single Version)","artist":"Kraftwerk","album":"1974-2004","uri":"http://192.168.178.105:32469/object/386b97769451d75a75b6/file.mp3","trackType":"mp3"} Dec 01 18:10:45 volumio volumio[901]: verbose: CURRENT POSITION 0 Dec 01 18:10:45 volumio volumio[901]: info: CoreStateMachine::syncState stateService play Dec 01 18:10:45 volumio volumio[901]: info: CoreStateMachine::syncState currentStatus play Dec 01 18:10:45 volumio volumio[901]: info: Received an update from plugin. extracting info from payload Dec 01 18:10:45 volumio volumio[901]: info: CoreStateMachine::pushState Dec 01 18:10:45 volumio volumio[901]: info: CoreCommandRouter::volumioPushState Dec 01 18:10:45 volumio volumio[901]: info: CoreStateMachine::pushState Dec 01 18:10:45 volumio volumio[901]: info: CoreCommandRouter::volumioPushState Dec 01 18:10:45 volumio volumio[901]: info: ------------------------------ 894ms Dec 01 18:10:45 volumio volumio[901]: info: ------------------------------ 640ms Dec 01 18:10:45 volumio volumio[901]: info: ------------------------------ 638ms Dec 01 18:10:45 volumio volumio[901]: info: [ASDebug] CurState: play PrevState: play Dec 01 18:10:45 volumio volumio[901]: info: [ASDebug] CurState: play PrevState: play Dec 01 18:10:45 volumio volumio[901]: info: [ASDebug] CurState: play PrevState: play Dec 01 18:10:45 volumio volumio[901]: info: [ASDebug] CurState: play PrevState: play Dec 01 18:10:45 volumio volumio[901]: info: [ASDebug] CurState: play PrevState: play Dec 01 18:10:45 volumio volumio[901]: info: [ASDebug] CurState: play PrevState: play Dec 01 18:10:45 volumio volumio[901]: info: CoreCommandRouter::volumioGetQueue Dec 01 18:10:45 volumio volumio[901]: info: CoreStateMachine::getQueue Dec 01 18:10:45 volumio volumio[901]: info: CorePlayQueue::getQueue Dec 01 18:10:45 volumio volumio[901]: info: CoreCommandRouter::volumioGetQueue Dec 01 18:10:45 volumio volumio[901]: info: CoreStateMachine::getQueue Dec 01 18:10:45 volumio volumio[901]: info: CorePlayQueue::getQueue Dec 01 18:10:45 volumio volumio[901]: info: CoreCommandRouter::volumioGetQueue Dec 01 18:10:45 volumio volumio[901]: info: CoreStateMachine::getQueue Dec 01 18:10:45 volumio volumio[901]: info: CorePlayQueue::getQueue Dec 01 18:10:45 volumio volumio[901]: info: CoreCommandRouter::volumioGetQueue Dec 01 18:10:45 volumio volumio[901]: info: CoreStateMachine::getQueue Dec 01 18:10:45 volumio volumio[901]: info: CorePlayQueue::getQueue Dec 01 18:10:45 volumio volumio[901]: info: CoreCommandRouter::volumioGetQueue Dec 01 18:10:45 volumio volumio[901]: info: CoreStateMachine::getQueue Dec 01 18:10:45 volumio volumio[901]: info: CorePlayQueue::getQueue Dec 01 18:10:45 volumio volumio[901]: info: CoreCommandRouter::volumioGetQueue Dec 01 18:10:45 volumio volumio[901]: info: CoreStateMachine::getQueue Dec 01 18:10:45 volumio volumio[901]: info: CorePlayQueue::getQueue Dec 01 18:10:45 volumio volumio[901]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Dec 01 18:10:45 volumio volumio[901]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Dec 01 18:10:45 volumio volumio[901]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Dec 01 18:10:45 volumio volumio[901]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Dec 01 18:10:45 volumio volumio[901]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Dec 01 18:10:45 volumio volumio[901]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 Dec 01 18:10:46 volumio kernel: hwmon hwmon1: Undervoltage detected! Dec 01 18:10:52 volumio kernel: hwmon hwmon1: Voltage normalised Dec 01 18:11:00 volumio volumio[901]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Dec 01 18:11:04 volumio volumio[901]: info: Preload queue cleared Dec 01 18:11:11 volumio kernel: hwmon hwmon1: Undervoltage detected! Dec 01 18:11:15 volumio kernel: hwmon hwmon1: Voltage normalised Dec 01 18:11:18 volumio volumio[901]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Dec 01 18:11:18 volumio volumio[901]: info: Preload queue cleared Dec 01 18:11:19 volumio kernel: hwmon hwmon1: Undervoltage detected! Dec 01 18:11:25 volumio kernel: hwmon hwmon1: Voltage normalised Dec 01 18:11:29 volumio volumio[901]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Dec 01 18:11:29 volumio volumio[901]: info: Preload queue cleared Dec 01 18:11:29 volumio volumio[901]: info: Preloading song: upnp/http://192.168.178.105:32469/ContentDirectory/7b58d976-c6f9-40f7-d1b0-54c9905d45f9/control.xml@f555605640bfc8a9def8 Dec 01 18:11:29 volumio volumio[901]: info: Preloading song: upnp/http://192.168.178.105:32469/ContentDirectory/7b58d976-c6f9-40f7-d1b0-54c9905d45f9/control.xml@778aab20d50b8a51d1c2 Dec 01 18:11:29 volumio volumio[901]: info: Preloading song: upnp/http://192.168.178.105:32469/ContentDirectory/7b58d976-c6f9-40f7-d1b0-54c9905d45f9/control.xml@3b8ff019e6258a97b6ef Dec 01 18:11:29 volumio volumio[901]: info: Preloading song: upnp/http://192.168.178.105:32469/ContentDirectory/7b58d976-c6f9-40f7-d1b0-54c9905d45f9/control.xml@241eecc8ce834bf07b53 Dec 01 18:11:29 volumio volumio[901]: info: Preloading song: upnp/http://192.168.178.105:32469/ContentDirectory/7b58d976-c6f9-40f7-d1b0-54c9905d45f9/control.xml@f8b3d513946930b16fa1 Dec 01 18:11:29 volumio volumio[901]: info: Preloading song: upnp/http://192.168.178.105:32469/ContentDirectory/7b58d976-c6f9-40f7-d1b0-54c9905d45f9/control.xml@8d5785f7c9293e169e4b Dec 01 18:11:29 volumio volumio[901]: info: Preloading song: upnp/http://192.168.178.105:32469/ContentDirectory/7b58d976-c6f9-40f7-d1b0-54c9905d45f9/control.xml@6f7ea84d36b00b452cba Dec 01 18:11:29 volumio volumio[901]: info: Exploding uri upnp/http://192.168.178.105:32469/ContentDirectory/7b58d976-c6f9-40f7-d1b0-54c9905d45f9/control.xml@f555605640bfc8a9def8 in service upnp_browser Dec 01 18:11:29 volumio volumio[901]: info: Exploding uri upnp/http://192.168.178.105:32469/ContentDirectory/7b58d976-c6f9-40f7-d1b0-54c9905d45f9/control.xml@778aab20d50b8a51d1c2 in service upnp_browser Dec 01 18:11:29 volumio volumio[901]: info: No valid Plugin REST Endpoint Dec 01 18:11:29 volumio volumio[901]: info: Exploding uri upnp/http://192.168.178.105:32469/ContentDirectory/7b58d976-c6f9-40f7-d1b0-54c9905d45f9/control.xml@3b8ff019e6258a97b6ef in service upnp_browser Dec 01 18:11:29 volumio volumio[901]: info: Exploding uri upnp/http://192.168.178.105:32469/ContentDirectory/7b58d976-c6f9-40f7-d1b0-54c9905d45f9/control.xml@241eecc8ce834bf07b53 in service upnp_browser Dec 01 18:11:29 volumio volumio[901]: info: Exploding uri upnp/http://192.168.178.105:32469/ContentDirectory/7b58d976-c6f9-40f7-d1b0-54c9905d45f9/control.xml@f8b3d513946930b16fa1 in service upnp_browser Dec 01 18:11:29 volumio volumio[901]: info: Exploding uri upnp/http://192.168.178.105:32469/ContentDirectory/7b58d976-c6f9-40f7-d1b0-54c9905d45f9/control.xml@8d5785f7c9293e169e4b in service upnp_browser Dec 01 18:11:29 volumio volumio[901]: info: Exploding uri upnp/http://192.168.178.105:32469/ContentDirectory/7b58d976-c6f9-40f7-d1b0-54c9905d45f9/control.xml@6f7ea84d36b00b452cba in service upnp_browser Dec 01 18:11:38 volumio volumio[901]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Dec 01 18:11:38 volumio volumio[901]: info: Preload queue cleared Dec 01 18:11:41 volumio volumio[901]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Dec 01 18:11:41 volumio volumio[901]: info: Preload queue cleared Dec 01 18:11:47 volumio volumio[901]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Dec 01 18:11:48 volumio volumio[901]: info: Preload queue cleared Dec 01 18:11:49 volumio volumio[901]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Dec 01 18:11:50 volumio volumio[901]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 01 18:11:50 volumio volumio[901]: TypeError: Cannot read property 'length' of undefined Dec 01 18:11:50 volumio volumio[901]: at /volumio/app/plugins/music_service/upnp_browser/index.js:341:25 Dec 01 18:11:50 volumio volumio[901]: at /volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:131:13 Dec 01 18:11:50 volumio volumio[901]: at Parser. (/volumio/node_modules/xml2js/lib/parser.js:304:18) Dec 01 18:11:50 volumio volumio[901]: at Parser.emit (events.js:315:20) Dec 01 18:11:50 volumio volumio[901]: at SAXParser.onclosetag (/volumio/node_modules/xml2js/lib/parser.js:262:26) Dec 01 18:11:50 volumio volumio[901]: at emit (/volumio/node_modules/sax/lib/sax.js:624:35) Dec 01 18:11:50 volumio volumio[901]: at emitNode (/volumio/node_modules/sax/lib/sax.js:629:5) Dec 01 18:11:50 volumio volumio[901]: at closeTag (/volumio/node_modules/sax/lib/sax.js:889:7) Dec 01 18:11:50 volumio volumio[901]: at SAXParser.write (/volumio/node_modules/sax/lib/sax.js:1436:13) Dec 01 18:11:50 volumio volumio[901]: at Parser.exports.Parser.Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:323:31) Dec 01 18:11:50 volumio volumio[901]: at Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:5:59) Dec 01 18:11:50 volumio volumio[901]: at Object.exports.parseString (/volumio/node_modules/xml2js/lib/parser.js:369:19) Dec 01 18:11:50 volumio volumio[901]: at IncomingMessage. (/volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:92:15) Dec 01 18:11:50 volumio volumio[901]: at IncomingMessage.emit (events.js:327:22) Dec 01 18:11:50 volumio volumio[901]: at endReadableNT (internal/streams/readable.js:1327:12) Dec 01 18:11:50 volumio volumio[901]: at processTicksAndRejections (internal/process/task_queues.js:80:21) Dec 01 18:11:50 volumio volumio[901]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 01 18:11:51 volumio sudo[1782]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-12-01 18:10 Dec 01 18:11:51 volumio sudo[1782]: 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"