-- Logs begin at Thu 2019-02-14 19:11:58 JST, end at Tue 2024-10-08 18:59:47 JST. -- Oct 08 18:58:00 tinkermio volumio[1173]: error: MyVolumio Custom Token format not valid, refreshing it Oct 08 18:58:00 tinkermio volumio[1173]: STREAMING PROXY: Starting server on port 3245 Oct 08 18:58:00 tinkermio volumio[1173]: Node JS runtime: 14 Oct 08 18:58:00 tinkermio volumio[1173]: info: MyVolumio login type: Token Oct 08 18:58:01 tinkermio volumio[1173]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Oct 08 18:58:01 tinkermio volumio[1173]: info: MyVolumio token set successfully Oct 08 18:58:01 tinkermio volumio[1173]: info: MYVOLUMIO: Adding device Oct 08 18:58:01 tinkermio volumio[1173]: info: MYVOLUMIO: Evaluating Server Oct 08 18:58:02 tinkermio volumio[1173]: info: MyVolumio status changed Oct 08 18:58:02 tinkermio volumio[1173]: info: Streaming services startup Oct 08 18:58:02 tinkermio volumio[1173]: info: Starting Streaming Daemon Oct 08 18:58:02 tinkermio volumio[1173]: info: Removing browser output: myVolumio user plan is not superstar Oct 08 18:58:02 tinkermio volumio[1173]: info: Removing audio output: Oct 08 18:58:02 tinkermio volumio[1173]: info: Stoppping Tunnel 1 Oct 08 18:58:02 tinkermio sudo[1736]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Oct 08 18:58:02 tinkermio sudo[1736]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 08 18:58:02 tinkermio sudo[1740]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Oct 08 18:58:02 tinkermio sudo[1740]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 08 18:58:02 tinkermio sudo[1736]: pam_unix(sudo:session): session closed for user root Oct 08 18:58:02 tinkermio volumio[1173]: error: Cannot start Volumio Streaming Daemon Oct 08 18:58:02 tinkermio volumio[1173]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Oct 08 18:58:02 tinkermio volumio[1173]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Oct 08 18:58:02 tinkermio sudo[1740]: pam_unix(sudo:session): session closed for user root Oct 08 18:58:02 tinkermio volumio[1173]: info: Remote SSH Stopped Oct 08 18:58:02 tinkermio volumio[1173]: info: Setting Geolocation for MyVolumio to as1 Oct 08 18:58:02 tinkermio volumio[1173]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 08 18:58:02 tinkermio volumio[1173]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 08 18:58:03 tinkermio volumio[1173]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Oct 08 18:58:03 tinkermio volumio[1173]: info: Updating MyVolumio device info Oct 08 18:58:03 tinkermio volumio[1173]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 08 18:58:04 tinkermio volumio[1173]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Oct 08 18:58:07 tinkermio volumio[1173]: info: MYVOLUMIO: Adding device Oct 08 18:58:07 tinkermio volumio[1173]: info: MYVOLUMIO: Evaluating Server Oct 08 18:58:07 tinkermio volumio[1173]: info: Setting Geolocation for MyVolumio to as1 Oct 08 18:58:07 tinkermio volumio[1173]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 08 18:58:07 tinkermio volumio[1173]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 08 18:58:07 tinkermio volumio[1173]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 08 18:58:08 tinkermio volumio[1173]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Oct 08 18:58:08 tinkermio volumio[1173]: info: Updating MyVolumio device info Oct 08 18:58:08 tinkermio volumio[1173]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 08 18:58:09 tinkermio volumio[1173]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Oct 08 18:58:12 tinkermio volumio[1643]: ............................................................................................................................................................................................................................................................................................................................................................................................................++++ Oct 08 18:58:14 tinkermio volumio[1173]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Oct 08 18:58:14 tinkermio volumio[1173]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 4 Oct 08 18:58:14 tinkermio volumio[1173]: info: CoreCommandRouter::volumioGetState Oct 08 18:58:14 tinkermio volumio[1173]: info: CorePlayQueue::getTrack 0 Oct 08 18:58:15 tinkermio volumio[1643]: .....................................................................++++ Oct 08 18:58:15 tinkermio volumio[1643]: e is 65537 (0x010001) Oct 08 18:58:16 tinkermio volumio[1643]: writing RSA key Oct 08 18:58:17 tinkermio volumio[1173]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 08 18:58:17 tinkermio volumio[1173]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 08 18:58:17 tinkermio volumio[1173]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Oct 08 18:58:18 tinkermio volumio-remote-updater[555]: No test mode Oct 08 18:58:18 tinkermio volumio-remote-updater[555]: No alpha test mode Oct 08 18:58:18 tinkermio volumio[1173]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Oct 08 18:58:18 tinkermio volumio[1173]: info: Update Ready: {"changeLogLink":"http://volumio.org","description":"

FIXES



 

NEW ADDITIONS



 

","title":"Update v3.757","updateavailable":true} Oct 08 18:58:18 tinkermio volumio[1173]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Oct 08 18:58:19 tinkermio volumio[1173]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 08 18:58:19 tinkermio volumio[1173]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 08 18:58:19 tinkermio volumio[1173]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Oct 08 18:58:19 tinkermio volumio[1173]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Oct 08 18:58:19 tinkermio volumio[1173]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Oct 08 18:58:19 tinkermio volumio[1173]: info: CoreCommandRouter::volumioGetBrowseSources Oct 08 18:58:19 tinkermio volumio[1173]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 08 18:58:19 tinkermio volumio[1173]: error: MyVolumio Plugin failed to authenticate in a timely fashion Oct 08 18:58:19 tinkermio volumio[1173]: info: Completed starting MyVolumio Plugin Oct 08 18:58:19 tinkermio volumio[1173]: info: BOOT COMPLETED Oct 08 18:58:19 tinkermio volumio[1173]: [Metrics] CommandRouter: 38s 952.37ms Oct 08 18:58:19 tinkermio volumio[1173]: info: CoreCommandRouter::volumiosetStartupVolume Oct 08 18:58:19 tinkermio volumio[1173]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 08 18:58:19 tinkermio volumio[1173]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 08 18:58:19 tinkermio volumio[1173]: info: CoreCommandRouter::Close All Modals sent Oct 08 18:58:19 tinkermio volumio[1173]: info: CoreCommandRouter::Close All Modals sent Oct 08 18:58:20 tinkermio volumio[1173]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Oct 08 18:58:20 tinkermio volumio[1173]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Oct 08 18:58:20 tinkermio volumio[1173]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Oct 08 18:58:37 tinkermio sudo[1831]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 08 18:58:37 tinkermio sudo[1834]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 08 18:58:37 tinkermio sudo[1831]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 08 18:58:37 tinkermio sudo[1834]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 08 18:58:37 tinkermio sudo[1831]: pam_unix(sudo:session): session closed for user root Oct 08 18:58:37 tinkermio sudo[1834]: pam_unix(sudo:session): session closed for user root Oct 08 18:58:38 tinkermio volumio[1173]: verbose: New Socket.io Connection to 192.168.1.20 from 192.168.1.168 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/129.0.0.0 Safari/537.36 Edg/129.0.0.0 Engine version: 3 Transport: polling Total Clients: 5 Oct 08 18:58:39 tinkermio sudo[1851]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 08 18:58:39 tinkermio sudo[1851]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 08 18:58:39 tinkermio sudo[1854]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 08 18:58:39 tinkermio sudo[1851]: pam_unix(sudo:session): session closed for user root Oct 08 18:58:39 tinkermio sudo[1854]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 08 18:58:39 tinkermio sudo[1854]: pam_unix(sudo:session): session closed for user root Oct 08 18:58:39 tinkermio volumio[1173]: verbose: New Socket.io Connection to 192.168.1.20 from 192.168.1.168 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/129.0.0.0 Safari/537.36 Edg/129.0.0.0 Engine version: 3 Transport: polling Total Clients: 6 Oct 08 18:58:39 tinkermio volumio[1173]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Oct 08 18:58:39 tinkermio volumio[1173]: info: CoreCommandRouter::volumioGetVisibleSources Oct 08 18:58:39 tinkermio volumio[1173]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 08 18:58:39 tinkermio volumio[1173]: info: CoreCommandRouter::volumioGetState Oct 08 18:58:39 tinkermio volumio[1173]: info: CorePlayQueue::getTrack 0 Oct 08 18:58:39 tinkermio volumio[1173]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Oct 08 18:58:39 tinkermio volumio[1173]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Oct 08 18:58:39 tinkermio volumio[1173]: info: Received Get System Info Oct 08 18:58:39 tinkermio volumio[1173]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 08 18:58:39 tinkermio volumio[1173]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 08 18:58:39 tinkermio volumio[1173]: info: Discovery: Getting this device information Oct 08 18:58:39 tinkermio volumio[1173]: info: CoreCommandRouter::volumioGetState Oct 08 18:58:39 tinkermio volumio[1173]: info: CorePlayQueue::getTrack 0 Oct 08 18:58:39 tinkermio volumio[1173]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 08 18:58:39 tinkermio volumio[1173]: info: CoreCommandRouter::volumioGetState Oct 08 18:58:39 tinkermio volumio[1173]: info: CorePlayQueue::getTrack 0 Oct 08 18:58:39 tinkermio volumio[1173]: info: Listing playlists Oct 08 18:58:39 tinkermio volumio[1173]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Oct 08 18:58:39 tinkermio volumio[1173]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Oct 08 18:58:41 tinkermio volumio[1173]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Oct 08 18:58:44 tinkermio volumio[1173]: info: CoreCommandRouter::volumioGetState Oct 08 18:58:44 tinkermio volumio[1173]: info: CorePlayQueue::getTrack 0 Oct 08 18:58:44 tinkermio volumio[1173]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 08 18:58:44 tinkermio volumio[1173]: info: Received Get System Info Oct 08 18:58:44 tinkermio volumio[1173]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 08 18:58:44 tinkermio volumio[1173]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 08 18:58:44 tinkermio volumio[1173]: info: Discovery: Getting this device information Oct 08 18:58:44 tinkermio volumio[1173]: info: CoreCommandRouter::volumioGetState Oct 08 18:58:44 tinkermio volumio[1173]: info: CorePlayQueue::getTrack 0 Oct 08 18:58:44 tinkermio volumio[1173]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 08 18:58:44 tinkermio volumio[1173]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Oct 08 18:58:44 tinkermio volumio[1173]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Oct 08 18:58:46 tinkermio volumio[1173]: info: CoreCommandRouter::volumioGetQueue Oct 08 18:58:46 tinkermio volumio[1173]: info: CoreStateMachine::getQueue Oct 08 18:58:46 tinkermio volumio[1173]: info: CorePlayQueue::getQueue Oct 08 18:58:48 tinkermio volumio[1173]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Oct 08 18:58:48 tinkermio volumio[1173]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Oct 08 18:58:48 tinkermio volumio[1173]: info: Received Get System Info Oct 08 18:58:48 tinkermio volumio[1173]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 08 18:58:48 tinkermio volumio[1173]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 08 18:58:48 tinkermio volumio[1173]: info: Discovery: Getting this device information Oct 08 18:58:48 tinkermio volumio[1173]: info: CoreCommandRouter::volumioGetState Oct 08 18:58:48 tinkermio volumio[1173]: info: CorePlayQueue::getTrack 0 Oct 08 18:58:48 tinkermio volumio[1173]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 08 18:58:49 tinkermio volumio[1173]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Oct 08 18:58:49 tinkermio volumio[1173]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Oct 08 18:58:51 tinkermio volumio[1173]: info: VolumeController::SetAlsaVolume29 Oct 08 18:58:51 tinkermio volumio[1173]: info: CoreCommandRouter::volumioGetState Oct 08 18:58:51 tinkermio volumio[1173]: info: CorePlayQueue::getTrack 0 Oct 08 18:58:51 tinkermio volumio[1173]: info: CoreStateMachine::pushState Oct 08 18:58:51 tinkermio volumio[1173]: info: CorePlayQueue::getTrack 0 Oct 08 18:58:51 tinkermio volumio[1173]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 08 18:58:51 tinkermio volumio[1173]: info: CoreCommandRouter::volumioPushState Oct 08 18:58:51 tinkermio volumio[1173]: SPOTIFY: RECEIVED VOLUMIO VOLUME 29 Oct 08 18:58:51 tinkermio volumio[1173]: SPOTIFY: SPOTIFY VOLUME 100 Oct 08 18:58:51 tinkermio volumio[1173]: SPOTIFY: VOLUMIO VOLUME 29 Oct 08 18:58:51 tinkermio volumio[1173]: SPOTIFY: DELTA VOLUME ENOUGH: true Oct 08 18:58:51 tinkermio volumio[1173]: info: Setting Spotify Volume from Volumio: 29 Oct 08 18:58:51 tinkermio volumio[1173]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: amixer: Unable to find simple control '',0 Oct 08 18:58:51 tinkermio volumio[1173]: info: VolumeController::SetAlsaVolume18 Oct 08 18:58:51 tinkermio volumio[1173]: info: CoreCommandRouter::volumioGetState Oct 08 18:58:51 tinkermio volumio[1173]: info: CorePlayQueue::getTrack 0 Oct 08 18:58:51 tinkermio volumio[1173]: info: CoreStateMachine::pushState Oct 08 18:58:51 tinkermio volumio[1173]: info: CorePlayQueue::getTrack 0 Oct 08 18:58:51 tinkermio volumio[1173]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 08 18:58:51 tinkermio volumio[1173]: info: CoreCommandRouter::volumioPushState Oct 08 18:58:51 tinkermio volumio[1173]: SPOTIFY: RECEIVED VOLUMIO VOLUME 18 Oct 08 18:58:51 tinkermio volumio[1173]: SPOTIFY: SPOTIFY VOLUME 29 Oct 08 18:58:51 tinkermio volumio[1173]: SPOTIFY: VOLUMIO VOLUME 18 Oct 08 18:58:51 tinkermio volumio[1173]: SPOTIFY: DELTA VOLUME ENOUGH: true Oct 08 18:58:51 tinkermio volumio[1173]: info: Setting Spotify Volume from Volumio: 18 Oct 08 18:58:51 tinkermio volumio[1173]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: amixer: Unable to find simple control '',0 Oct 08 18:58:53 tinkermio volumio[1173]: SPOTIFY: SETTING SPOTIFY VOLUME 18 Oct 08 18:58:53 tinkermio volumio[1173]: info: Sending Spotify command with payload to local API: /player/volume Oct 08 18:58:53 tinkermio go-librespot[1425]: time="2024-10-08T18:58:53+09:00" level=debug msg="update volume to 11796/65535" Oct 08 18:58:53 tinkermio go-librespot[1425]: time="2024-10-08T18:58:53+09:00" level=debug msg="put connect state because VOLUME_CHANGED" Oct 08 18:58:53 tinkermio go-librespot[1425]: time="2024-10-08T18:58:53+09:00" level=trace msg="emitting websocket event: volume" Oct 08 18:58:53 tinkermio volumio[1173]: SPOTIFY: received: {"type":"volume","data":{"value":18,"max":100}} Oct 08 18:58:53 tinkermio volumio[1173]: SPOTIFY: RECEIVED SPOTIFY VOLUME 18 Oct 08 18:58:54 tinkermio volumio[1173]: info: CoreCommandRouter::volumioPlay Oct 08 18:58:54 tinkermio volumio[1173]: info: CoreStateMachine::play index undefined Oct 08 18:58:54 tinkermio volumio[1173]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 08 18:58:54 tinkermio volumio[1173]: info: CorePlayQueue::getTrack 0 Oct 08 18:58:54 tinkermio volumio[1173]: info: CoreStateMachine::startPlaybackTimer Oct 08 18:58:54 tinkermio volumio[1173]: info: CorePlayQueue::getTrack 0 Oct 08 18:58:54 tinkermio volumio[1173]: info: [1728381534827] ControllerUPNPBrowser::clearAddPlayTrack Oct 08 18:58:54 tinkermio volumio[1173]: verbose: ControllerMpd::sendMpdCommand stop Oct 08 18:58:54 tinkermio volumio[1173]: info: sendMpdCommand stop took 1 milliseconds Oct 08 18:58:54 tinkermio volumio[1173]: verbose: ControllerMpd::sendMpdCommand clear Oct 08 18:58:54 tinkermio volumio[1173]: info: sendMpdCommand clear took 1 milliseconds Oct 08 18:58:54 tinkermio volumio[1173]: verbose: ControllerMpd::sendMpdCommand load "http://192.168.1.200:8200/MediaItems/34806.flac" Oct 08 18:58:54 tinkermio volumio[1173]: info: Oct 08 18:58:54 tinkermio volumio[1173]: ---------------------------- MPD announces system playlist update Oct 08 18:58:54 tinkermio volumio[1173]: info: Ignoring MPD Status Update Oct 08 18:58:54 tinkermio volumio[1173]: info: Oct 08 18:58:54 tinkermio volumio[1173]: ---------------------------- MPD announces system playlist update Oct 08 18:58:54 tinkermio volumio[1173]: info: Ignoring MPD Status Update Oct 08 18:58:54 tinkermio volumio[1173]: info: Oct 08 18:58:54 tinkermio volumio[1173]: ---------------------------- MPD announces system playlist update Oct 08 18:58:54 tinkermio volumio[1173]: info: Ignoring MPD Status Update Oct 08 18:58:54 tinkermio volumio[1173]: error: Upnp client error: Error: This socket has been ended by the other party Oct 08 18:58:55 tinkermio volumio[1173]: verbose: ControllerMpd::sendMpdCommand add "http://192.168.1.200:8200/MediaItems/34806.flac" Oct 08 18:58:55 tinkermio volumio[1173]: error: updateQueue error: null Oct 08 18:58:55 tinkermio volumio[1173]: error: updateQueue error: null Oct 08 18:58:55 tinkermio volumio[1173]: error: updateQueue error: null Oct 08 18:58:55 tinkermio volumio[1173]: info: ------------------------------ 239ms Oct 08 18:58:55 tinkermio volumio[1173]: info: ------------------------------ 237ms Oct 08 18:58:55 tinkermio volumio[1173]: info: ------------------------------ 236ms Oct 08 18:58:55 tinkermio volumio[1173]: info: Oct 08 18:58:55 tinkermio volumio[1173]: ---------------------------- MPD announces system playlist update Oct 08 18:58:55 tinkermio volumio[1173]: info: Ignoring MPD Status Update Oct 08 18:58:55 tinkermio volumio[1173]: info: sendMpdCommand add "http://192.168.1.200:8200/MediaItems/34806.flac" took 3 milliseconds Oct 08 18:58:55 tinkermio volumio[1173]: info: CoreStateMachine::setConsumeUpdateService mpd Oct 08 18:58:55 tinkermio volumio[1173]: verbose: ControllerMpd::sendMpdCommand play Oct 08 18:58:55 tinkermio volumio[1173]: info: Oct 08 18:58:55 tinkermio volumio[1173]: ---------------------------- MPD announces system playlist update Oct 08 18:58:55 tinkermio volumio[1173]: info: Ignoring MPD Status Update Oct 08 18:58:55 tinkermio volumio[1173]: info: Oct 08 18:58:55 tinkermio volumio[1173]: ---------------------------- MPD announces system playlist update Oct 08 18:58:55 tinkermio volumio[1173]: info: Ignoring MPD Status Update Oct 08 18:58:55 tinkermio volumio[1173]: info: ------------------------------ 6ms Oct 08 18:58:55 tinkermio volumio[1173]: info: sendMpdCommand play took 5 milliseconds Oct 08 18:58:55 tinkermio volumio[1173]: info: ------------------------------ 5ms Oct 08 18:58:55 tinkermio volumio[1173]: info: ------------------------------ 4ms Oct 08 18:58:55 tinkermio volumio[1173]: info: Oct 08 18:58:55 tinkermio volumio[1173]: ---------------------------- MPD announces state update: player Oct 08 18:58:55 tinkermio volumio[1173]: info: ControllerMpd::getState Oct 08 18:58:55 tinkermio volumio[1173]: verbose: ControllerMpd::sendMpdCommand status Oct 08 18:58:55 tinkermio volumio[1173]: info: Oct 08 18:58:55 tinkermio volumio[1173]: ---------------------------- MPD announces state update: player Oct 08 18:58:55 tinkermio volumio[1173]: info: ControllerMpd::getState Oct 08 18:58:55 tinkermio volumio[1173]: verbose: ControllerMpd::sendMpdCommand status Oct 08 18:58:55 tinkermio volumio[1173]: info: Oct 08 18:58:55 tinkermio volumio[1173]: ---------------------------- MPD announces state update: player Oct 08 18:58:55 tinkermio volumio[1173]: info: ControllerMpd::getState Oct 08 18:58:55 tinkermio volumio[1173]: verbose: ControllerMpd::sendMpdCommand status Oct 08 18:58:55 tinkermio volumio[1173]: info: Oct 08 18:58:55 tinkermio volumio[1173]: ---------------------------- MPD announces state update: player Oct 08 18:58:55 tinkermio volumio[1173]: info: sendMpdCommand status took 5 milliseconds Oct 08 18:58:55 tinkermio volumio[1173]: info: ControllerMpd::getState Oct 08 18:58:55 tinkermio volumio[1173]: verbose: ControllerMpd::sendMpdCommand status Oct 08 18:58:55 tinkermio volumio[1173]: info: sendMpdCommand status took 4 milliseconds Oct 08 18:58:55 tinkermio volumio[1173]: verbose: ControllerMpd::parseState Oct 08 18:58:55 tinkermio volumio[1173]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 08 18:58:55 tinkermio volumio[1173]: verbose: ControllerMpd::parseState Oct 08 18:58:55 tinkermio volumio[1173]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 08 18:58:55 tinkermio volumio[1173]: info: Oct 08 18:58:55 tinkermio volumio[1173]: ---------------------------- MPD announces state update: player Oct 08 18:58:55 tinkermio volumio[1173]: info: ControllerMpd::getState Oct 08 18:58:55 tinkermio volumio[1173]: verbose: ControllerMpd::sendMpdCommand status Oct 08 18:58:55 tinkermio volumio[1173]: info: sendMpdCommand status took 7 milliseconds Oct 08 18:58:55 tinkermio volumio[1173]: info: sendMpdCommand status took 4 milliseconds Oct 08 18:58:55 tinkermio volumio[1173]: info: sendMpdCommand playlistinfo took 4 milliseconds Oct 08 18:58:55 tinkermio volumio[1173]: info: sendMpdCommand playlistinfo took 3 milliseconds Oct 08 18:58:55 tinkermio volumio[1173]: info: sendMpdCommand status took 2 milliseconds Oct 08 18:58:55 tinkermio volumio[1173]: verbose: ControllerMpd::parseState Oct 08 18:58:55 tinkermio volumio[1173]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 08 18:58:55 tinkermio volumio[1173]: verbose: ControllerMpd::parseState Oct 08 18:58:55 tinkermio volumio[1173]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 08 18:58:55 tinkermio volumio[1173]: verbose: ControllerMpd::parseTrackInfo Oct 08 18:58:55 tinkermio volumio[1173]: verbose: ControllerMpd::parseTrackInfo Oct 08 18:58:55 tinkermio volumio[1173]: verbose: ControllerMpd::parseState Oct 08 18:58:55 tinkermio volumio[1173]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 08 18:58:55 tinkermio volumio[1173]: info: ControllerMpd::pushState Oct 08 18:58:55 tinkermio volumio[1173]: info: CoreCommandRouter::servicePushState Oct 08 18:58:55 tinkermio volumio[1173]: info: CorePlayQueue::getTrack 0 Oct 08 18:58:55 tinkermio volumio[1173]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":221,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"34806.flac","artist":null,"album":null,"uri":"http://192.168.1.200:8200/MediaItems/34806.flac","trackType":"flac"} Oct 08 18:58:55 tinkermio volumio[1173]: verbose: CURRENT POSITION 0 Oct 08 18:58:55 tinkermio volumio[1173]: info: CoreStateMachine::syncState stateService play Oct 08 18:58:55 tinkermio volumio[1173]: info: CoreStateMachine::syncState currentStatus stop Oct 08 18:58:55 tinkermio volumio[1173]: info: ControllerMpd::pushState Oct 08 18:58:55 tinkermio volumio[1173]: info: CoreCommandRouter::servicePushState Oct 08 18:58:55 tinkermio volumio[1173]: info: CorePlayQueue::getTrack 0 Oct 08 18:58:55 tinkermio volumio[1173]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":221,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"34806.flac","artist":null,"album":null,"uri":"http://192.168.1.200:8200/MediaItems/34806.flac","trackType":"flac"} Oct 08 18:58:55 tinkermio volumio[1173]: verbose: CURRENT POSITION 0 Oct 08 18:58:55 tinkermio volumio[1173]: info: CoreStateMachine::syncState stateService play Oct 08 18:58:55 tinkermio volumio[1173]: info: CoreStateMachine::syncState currentStatus play Oct 08 18:58:55 tinkermio volumio[1173]: info: Received an update from plugin. extracting info from payload Oct 08 18:58:55 tinkermio volumio[1173]: info: CoreStateMachine::pushState Oct 08 18:58:55 tinkermio volumio[1173]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 08 18:58:55 tinkermio volumio[1173]: info: CoreCommandRouter::volumioPushState Oct 08 18:58:55 tinkermio volumio[1173]: info: CoreStateMachine::pushState Oct 08 18:58:55 tinkermio volumio[1173]: info: CoreCommandRouter::volumioPushState Oct 08 18:58:55 tinkermio volumio[1173]: info: ------------------------------ 30ms Oct 08 18:58:55 tinkermio volumio[1173]: info: ------------------------------ 34ms Oct 08 18:58:55 tinkermio volumio[1173]: info: Oct 08 18:58:55 tinkermio volumio[1173]: ---------------------------- MPD announces state update: player Oct 08 18:58:55 tinkermio volumio[1173]: info: ControllerMpd::getState Oct 08 18:58:55 tinkermio volumio[1173]: verbose: ControllerMpd::sendMpdCommand status Oct 08 18:58:55 tinkermio volumio[1173]: info: sendMpdCommand playlistinfo took 26 milliseconds Oct 08 18:58:55 tinkermio volumio[1173]: info: sendMpdCommand playlistinfo took 26 milliseconds Oct 08 18:58:55 tinkermio volumio[1173]: info: sendMpdCommand playlistinfo took 25 milliseconds Oct 08 18:58:55 tinkermio volumio[1173]: verbose: ControllerMpd::parseTrackInfo Oct 08 18:58:55 tinkermio volumio[1173]: verbose: ControllerMpd::parseTrackInfo Oct 08 18:58:55 tinkermio volumio[1173]: verbose: ControllerMpd::parseTrackInfo Oct 08 18:58:55 tinkermio volumio[1173]: info: ControllerMpd::pushState Oct 08 18:58:55 tinkermio volumio[1173]: info: CoreCommandRouter::servicePushState Oct 08 18:58:55 tinkermio volumio[1173]: info: CorePlayQueue::getTrack 0 Oct 08 18:58:55 tinkermio volumio[1173]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":221,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"34806.flac","artist":null,"album":null,"uri":"http://192.168.1.200:8200/MediaItems/34806.flac","trackType":"flac"} Oct 08 18:58:55 tinkermio volumio[1173]: verbose: CURRENT POSITION 0 Oct 08 18:58:55 tinkermio volumio[1173]: info: CoreStateMachine::syncState stateService play Oct 08 18:58:55 tinkermio volumio[1173]: info: CoreStateMachine::syncState currentStatus play Oct 08 18:58:55 tinkermio volumio[1173]: info: Received an update from plugin. extracting info from payload Oct 08 18:58:55 tinkermio volumio[1173]: info: CoreStateMachine::pushState Oct 08 18:58:55 tinkermio volumio[1173]: info: CoreCommandRouter::volumioPushState Oct 08 18:58:55 tinkermio volumio[1173]: info: CoreStateMachine::pushState Oct 08 18:58:55 tinkermio volumio[1173]: info: CoreCommandRouter::volumioPushState Oct 08 18:58:55 tinkermio volumio[1173]: info: ControllerMpd::pushState Oct 08 18:58:55 tinkermio volumio[1173]: info: CoreCommandRouter::servicePushState Oct 08 18:58:55 tinkermio volumio[1173]: info: CorePlayQueue::getTrack 0 Oct 08 18:58:55 tinkermio volumio[1173]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":221,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"34806.flac","artist":null,"album":null,"uri":"http://192.168.1.200:8200/MediaItems/34806.flac","trackType":"flac"} Oct 08 18:58:55 tinkermio volumio[1173]: verbose: CURRENT POSITION 0 Oct 08 18:58:55 tinkermio volumio[1173]: info: CoreStateMachine::syncState stateService play Oct 08 18:58:55 tinkermio volumio[1173]: info: CoreStateMachine::syncState currentStatus play Oct 08 18:58:55 tinkermio volumio[1173]: info: Received an update from plugin. extracting info from payload Oct 08 18:58:55 tinkermio volumio[1173]: info: CoreStateMachine::pushState Oct 08 18:58:55 tinkermio volumio[1173]: info: CoreCommandRouter::volumioPushState Oct 08 18:58:55 tinkermio volumio[1173]: info: CoreStateMachine::pushState Oct 08 18:58:55 tinkermio volumio[1173]: info: CoreCommandRouter::volumioPushState Oct 08 18:58:55 tinkermio volumio[1173]: info: ControllerMpd::pushState Oct 08 18:58:55 tinkermio volumio[1173]: info: CoreCommandRouter::servicePushState Oct 08 18:58:55 tinkermio volumio[1173]: info: CorePlayQueue::getTrack 0 Oct 08 18:58:55 tinkermio volumio[1173]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":221,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"34806.flac","artist":null,"album":null,"uri":"http://192.168.1.200:8200/MediaItems/34806.flac","trackType":"flac"} Oct 08 18:58:55 tinkermio volumio[1173]: verbose: CURRENT POSITION 0 Oct 08 18:58:55 tinkermio volumio[1173]: info: CoreStateMachine::syncState stateService play Oct 08 18:58:55 tinkermio volumio[1173]: info: CoreStateMachine::syncState currentStatus play Oct 08 18:58:55 tinkermio volumio[1173]: info: Received an update from plugin. extracting info from payload Oct 08 18:58:55 tinkermio volumio[1173]: info: CoreStateMachine::pushState Oct 08 18:58:55 tinkermio volumio[1173]: info: CoreCommandRouter::volumioPushState Oct 08 18:58:55 tinkermio volumio[1173]: info: CoreStateMachine::pushState Oct 08 18:58:55 tinkermio volumio[1173]: info: CoreCommandRouter::volumioPushState Oct 08 18:58:55 tinkermio volumio[1173]: info: ------------------------------ 77ms Oct 08 18:58:55 tinkermio volumio[1173]: info: ------------------------------ 76ms Oct 08 18:58:55 tinkermio volumio[1173]: info: ------------------------------ 71ms Oct 08 18:58:55 tinkermio volumio[1173]: SPOTIFY: RECEIVED VOLUMIO VOLUME 18 Oct 08 18:58:55 tinkermio volumio[1173]: SPOTIFY: RECEIVED VOLUMIO VOLUME 18 Oct 08 18:58:55 tinkermio volumio[1173]: SPOTIFY: RECEIVED VOLUMIO VOLUME 18 Oct 08 18:58:55 tinkermio volumio[1173]: SPOTIFY: RECEIVED VOLUMIO VOLUME 18 Oct 08 18:58:55 tinkermio volumio[1173]: SPOTIFY: RECEIVED VOLUMIO VOLUME 18 Oct 08 18:58:55 tinkermio volumio[1173]: SPOTIFY: RECEIVED VOLUMIO VOLUME 18 Oct 08 18:58:55 tinkermio volumio[1173]: SPOTIFY: RECEIVED VOLUMIO VOLUME 18 Oct 08 18:58:55 tinkermio volumio[1173]: SPOTIFY: RECEIVED VOLUMIO VOLUME 18 Oct 08 18:58:55 tinkermio volumio[1173]: info: Oct 08 18:58:55 tinkermio volumio[1173]: ---------------------------- MPD announces system playlist update Oct 08 18:58:55 tinkermio volumio[1173]: info: Ignoring MPD Status Update Oct 08 18:58:55 tinkermio volumio[1173]: info: Oct 08 18:58:55 tinkermio volumio[1173]: ---------------------------- MPD announces state update: player Oct 08 18:58:55 tinkermio volumio[1173]: info: sendMpdCommand status took 60 milliseconds Oct 08 18:58:55 tinkermio volumio[1173]: info: ControllerMpd::getState Oct 08 18:58:55 tinkermio volumio[1173]: verbose: ControllerMpd::sendMpdCommand status Oct 08 18:58:55 tinkermio volumio[1173]: verbose: ControllerMpd::parseState Oct 08 18:58:55 tinkermio volumio[1173]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 08 18:58:55 tinkermio volumio[1173]: info: Oct 08 18:58:55 tinkermio volumio[1173]: ---------------------------- MPD announces system playlist update Oct 08 18:58:55 tinkermio volumio[1173]: info: Ignoring MPD Status Update Oct 08 18:58:55 tinkermio volumio[1173]: info: Oct 08 18:58:55 tinkermio volumio[1173]: ---------------------------- MPD announces state update: player Oct 08 18:58:55 tinkermio volumio[1173]: info: ControllerMpd::getState Oct 08 18:58:55 tinkermio volumio[1173]: verbose: ControllerMpd::sendMpdCommand status Oct 08 18:58:55 tinkermio volumio[1173]: info: Oct 08 18:58:55 tinkermio volumio[1173]: ---------------------------- MPD announces system playlist update Oct 08 18:58:55 tinkermio volumio[1173]: info: Ignoring MPD Status Update Oct 08 18:58:55 tinkermio volumio[1173]: info: Oct 08 18:58:55 tinkermio volumio[1173]: ---------------------------- MPD announces state update: player Oct 08 18:58:55 tinkermio volumio[1173]: info: ControllerMpd::getState Oct 08 18:58:55 tinkermio volumio[1173]: verbose: ControllerMpd::sendMpdCommand status Oct 08 18:58:55 tinkermio volumio[1173]: info: ------------------------------ 14ms Oct 08 18:58:55 tinkermio volumio[1173]: info: sendMpdCommand status took 12 milliseconds Oct 08 18:58:55 tinkermio volumio[1173]: info: sendMpdCommand playlistinfo took 13 milliseconds Oct 08 18:58:55 tinkermio volumio[1173]: info: ------------------------------ 12ms Oct 08 18:58:55 tinkermio volumio[1173]: info: sendMpdCommand status took 11 milliseconds Oct 08 18:58:55 tinkermio volumio[1173]: info: ------------------------------ 10ms Oct 08 18:58:55 tinkermio volumio[1173]: info: sendMpdCommand status took 10 milliseconds Oct 08 18:58:55 tinkermio volumio[1173]: verbose: ControllerMpd::parseState Oct 08 18:58:55 tinkermio volumio[1173]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 08 18:58:55 tinkermio volumio[1173]: verbose: ControllerMpd::parseTrackInfo Oct 08 18:58:55 tinkermio volumio[1173]: verbose: ControllerMpd::parseState Oct 08 18:58:55 tinkermio volumio[1173]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 08 18:58:55 tinkermio volumio[1173]: verbose: ControllerMpd::parseState Oct 08 18:58:55 tinkermio volumio[1173]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 08 18:58:55 tinkermio volumio[1173]: info: ControllerMpd::pushState Oct 08 18:58:55 tinkermio volumio[1173]: info: CoreCommandRouter::servicePushState Oct 08 18:58:55 tinkermio volumio[1173]: info: CorePlayQueue::getTrack 0 Oct 08 18:58:55 tinkermio volumio[1173]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":221,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"More One Night","artist":"チト(CV:水瀬いのり)、ユーリ(CV:久保ユリカ)","album":"More One Night","uri":"http://192.168.1.200:8200/MediaItems/34806.flac","trackType":"flac"} Oct 08 18:58:55 tinkermio volumio[1173]: verbose: CURRENT POSITION 0 Oct 08 18:58:55 tinkermio volumio[1173]: info: CoreStateMachine::syncState stateService play Oct 08 18:58:55 tinkermio volumio[1173]: info: CoreStateMachine::syncState currentStatus play Oct 08 18:58:55 tinkermio volumio[1173]: info: Received an update from plugin. extracting info from payload Oct 08 18:58:55 tinkermio volumio[1173]: info: CoreStateMachine::pushState Oct 08 18:58:55 tinkermio volumio[1173]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 08 18:58:55 tinkermio volumio[1173]: info: CoreCommandRouter::volumioPushState Oct 08 18:58:55 tinkermio volumio[1173]: info: CoreStateMachine::pushState Oct 08 18:58:55 tinkermio volumio[1173]: info: CoreCommandRouter::volumioPushState Oct 08 18:58:55 tinkermio volumio[1173]: info: ------------------------------ 95ms Oct 08 18:58:55 tinkermio volumio[1173]: info: sendMpdCommand playlistinfo took 23 milliseconds Oct 08 18:58:55 tinkermio volumio[1173]: info: sendMpdCommand playlistinfo took 22 milliseconds Oct 08 18:58:55 tinkermio volumio[1173]: info: sendMpdCommand playlistinfo took 22 milliseconds Oct 08 18:58:55 tinkermio volumio[1173]: verbose: ControllerMpd::parseTrackInfo Oct 08 18:58:55 tinkermio volumio[1173]: verbose: ControllerMpd::parseTrackInfo Oct 08 18:58:55 tinkermio volumio[1173]: verbose: ControllerMpd::parseTrackInfo Oct 08 18:58:55 tinkermio volumio[1173]: info: ControllerMpd::pushState Oct 08 18:58:55 tinkermio volumio[1173]: info: CoreCommandRouter::servicePushState Oct 08 18:58:55 tinkermio volumio[1173]: info: CorePlayQueue::getTrack 0 Oct 08 18:58:55 tinkermio volumio[1173]: verbose: STATE SERVICE {"status":"play","position":0,"seek":846,"duration":221,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1176 Kbps","isStreaming":false,"title":"More One Night","artist":"チト(CV:水瀬いのり)、ユーリ(CV:久保ユリカ)","album":"More One Night","uri":"http://192.168.1.200:8200/MediaItems/34806.flac","trackType":"flac"} Oct 08 18:58:55 tinkermio volumio[1173]: verbose: CURRENT POSITION 0 Oct 08 18:58:55 tinkermio volumio[1173]: info: CoreStateMachine::syncState stateService play Oct 08 18:58:55 tinkermio volumio[1173]: info: CoreStateMachine::syncState currentStatus play Oct 08 18:58:55 tinkermio volumio[1173]: info: Received an update from plugin. extracting info from payload Oct 08 18:58:55 tinkermio volumio[1173]: info: CoreStateMachine::pushState Oct 08 18:58:55 tinkermio volumio[1173]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 08 18:58:55 tinkermio volumio[1173]: info: CoreCommandRouter::volumioPushState Oct 08 18:58:55 tinkermio volumio[1173]: info: CoreStateMachine::pushState Oct 08 18:58:55 tinkermio volumio[1173]: info: CoreCommandRouter::volumioPushState Oct 08 18:58:55 tinkermio volumio[1173]: info: ControllerMpd::pushState Oct 08 18:58:55 tinkermio volumio[1173]: info: CoreCommandRouter::servicePushState Oct 08 18:58:55 tinkermio volumio[1173]: info: CorePlayQueue::getTrack 0 Oct 08 18:58:55 tinkermio volumio[1173]: verbose: STATE SERVICE {"status":"play","position":0,"seek":846,"duration":221,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1176 Kbps","isStreaming":false,"title":"More One Night","artist":"チト(CV:水瀬いのり)、ユーリ(CV:久保ユリカ)","album":"More One Night","uri":"http://192.168.1.200:8200/MediaItems/34806.flac","trackType":"flac"} Oct 08 18:58:55 tinkermio volumio[1173]: verbose: CURRENT POSITION 0 Oct 08 18:58:55 tinkermio volumio[1173]: info: CoreStateMachine::syncState stateService play Oct 08 18:58:55 tinkermio volumio[1173]: info: CoreStateMachine::syncState currentStatus play Oct 08 18:58:55 tinkermio volumio[1173]: info: Received an update from plugin. extracting info from payload Oct 08 18:58:55 tinkermio volumio[1173]: info: CoreStateMachine::pushState Oct 08 18:58:55 tinkermio volumio[1173]: info: CoreCommandRouter::volumioPushState Oct 08 18:58:55 tinkermio volumio[1173]: info: CoreStateMachine::pushState Oct 08 18:58:55 tinkermio volumio[1173]: info: CoreCommandRouter::volumioPushState Oct 08 18:58:55 tinkermio volumio[1173]: info: ControllerMpd::pushState Oct 08 18:58:55 tinkermio volumio[1173]: info: CoreCommandRouter::servicePushState Oct 08 18:58:55 tinkermio volumio[1173]: info: CorePlayQueue::getTrack 0 Oct 08 18:58:55 tinkermio volumio[1173]: verbose: STATE SERVICE {"status":"play","position":0,"seek":846,"duration":221,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1176 Kbps","isStreaming":false,"title":"More One Night","artist":"チト(CV:水瀬いのり)、ユーリ(CV:久保ユリカ)","album":"More One Night","uri":"http://192.168.1.200:8200/MediaItems/34806.flac","trackType":"flac"} Oct 08 18:58:55 tinkermio volumio[1173]: verbose: CURRENT POSITION 0 Oct 08 18:58:55 tinkermio volumio[1173]: info: CoreStateMachine::syncState stateService play Oct 08 18:58:55 tinkermio volumio[1173]: info: CoreStateMachine::syncState currentStatus play Oct 08 18:58:55 tinkermio volumio[1173]: info: Received an update from plugin. extracting info from payload Oct 08 18:58:55 tinkermio volumio[1173]: info: CoreStateMachine::pushState Oct 08 18:58:55 tinkermio volumio[1173]: info: CoreCommandRouter::volumioPushState Oct 08 18:58:55 tinkermio volumio[1173]: info: CoreStateMachine::pushState Oct 08 18:58:55 tinkermio volumio[1173]: info: CoreCommandRouter::volumioPushState Oct 08 18:58:55 tinkermio volumio[1173]: info: ------------------------------ 79ms Oct 08 18:58:55 tinkermio volumio[1173]: info: ------------------------------ 76ms Oct 08 18:58:55 tinkermio volumio[1173]: info: ------------------------------ 76ms Oct 08 18:58:55 tinkermio volumio[1173]: info: CoreCommandRouter::volumioGetState Oct 08 18:58:55 tinkermio volumio[1173]: info: CoreCommandRouter::volumioGetQueue Oct 08 18:58:55 tinkermio volumio[1173]: info: CoreStateMachine::getQueue Oct 08 18:58:55 tinkermio volumio[1173]: info: CorePlayQueue::getQueue Oct 08 18:58:55 tinkermio volumio[1173]: info: CoreCommandRouter::volumioGetQueue Oct 08 18:58:55 tinkermio volumio[1173]: info: CoreStateMachine::getQueue Oct 08 18:58:55 tinkermio volumio[1173]: info: CorePlayQueue::getQueue Oct 08 18:58:55 tinkermio volumio[1173]: info: CoreCommandRouter::volumioGetQueue Oct 08 18:58:55 tinkermio volumio[1173]: info: CoreStateMachine::getQueue Oct 08 18:58:55 tinkermio volumio[1173]: info: CorePlayQueue::getQueue Oct 08 18:58:55 tinkermio volumio[1173]: info: CoreCommandRouter::volumioGetQueue Oct 08 18:58:55 tinkermio volumio[1173]: info: CoreStateMachine::getQueue Oct 08 18:58:55 tinkermio volumio[1173]: info: CorePlayQueue::getQueue Oct 08 18:58:55 tinkermio volumio[1173]: info: CoreCommandRouter::volumioGetQueue Oct 08 18:58:55 tinkermio volumio[1173]: info: CoreStateMachine::getQueue Oct 08 18:58:55 tinkermio volumio[1173]: info: CorePlayQueue::getQueue Oct 08 18:58:55 tinkermio volumio[1173]: info: CoreCommandRouter::volumioGetQueue Oct 08 18:58:55 tinkermio volumio[1173]: info: CoreStateMachine::getQueue Oct 08 18:58:55 tinkermio volumio[1173]: info: CorePlayQueue::getQueue Oct 08 18:58:55 tinkermio volumio[1173]: info: CoreCommandRouter::volumioGetQueue Oct 08 18:58:55 tinkermio volumio[1173]: info: CoreStateMachine::getQueue Oct 08 18:58:55 tinkermio volumio[1173]: info: CorePlayQueue::getQueue Oct 08 18:58:55 tinkermio volumio[1173]: info: CoreCommandRouter::volumioGetQueue Oct 08 18:58:55 tinkermio volumio[1173]: info: CoreStateMachine::getQueue Oct 08 18:58:55 tinkermio volumio[1173]: info: CorePlayQueue::getQueue Oct 08 18:58:55 tinkermio volumio[1173]: SPOTIFY: RECEIVED VOLUMIO VOLUME 18 Oct 08 18:58:55 tinkermio volumio[1173]: SPOTIFY: RECEIVED VOLUMIO VOLUME 18 Oct 08 18:58:55 tinkermio volumio[1173]: SPOTIFY: RECEIVED VOLUMIO VOLUME 18 Oct 08 18:58:55 tinkermio volumio[1173]: SPOTIFY: RECEIVED VOLUMIO VOLUME 18 Oct 08 18:58:55 tinkermio volumio[1173]: SPOTIFY: RECEIVED VOLUMIO VOLUME 18 Oct 08 18:58:55 tinkermio volumio[1173]: SPOTIFY: RECEIVED VOLUMIO VOLUME 18 Oct 08 18:58:55 tinkermio volumio[1173]: SPOTIFY: RECEIVED VOLUMIO VOLUME 18 Oct 08 18:58:55 tinkermio volumio[1173]: SPOTIFY: RECEIVED VOLUMIO VOLUME 18 Oct 08 18:58:58 tinkermio volumio[1173]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Oct 08 18:58:58 tinkermio volumio[1173]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Oct 08 18:58:58 tinkermio volumio[1173]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Oct 08 18:58:58 tinkermio volumio[1173]: info: Received Get System Version Oct 08 18:58:58 tinkermio volumio[1173]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Oct 08 18:58:58 tinkermio volumio[1173]: info: Received Get System Info Oct 08 18:58:58 tinkermio volumio[1173]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 08 18:58:58 tinkermio volumio[1173]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 08 18:58:58 tinkermio volumio[1173]: info: Discovery: Getting this device information Oct 08 18:58:58 tinkermio volumio[1173]: info: CoreCommandRouter::volumioGetState Oct 08 18:58:58 tinkermio volumio[1173]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 08 18:59:17 tinkermio volumio[1173]: info: VolumeController::SetAlsaVolume17 Oct 08 18:59:17 tinkermio volumio[1173]: info: CoreCommandRouter::volumioGetState Oct 08 18:59:17 tinkermio volumio[1173]: info: CoreStateMachine::pushState Oct 08 18:59:17 tinkermio volumio[1173]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 08 18:59:17 tinkermio volumio[1173]: info: CoreCommandRouter::volumioPushState Oct 08 18:59:17 tinkermio volumio[1173]: info: CoreCommandRouter::volumioGetQueue Oct 08 18:59:17 tinkermio volumio[1173]: info: CoreStateMachine::getQueue Oct 08 18:59:17 tinkermio volumio[1173]: info: CorePlayQueue::getQueue Oct 08 18:59:17 tinkermio volumio[1173]: SPOTIFY: RECEIVED VOLUMIO VOLUME 17 Oct 08 18:59:17 tinkermio volumio[1173]: SPOTIFY: SPOTIFY VOLUME 18 Oct 08 18:59:17 tinkermio volumio[1173]: SPOTIFY: VOLUMIO VOLUME 17 Oct 08 18:59:17 tinkermio volumio[1173]: SPOTIFY: DELTA VOLUME ENOUGH: false Oct 08 18:59:17 tinkermio volumio[1173]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: amixer: Unable to find simple control '',0 Oct 08 18:59:17 tinkermio volumio[1173]: info: VolumeController::SetAlsaVolume16 Oct 08 18:59:17 tinkermio volumio[1173]: info: CoreCommandRouter::volumioGetState Oct 08 18:59:17 tinkermio volumio[1173]: info: CoreStateMachine::pushState Oct 08 18:59:17 tinkermio volumio[1173]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 08 18:59:17 tinkermio volumio[1173]: info: CoreCommandRouter::volumioPushState Oct 08 18:59:17 tinkermio volumio[1173]: info: CoreCommandRouter::volumioGetQueue Oct 08 18:59:17 tinkermio volumio[1173]: info: CoreStateMachine::getQueue Oct 08 18:59:17 tinkermio volumio[1173]: info: CorePlayQueue::getQueue Oct 08 18:59:17 tinkermio volumio[1173]: SPOTIFY: RECEIVED VOLUMIO VOLUME 16 Oct 08 18:59:17 tinkermio volumio[1173]: SPOTIFY: SPOTIFY VOLUME 18 Oct 08 18:59:17 tinkermio volumio[1173]: SPOTIFY: VOLUMIO VOLUME 16 Oct 08 18:59:17 tinkermio volumio[1173]: SPOTIFY: DELTA VOLUME ENOUGH: true Oct 08 18:59:17 tinkermio volumio[1173]: info: Setting Spotify Volume from Volumio: 16 Oct 08 18:59:17 tinkermio volumio[1173]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: amixer: Unable to find simple control '',0 Oct 08 18:59:17 tinkermio volumio[1173]: info: VolumeController::SetAlsaVolume14 Oct 08 18:59:17 tinkermio volumio[1173]: info: CoreCommandRouter::volumioGetState Oct 08 18:59:17 tinkermio volumio[1173]: info: CoreStateMachine::pushState Oct 08 18:59:17 tinkermio volumio[1173]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 08 18:59:17 tinkermio volumio[1173]: info: CoreCommandRouter::volumioPushState Oct 08 18:59:17 tinkermio volumio[1173]: info: CoreCommandRouter::volumioGetQueue Oct 08 18:59:17 tinkermio volumio[1173]: info: CoreStateMachine::getQueue Oct 08 18:59:17 tinkermio volumio[1173]: info: CorePlayQueue::getQueue Oct 08 18:59:17 tinkermio volumio[1173]: SPOTIFY: RECEIVED VOLUMIO VOLUME 14 Oct 08 18:59:17 tinkermio volumio[1173]: SPOTIFY: SPOTIFY VOLUME 16 Oct 08 18:59:17 tinkermio volumio[1173]: SPOTIFY: VOLUMIO VOLUME 14 Oct 08 18:59:17 tinkermio volumio[1173]: SPOTIFY: DELTA VOLUME ENOUGH: true Oct 08 18:59:17 tinkermio volumio[1173]: info: Setting Spotify Volume from Volumio: 14 Oct 08 18:59:17 tinkermio volumio[1173]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: amixer: Unable to find simple control '',0 Oct 08 18:59:19 tinkermio volumio[1173]: info: VolumeController::SetAlsaVolume11 Oct 08 18:59:19 tinkermio volumio[1173]: info: CoreCommandRouter::volumioGetState Oct 08 18:59:19 tinkermio volumio[1173]: info: CoreStateMachine::pushState Oct 08 18:59:19 tinkermio volumio[1173]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 08 18:59:19 tinkermio volumio[1173]: info: CoreCommandRouter::volumioPushState Oct 08 18:59:19 tinkermio volumio[1173]: info: CoreCommandRouter::volumioGetQueue Oct 08 18:59:19 tinkermio volumio[1173]: info: CoreStateMachine::getQueue Oct 08 18:59:19 tinkermio volumio[1173]: info: CorePlayQueue::getQueue Oct 08 18:59:19 tinkermio volumio[1173]: SPOTIFY: RECEIVED VOLUMIO VOLUME 11 Oct 08 18:59:19 tinkermio volumio[1173]: SPOTIFY: SPOTIFY VOLUME 14 Oct 08 18:59:19 tinkermio volumio[1173]: SPOTIFY: VOLUMIO VOLUME 11 Oct 08 18:59:19 tinkermio volumio[1173]: SPOTIFY: DELTA VOLUME ENOUGH: true Oct 08 18:59:19 tinkermio volumio[1173]: info: Setting Spotify Volume from Volumio: 11 Oct 08 18:59:19 tinkermio volumio[1173]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: amixer: Unable to find simple control '',0 Oct 08 18:59:20 tinkermio volumio[1173]: SPOTIFY: SETTING SPOTIFY VOLUME 11 Oct 08 18:59:20 tinkermio volumio[1173]: info: Sending Spotify command with payload to local API: /player/volume Oct 08 18:59:20 tinkermio go-librespot[1425]: time="2024-10-08T18:59:20+09:00" level=debug msg="update volume to 7208/65535" Oct 08 18:59:20 tinkermio go-librespot[1425]: time="2024-10-08T18:59:20+09:00" level=debug msg="put connect state because VOLUME_CHANGED" Oct 08 18:59:20 tinkermio go-librespot[1425]: time="2024-10-08T18:59:20+09:00" level=trace msg="emitting websocket event: volume" Oct 08 18:59:20 tinkermio volumio[1173]: SPOTIFY: received: {"type":"volume","data":{"value":11,"max":100}} Oct 08 18:59:20 tinkermio volumio[1173]: SPOTIFY: RECEIVED SPOTIFY VOLUME 11 Oct 08 18:59:23 tinkermio volumio[1173]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Oct 08 18:59:23 tinkermio volumio[1173]: info: Preload queue cleared Oct 08 18:59:24 tinkermio volumio[1173]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Oct 08 18:59:24 tinkermio volumio[1173]: info: Preload queue cleared Oct 08 18:59:25 tinkermio volumio[1173]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Oct 08 18:59:25 tinkermio volumio[1173]: info: Preload queue cleared Oct 08 18:59:26 tinkermio volumio[1173]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Oct 08 18:59:27 tinkermio volumio[1173]: info: Preload queue cleared Oct 08 18:59:46 tinkermio volumio[1173]: info: CoreCommandRouter::executeOnPlugin: upnp_browser , handleBrowseUri Oct 08 18:59:46 tinkermio volumio[1173]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 08 18:59:46 tinkermio volumio[1173]: TypeError: Cannot read property 'length' of undefined Oct 08 18:59:46 tinkermio volumio[1173]: at /volumio/app/plugins/music_service/upnp_browser/index.js:341:25 Oct 08 18:59:46 tinkermio volumio[1173]: at /volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:131:13 Oct 08 18:59:46 tinkermio volumio[1173]: at Parser. (/volumio/node_modules/xml2js/lib/parser.js:304:18) Oct 08 18:59:46 tinkermio volumio[1173]: at Parser.emit (events.js:400:28) Oct 08 18:59:46 tinkermio volumio[1173]: at SAXParser.onclosetag (/volumio/node_modules/xml2js/lib/parser.js:262:26) Oct 08 18:59:46 tinkermio volumio[1173]: at emit (/volumio/node_modules/sax/lib/sax.js:624:35) Oct 08 18:59:46 tinkermio volumio[1173]: at emitNode (/volumio/node_modules/sax/lib/sax.js:629:5) Oct 08 18:59:46 tinkermio volumio[1173]: at closeTag (/volumio/node_modules/sax/lib/sax.js:889:7) Oct 08 18:59:46 tinkermio volumio[1173]: at SAXParser.write (/volumio/node_modules/sax/lib/sax.js:1436:13) Oct 08 18:59:46 tinkermio volumio[1173]: at Parser.exports.Parser.Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:323:31) Oct 08 18:59:46 tinkermio volumio[1173]: at Parser.parseString (/volumio/node_modules/xml2js/lib/parser.js:5:59) Oct 08 18:59:46 tinkermio volumio[1173]: at Object.exports.parseString (/volumio/node_modules/xml2js/lib/parser.js:369:19) Oct 08 18:59:46 tinkermio volumio[1173]: at IncomingMessage. (/volumio/app/plugins/music_service/upnp_browser/dlna-browser.js:92:15) Oct 08 18:59:46 tinkermio volumio[1173]: at IncomingMessage.emit (events.js:412:35) Oct 08 18:59:46 tinkermio volumio[1173]: at endReadableNT (internal/streams/readable.js:1333:12) Oct 08 18:59:46 tinkermio volumio[1173]: at processTicksAndRejections (internal/process/task_queues.js:82:21) Oct 08 18:59:46 tinkermio volumio[1173]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 08 18:59:47 tinkermio sudo[2059]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-10-08 18:58 Oct 08 18:59:47 tinkermio sudo[2059]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Debian GNU/Linux 10 (buster)" NAME="Debian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="5fd3886148e72a9cecd88a772d1f6079fb64d11a" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="8bb23b009e91ae4c7ecd678f193e7d3b281fca0c" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Mon 22 Jul 2024 07:35:31 PM CEST" VOLUMIO_VERSION="3.742" VOLUMIO_HARDWARE="tinkerboard" VOLUMIO_DEVICENAME="Asus Tinkerboard" VOLUMIO_HASH="8e206762eb84baf3ce9616e2bda58682"