Dec 27 16:28:07 volumio3b volumio[1224]: info: CoreCommandRouter::volumioGetState Dec 27 16:28:09 volumio3b volumio[1224]: info: CoreCommandRouter::volumioGetQueue Dec 27 16:28:09 volumio3b volumio[1224]: info: CoreStateMachine::getQueue Dec 27 16:28:09 volumio3b volumio[1224]: info: CorePlayQueue::getQueue Dec 27 16:28:09 volumio3b volumio[1224]: info: Executing endpoint metavolumio Dec 27 16:28:09 volumio3b volumio[1224]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Dec 27 16:28:16 volumio3b kernel: usb 1-1.4: new high-speed USB device number 4 using dwc_otg Dec 27 16:28:16 volumio3b kernel: usb 1-1.4: New USB device found, idVendor=8564, idProduct=4000, bcdDevice= 0.37 Dec 27 16:28:16 volumio3b kernel: usb 1-1.4: New USB device strings: Mfr=3, Product=4, SerialNumber=5 Dec 27 16:28:16 volumio3b kernel: usb 1-1.4: Product: Transcend Dec 27 16:28:16 volumio3b kernel: usb 1-1.4: Manufacturer: TS-RDF5 Dec 27 16:28:16 volumio3b kernel: usb 1-1.4: SerialNumber: 000000000039 Dec 27 16:28:16 volumio3b kernel: usb-storage 1-1.4:1.0: USB Mass Storage device detected Dec 27 16:28:16 volumio3b kernel: scsi host0: usb-storage 1-1.4:1.0 Dec 27 16:28:17 volumio3b kernel: scsi 0:0:0:0: Direct-Access TS-RDF5 SD Transcend TS37 PQ: 0 ANSI: 6 Dec 27 16:28:17 volumio3b kernel: sd 0:0:0:0: [sda] Media removed, stopped polling Dec 27 16:28:17 volumio3b kernel: sd 0:0:0:0: [sda] Attached SCSI removable disk Dec 27 16:28:17 volumio3b kernel: sd 0:0:0:0: Attached scsi generic sg0 type 0 Dec 27 16:28:17 volumio3b volumio[1224]: info: CoreCommandRouter::volumioGetState Dec 27 16:28:17 volumio3b volumio[1224]: info: Clearing queue from CD entries Dec 27 16:28:17 volumio3b volumio[1224]: info: CoreCommandRouter::volumioPushQueue Dec 27 16:28:17 volumio3b volumio[1224]: info: CoreCommandRouter::volumioRemoveToBrowseSourcesAudio CD Dec 27 16:28:17 volumio3b volumio[1224]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Dec 27 16:28:17 volumio3b volumio[1224]: Cannot find translation for source Dummy Dec 27 16:28:18 volumio3b kernel: usb 1-1.4: USB disconnect, device number 4 Dec 27 16:28:25 volumio3b kernel: usb 1-1.4: new high-speed USB device number 5 using dwc_otg Dec 27 16:28:25 volumio3b kernel: usb 1-1.4: New USB device found, idVendor=0951, idProduct=1666, bcdDevice= 1.00 Dec 27 16:28:25 volumio3b kernel: usb 1-1.4: New USB device strings: Mfr=1, Product=2, SerialNumber=3 Dec 27 16:28:25 volumio3b kernel: usb 1-1.4: Product: DataTraveler 3.0 Dec 27 16:28:25 volumio3b kernel: usb 1-1.4: Manufacturer: Kingston Dec 27 16:28:25 volumio3b kernel: usb 1-1.4: SerialNumber: 08606E6B655BBF51E72C1100 Dec 27 16:28:25 volumio3b kernel: usb-storage 1-1.4:1.0: USB Mass Storage device detected Dec 27 16:28:25 volumio3b kernel: scsi host0: usb-storage 1-1.4:1.0 Dec 27 16:28:26 volumio3b kernel: scsi 0:0:0:0: Direct-Access Kingston DataTraveler 3.0 PMAP PQ: 0 ANSI: 6 Dec 27 16:28:26 volumio3b kernel: sd 0:0:0:0: Attached scsi generic sg0 type 0 Dec 27 16:28:27 volumio3b kernel: sd 0:0:0:0: [sda] 15364416 512-byte logical blocks: (7.87 GB/7.33 GiB) Dec 27 16:28:27 volumio3b kernel: sd 0:0:0:0: [sda] Write Protect is off Dec 27 16:28:27 volumio3b kernel: sd 0:0:0:0: [sda] Mode Sense: 23 00 00 00 Dec 27 16:28:27 volumio3b kernel: sd 0:0:0:0: [sda] No Caching mode page found Dec 27 16:28:27 volumio3b kernel: sd 0:0:0:0: [sda] Assuming drive cache: write through Dec 27 16:28:27 volumio3b kernel: sda: sda1 Dec 27 16:28:27 volumio3b kernel: sd 0:0:0:0: [sda] Attached SCSI removable disk Dec 27 16:28:28 volumio3b volumio[1224]: info: Mounting Device 6C52-A152 Dec 27 16:28:28 volumio3b sudo[2960]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/mount /dev/sda1 /mnt/USB/6C52-A152 -o noatime,dmask=0000,fmask=0000,iocharset=utf8 Dec 27 16:28:28 volumio3b sudo[2960]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 27 16:28:28 volumio3b kernel: FAT-fs (sda1): utf8 is not a recommended IO charset for FAT filesystems, filesystem will be case sensitive! Dec 27 16:28:28 volumio3b kernel: FAT-fs (sda1): Volume was not properly unmounted. Some data may be corrupt. Please run fsck. Dec 27 16:28:28 volumio3b sudo[2960]: pam_unix(sudo:session): session closed for user root Dec 27 16:28:29 volumio3b volumio[1224]: info: Scanning new location : "USB/6C52-A152" Dec 27 16:28:29 volumio3b volumio[1224]: verbose: ControllerMpd::sendMpdCommand status Dec 27 16:28:29 volumio3b volumio[1224]: info: Dec 27 16:28:29 volumio3b volumio[1224]: ---------------------------- MPD announces state update: update Dec 27 16:28:29 volumio3b volumio[1224]: info: ControllerMpd::getState Dec 27 16:28:29 volumio3b volumio[1224]: verbose: ControllerMpd::sendMpdCommand status Dec 27 16:28:29 volumio3b volumio[1224]: verbose: ControllerMpd::sendMpdCommand status Dec 27 16:28:29 volumio3b volumio[1224]: info: Dec 27 16:28:29 volumio3b volumio[1224]: ---------------------------- MPD announces state update: update Dec 27 16:28:29 volumio3b volumio[1224]: info: ControllerMpd::getState Dec 27 16:28:29 volumio3b volumio[1224]: verbose: ControllerMpd::sendMpdCommand status Dec 27 16:28:29 volumio3b volumio[1224]: verbose: ControllerMpd::sendMpdCommand status Dec 27 16:28:29 volumio3b volumio[1224]: info: Dec 27 16:28:29 volumio3b volumio[1224]: ---------------------------- MPD announces state update: update Dec 27 16:28:29 volumio3b volumio[1224]: info: ControllerMpd::getState Dec 27 16:28:29 volumio3b volumio[1224]: verbose: ControllerMpd::sendMpdCommand status Dec 27 16:28:29 volumio3b volumio[1224]: info: sendMpdCommand status took 67 milliseconds Dec 27 16:28:29 volumio3b volumio[1224]: info: sendMpdCommand status took 36 milliseconds Dec 27 16:28:29 volumio3b volumio[1224]: info: sendMpdCommand status took 34 milliseconds Dec 27 16:28:29 volumio3b volumio[1224]: verbose: ControllerMpd::parseState Dec 27 16:28:29 volumio3b volumio[1224]: info: Command Router : Notfying DB Updatetrue Dec 27 16:28:29 volumio3b volumio[1224]: verbose: ControllerMpd::parseState Dec 27 16:28:29 volumio3b volumio[1224]: verbose: ControllerMpd::parseState Dec 27 16:28:29 volumio3b volumio[1224]: info: Command Router : Notfying DB Updatetrue Dec 27 16:28:29 volumio3b volumio[1224]: info: CoreCommandRouter::Close All Modals sent Dec 27 16:28:29 volumio3b volumio[1224]: info: ControllerMpd::pushState Dec 27 16:28:29 volumio3b volumio[1224]: info: CoreCommandRouter::servicePushState Dec 27 16:28:29 volumio3b volumio[1224]: info: CoreStateMachine::pushState Dec 27 16:28:29 volumio3b volumio[1224]: info: CoreCommandRouter::volumioPushState Dec 27 16:28:29 volumio3b volumio[1224]: info: MRS: Pushing multiroomSync output update for this device Dec 27 16:28:29 volumio3b volumio[1224]: info: MRS: Pushing multiroomSync output Dec 27 16:28:29 volumio3b volumio[1224]: info: CoreCommandRouter::volumioGetState Dec 27 16:28:29 volumio3b volumio[1224]: info: CorePlayQueue::getTrack 0 Dec 27 16:28:29 volumio3b volumio[1224]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received mpd Dec 27 16:28:29 volumio3b volumio[1224]: info: ------------------------------ 454ms Dec 27 16:28:29 volumio3b volumio[1224]: info: sendMpdCommand status took 426 milliseconds Dec 27 16:28:29 volumio3b volumio[1224]: info: sendMpdCommand status took 402 milliseconds Dec 27 16:28:29 volumio3b volumio[1224]: info: sendMpdCommand status took 401 milliseconds Dec 27 16:28:29 volumio3b volumio[1224]: verbose: ControllerMpd::parseState Dec 27 16:28:29 volumio3b volumio[1224]: verbose: ControllerMpd::parseState Dec 27 16:28:29 volumio3b volumio[1224]: info: Command Router : Notfying DB Updatetrue Dec 27 16:28:29 volumio3b volumio[1224]: info: CoreCommandRouter::Close All Modals sent Dec 27 16:28:29 volumio3b volumio[1224]: verbose: ControllerMpd::parseState Dec 27 16:28:29 volumio3b volumio[1224]: info: ControllerMpd::pushState Dec 27 16:28:29 volumio3b volumio[1224]: info: CoreCommandRouter::servicePushState Dec 27 16:28:29 volumio3b volumio[1224]: info: CoreStateMachine::pushState Dec 27 16:28:29 volumio3b volumio[1224]: info: CoreCommandRouter::volumioPushState Dec 27 16:28:29 volumio3b volumio[1224]: info: MRS: Pushing multiroomSync output update for this device Dec 27 16:28:29 volumio3b volumio[1224]: info: MRS: Pushing multiroomSync output Dec 27 16:28:29 volumio3b volumio[1224]: info: CoreCommandRouter::volumioGetState Dec 27 16:28:29 volumio3b volumio[1224]: info: CorePlayQueue::getTrack 0 Dec 27 16:28:29 volumio3b volumio[1224]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received mpd Dec 27 16:28:29 volumio3b volumio[1224]: info: ControllerMpd::pushState Dec 27 16:28:29 volumio3b volumio[1224]: info: CoreCommandRouter::servicePushState Dec 27 16:28:29 volumio3b volumio[1224]: info: CoreStateMachine::pushState Dec 27 16:28:29 volumio3b volumio[1224]: info: CoreCommandRouter::volumioPushState Dec 27 16:28:29 volumio3b volumio[1224]: info: MRS: Pushing multiroomSync output update for this device Dec 27 16:28:29 volumio3b volumio[1224]: info: MRS: Pushing multiroomSync output Dec 27 16:28:29 volumio3b volumio[1224]: info: CoreCommandRouter::volumioGetState Dec 27 16:28:29 volumio3b volumio[1224]: info: CorePlayQueue::getTrack 0 Dec 27 16:28:29 volumio3b volumio[1224]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received mpd Dec 27 16:28:29 volumio3b volumio[1224]: info: ------------------------------ 698ms Dec 27 16:28:29 volumio3b volumio[1224]: info: ------------------------------ 731ms Dec 27 16:28:29 volumio3b volumio[1224]: info: peppy_screensaver: pushState - status=undefined service=undefined volatile=true Dec 27 16:28:29 volumio3b volumio[1224]: info: peppy_screensaver: pushState - status=undefined service=undefined volatile=true Dec 27 16:28:29 volumio3b volumio[1224]: info: peppy_screensaver: pushState - status=undefined service=undefined volatile=true Dec 27 16:28:29 volumio3b volumio[1224]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.W5jQ7k3idpX1GsfQQkegZTmqR302.42aa2a88bfaba19058424d9f102269c3.state.status' Dec 27 16:28:30 volumio3b volumio[1224]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.W5jQ7k3idpX1GsfQQkegZTmqR302.42aa2a88bfaba19058424d9f102269c3.state.status' Dec 27 16:28:30 volumio3b volumio[1224]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.W5jQ7k3idpX1GsfQQkegZTmqR302.42aa2a88bfaba19058424d9f102269c3.state.status' Dec 27 16:28:30 volumio3b volumio[1224]: info: MPD Database updated - AlbumList cache refreshed Dec 27 16:28:30 volumio3b volumio[1224]: info: Dec 27 16:28:30 volumio3b volumio[1224]: ---------------------------- MPD announces state update: database Dec 27 16:28:30 volumio3b volumio[1224]: verbose: ControllerMpd::sendMpdCommand status Dec 27 16:28:30 volumio3b volumio[1224]: info: Dec 27 16:28:30 volumio3b volumio[1224]: ---------------------------- MPD announces state update: update Dec 27 16:28:30 volumio3b volumio[1224]: info: ControllerMpd::getState Dec 27 16:28:30 volumio3b volumio[1224]: verbose: ControllerMpd::sendMpdCommand status Dec 27 16:28:30 volumio3b volumio[1224]: info: ControllerMpd::getState Dec 27 16:28:30 volumio3b volumio[1224]: verbose: ControllerMpd::sendMpdCommand status Dec 27 16:28:30 volumio3b volumio[1224]: info: MPD Database updated - AlbumList cache refreshed Dec 27 16:28:30 volumio3b volumio[1224]: info: Dec 27 16:28:30 volumio3b volumio[1224]: ---------------------------- MPD announces state update: database Dec 27 16:28:30 volumio3b volumio[1224]: verbose: ControllerMpd::sendMpdCommand status Dec 27 16:28:30 volumio3b volumio[1224]: info: Dec 27 16:28:30 volumio3b volumio[1224]: ---------------------------- MPD announces state update: update Dec 27 16:28:30 volumio3b volumio[1224]: info: ControllerMpd::getState Dec 27 16:28:30 volumio3b volumio[1224]: verbose: ControllerMpd::sendMpdCommand status Dec 27 16:28:30 volumio3b volumio[1224]: info: ControllerMpd::getState Dec 27 16:28:30 volumio3b volumio[1224]: verbose: ControllerMpd::sendMpdCommand status Dec 27 16:28:30 volumio3b volumio[1224]: info: MPD Database updated - AlbumList cache refreshed Dec 27 16:28:30 volumio3b volumio[1224]: info: Dec 27 16:28:30 volumio3b volumio[1224]: ---------------------------- MPD announces state update: database Dec 27 16:28:30 volumio3b volumio[1224]: verbose: ControllerMpd::sendMpdCommand status Dec 27 16:28:30 volumio3b volumio[1224]: info: Dec 27 16:28:30 volumio3b volumio[1224]: ---------------------------- MPD announces state update: update Dec 27 16:28:30 volumio3b volumio[1224]: info: ControllerMpd::getState Dec 27 16:28:30 volumio3b volumio[1224]: verbose: ControllerMpd::sendMpdCommand status Dec 27 16:28:30 volumio3b volumio[1224]: info: ControllerMpd::getState Dec 27 16:28:30 volumio3b volumio[1224]: verbose: ControllerMpd::sendMpdCommand status Dec 27 16:28:30 volumio3b volumio[1224]: info: sendMpdCommand status took 229 milliseconds Dec 27 16:28:30 volumio3b volumio[1224]: info: sendMpdCommand status took 206 milliseconds Dec 27 16:28:30 volumio3b volumio[1224]: info: sendMpdCommand status took 201 milliseconds Dec 27 16:28:30 volumio3b volumio[1224]: info: sendMpdCommand status took 178 milliseconds Dec 27 16:28:30 volumio3b volumio[1224]: info: sendMpdCommand status took 161 milliseconds Dec 27 16:28:30 volumio3b volumio[1224]: info: sendMpdCommand status took 152 milliseconds Dec 27 16:28:30 volumio3b volumio[1224]: verbose: ControllerMpd::parseState Dec 27 16:28:31 volumio3b volumio[1224]: info: Command Router : Notfying DB Updatefalse Dec 27 16:28:31 volumio3b volumio[1224]: info: CoreCommandRouter::Close All Modals sent Dec 27 16:28:31 volumio3b volumio[1224]: verbose: ControllerMpd::parseState Dec 27 16:28:31 volumio3b volumio[1224]: verbose: ControllerMpd::parseState Dec 27 16:28:31 volumio3b volumio[1224]: verbose: ControllerMpd::parseState Dec 27 16:28:31 volumio3b volumio[1224]: info: Command Router : Notfying DB Updatefalse Dec 27 16:28:31 volumio3b volumio[1224]: info: CoreCommandRouter::Close All Modals sent Dec 27 16:28:31 volumio3b volumio[1224]: verbose: ControllerMpd::parseState Dec 27 16:28:31 volumio3b volumio[1224]: verbose: ControllerMpd::parseState Dec 27 16:28:31 volumio3b volumio[1224]: info: ControllerMpd::pushState Dec 27 16:28:31 volumio3b volumio[1224]: info: CoreCommandRouter::servicePushState Dec 27 16:28:31 volumio3b volumio[1224]: info: CoreStateMachine::pushState Dec 27 16:28:31 volumio3b volumio[1224]: info: CoreCommandRouter::volumioPushState Dec 27 16:28:31 volumio3b volumio[1224]: info: MRS: Pushing multiroomSync output update for this device Dec 27 16:28:31 volumio3b volumio[1224]: info: MRS: Pushing multiroomSync output Dec 27 16:28:31 volumio3b volumio[1224]: info: CoreCommandRouter::volumioGetState Dec 27 16:28:31 volumio3b volumio[1224]: info: CorePlayQueue::getTrack 0 Dec 27 16:28:31 volumio3b volumio[1224]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received mpd Dec 27 16:28:31 volumio3b volumio[1224]: info: ControllerMpd::pushState Dec 27 16:28:31 volumio3b volumio[1224]: info: CoreCommandRouter::servicePushState Dec 27 16:28:31 volumio3b volumio[1224]: info: CoreStateMachine::pushState Dec 27 16:28:31 volumio3b volumio[1224]: info: CoreCommandRouter::volumioPushState Dec 27 16:28:31 volumio3b volumio[1224]: info: MRS: Pushing multiroomSync output update for this device Dec 27 16:28:31 volumio3b volumio[1224]: info: MRS: Pushing multiroomSync output Dec 27 16:28:31 volumio3b volumio[1224]: info: CoreCommandRouter::volumioGetState Dec 27 16:28:31 volumio3b volumio[1224]: info: CorePlayQueue::getTrack 0 Dec 27 16:28:31 volumio3b volumio[1224]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received mpd Dec 27 16:28:31 volumio3b volumio[1224]: info: ControllerMpd::pushState Dec 27 16:28:31 volumio3b volumio[1224]: info: CoreCommandRouter::servicePushState Dec 27 16:28:31 volumio3b volumio[1224]: info: CoreStateMachine::pushState Dec 27 16:28:31 volumio3b volumio[1224]: info: CoreCommandRouter::volumioPushState Dec 27 16:28:31 volumio3b volumio[1224]: info: MRS: Pushing multiroomSync output update for this device Dec 27 16:28:31 volumio3b volumio[1224]: info: MRS: Pushing multiroomSync output Dec 27 16:28:31 volumio3b volumio[1224]: info: CoreCommandRouter::volumioGetState Dec 27 16:28:31 volumio3b volumio[1224]: info: CorePlayQueue::getTrack 0 Dec 27 16:28:31 volumio3b volumio[1224]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received mpd Dec 27 16:28:31 volumio3b volumio[1224]: info: ControllerMpd::pushState Dec 27 16:28:31 volumio3b volumio[1224]: info: CoreCommandRouter::servicePushState Dec 27 16:28:31 volumio3b volumio[1224]: info: CoreStateMachine::pushState Dec 27 16:28:31 volumio3b volumio[1224]: info: CoreCommandRouter::volumioPushState Dec 27 16:28:31 volumio3b volumio[1224]: info: MRS: Pushing multiroomSync output update for this device Dec 27 16:28:31 volumio3b volumio[1224]: info: MRS: Pushing multiroomSync output Dec 27 16:28:31 volumio3b volumio[1224]: info: CoreCommandRouter::volumioGetState Dec 27 16:28:31 volumio3b volumio[1224]: info: CorePlayQueue::getTrack 0 Dec 27 16:28:31 volumio3b volumio[1224]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received mpd Dec 27 16:28:32 volumio3b volumio[1224]: info: ------------------------------ 1502ms Dec 27 16:28:32 volumio3b volumio[1224]: info: ------------------------------ 1501ms Dec 27 16:28:32 volumio3b volumio[1224]: info: ------------------------------ 1477ms Dec 27 16:28:32 volumio3b volumio[1224]: info: ------------------------------ 1474ms Dec 27 16:28:32 volumio3b volumio[1224]: info: sendMpdCommand status took 1511 milliseconds Dec 27 16:28:32 volumio3b volumio[1224]: info: sendMpdCommand status took 1385 milliseconds Dec 27 16:28:32 volumio3b volumio[1224]: info: sendMpdCommand status took 1385 milliseconds Dec 27 16:28:32 volumio3b volumio[1224]: verbose: ControllerMpd::parseState Dec 27 16:28:32 volumio3b volumio[1224]: info: Command Router : Notfying DB Updatefalse Dec 27 16:28:32 volumio3b volumio[1224]: info: CoreCommandRouter::Close All Modals sent Dec 27 16:28:32 volumio3b volumio[1224]: verbose: ControllerMpd::parseState Dec 27 16:28:32 volumio3b volumio[1224]: verbose: ControllerMpd::parseState Dec 27 16:28:32 volumio3b volumio[1224]: info: ControllerMpd::pushState Dec 27 16:28:32 volumio3b volumio[1224]: info: CoreCommandRouter::servicePushState Dec 27 16:28:32 volumio3b volumio[1224]: info: CoreStateMachine::pushState Dec 27 16:28:32 volumio3b volumio[1224]: info: CoreCommandRouter::volumioPushState Dec 27 16:28:32 volumio3b volumio[1224]: info: MRS: Pushing multiroomSync output update for this device Dec 27 16:28:32 volumio3b volumio[1224]: info: MRS: Pushing multiroomSync output Dec 27 16:28:32 volumio3b volumio[1224]: info: CoreCommandRouter::volumioGetState Dec 27 16:28:32 volumio3b volumio[1224]: info: CorePlayQueue::getTrack 0 Dec 27 16:28:32 volumio3b volumio[1224]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received mpd Dec 27 16:28:32 volumio3b volumio[1224]: info: ControllerMpd::pushState Dec 27 16:28:32 volumio3b volumio[1224]: info: CoreCommandRouter::servicePushState Dec 27 16:28:32 volumio3b volumio[1224]: info: CoreStateMachine::pushState Dec 27 16:28:32 volumio3b volumio[1224]: info: CoreCommandRouter::volumioPushState Dec 27 16:28:32 volumio3b volumio[1224]: info: MRS: Pushing multiroomSync output update for this device Dec 27 16:28:32 volumio3b volumio[1224]: info: MRS: Pushing multiroomSync output Dec 27 16:28:32 volumio3b volumio[1224]: info: CoreCommandRouter::volumioGetState Dec 27 16:28:32 volumio3b volumio[1224]: info: CorePlayQueue::getTrack 0 Dec 27 16:28:32 volumio3b volumio[1224]: info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current webradio Received mpd Dec 27 16:28:32 volumio3b volumio[1224]: info: ------------------------------ 2042ms Dec 27 16:28:32 volumio3b volumio[1224]: info: ------------------------------ 2041ms Dec 27 16:28:32 volumio3b volumio[1224]: info: peppy_screensaver: pushState - status=undefined service=undefined volatile=true Dec 27 16:28:32 volumio3b volumio[1224]: info: peppy_screensaver: pushState - status=undefined service=undefined volatile=true Dec 27 16:28:32 volumio3b volumio[1224]: info: peppy_screensaver: pushState - status=undefined service=undefined volatile=true Dec 27 16:28:32 volumio3b volumio[1224]: info: peppy_screensaver: pushState - status=undefined service=undefined volatile=true Dec 27 16:28:32 volumio3b volumio[1224]: info: peppy_screensaver: pushState - status=undefined service=undefined volatile=true Dec 27 16:28:32 volumio3b volumio[1224]: info: peppy_screensaver: pushState - status=undefined service=undefined volatile=true Dec 27 16:28:33 volumio3b volumio[1224]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.W5jQ7k3idpX1GsfQQkegZTmqR302.42aa2a88bfaba19058424d9f102269c3.state.status' Dec 27 16:28:33 volumio3b volumio[1224]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.W5jQ7k3idpX1GsfQQkegZTmqR302.42aa2a88bfaba19058424d9f102269c3.state.status' Dec 27 16:28:33 volumio3b volumio[1224]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.W5jQ7k3idpX1GsfQQkegZTmqR302.42aa2a88bfaba19058424d9f102269c3.state.status' Dec 27 16:28:33 volumio3b volumio[1224]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.W5jQ7k3idpX1GsfQQkegZTmqR302.42aa2a88bfaba19058424d9f102269c3.state.status' Dec 27 16:28:33 volumio3b volumio[1224]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.W5jQ7k3idpX1GsfQQkegZTmqR302.42aa2a88bfaba19058424d9f102269c3.state.status' Dec 27 16:28:33 volumio3b volumio[1224]: error: Cannot update RT Device info: Error: Reference.set failed: First argument contains undefined in property 'user_devices.W5jQ7k3idpX1GsfQQkegZTmqR302.42aa2a88bfaba19058424d9f102269c3.state.status' Dec 27 16:28:33 volumio3b volumio[1224]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Dec 27 16:28:33 volumio3b volumio[1224]: info: CURURI: music-library Dec 27 16:28:33 volumio3b volumio[1224]: info: Preload queue cleared Dec 27 16:28:35 volumio3b volumio[1224]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Dec 27 16:28:35 volumio3b volumio[1224]: info: CURURI: music-library/USB Dec 27 16:28:35 volumio3b volumio[1224]: info: Preload queue cleared Dec 27 16:28:36 volumio3b volumio[1224]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Dec 27 16:28:36 volumio3b volumio[1224]: info: CURURI: music-library/USB/6C52-A152 Dec 27 16:28:36 volumio3b volumio[1224]: info: Preload queue cleared Dec 27 16:28:37 volumio3b volumio[1224]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Dec 27 16:28:37 volumio3b volumio[1224]: info: CURURI: music-library/USB/6C52-A152/Music Dec 27 16:28:37 volumio3b volumio[1224]: info: Preload queue cleared Dec 27 16:28:45 volumio3b volumio[1224]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Dec 27 16:28:45 volumio3b volumio[1224]: info: CURURI: music-library Dec 27 16:28:45 volumio3b volumio[1224]: info: Preload queue cleared Dec 27 16:28:46 volumio3b volumio[1224]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Dec 27 16:28:46 volumio3b volumio[1224]: info: CURURI: music-library/USB Dec 27 16:28:46 volumio3b volumio[1224]: info: Preload queue cleared Dec 27 16:28:47 volumio3b volumio[1224]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Dec 27 16:28:47 volumio3b volumio[1224]: info: CURURI: music-library/USB/6C52-A152 Dec 27 16:28:47 volumio3b volumio[1224]: info: Preload queue cleared Dec 27 16:28:47 volumio3b volumio[1224]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Dec 27 16:28:47 volumio3b volumio[1224]: info: CURURI: music-library/USB/6C52-A152/Music Dec 27 16:28:47 volumio3b volumio[1224]: info: Preload queue cleared Dec 27 16:28:48 volumio3b volumio[1224]: info: CoreCommandRouter::executeOnPlugin: mpd , handleBrowseUri Dec 27 16:28:48 volumio3b volumio[1224]: info: CURURI: music-library/USB/6C52-A152/Music/Adele - 19 Dec 27 16:28:48 volumio3b volumio[1224]: info: Preload queue cleared Dec 27 16:28:48 volumio3b volumio[1224]: info: Preloading song: music-library/USB/6C52-A152/Music/Adele - 19/01 Daydreams.mp3 Dec 27 16:28:48 volumio3b volumio[1224]: info: Preloading song: music-library/USB/6C52-A152/Music/Adele - 19/02 Best For Last.mp3 Dec 27 16:28:48 volumio3b volumio[1224]: info: Preloading song: music-library/USB/6C52-A152/Music/Adele - 19/03 Chasing Pavements.mp3 Dec 27 16:28:48 volumio3b volumio[1224]: info: Preloading song: music-library/USB/6C52-A152/Music/Adele - 19/04 Cold Shoulder.mp3 Dec 27 16:28:48 volumio3b volumio[1224]: info: Preloading song: music-library/USB/6C52-A152/Music/Adele - 19/05 Crazy For You.mp3 Dec 27 16:28:48 volumio3b volumio[1224]: info: Preloading song: music-library/USB/6C52-A152/Music/Adele - 19/06 Melt My Heart To Stone.mp3 Dec 27 16:28:48 volumio3b volumio[1224]: info: Preloading song: music-library/USB/6C52-A152/Music/Adele - 19/07 First Love.mp3 Dec 27 16:28:48 volumio3b volumio[1224]: info: Preloading song: music-library/USB/6C52-A152/Music/Adele - 19/08 Right As Rain.mp3 Dec 27 16:28:48 volumio3b volumio[1224]: info: Preloading song: music-library/USB/6C52-A152/Music/Adele - 19/09 Make You Feel My Love.mp3 Dec 27 16:28:48 volumio3b volumio[1224]: info: Preloading song: music-library/USB/6C52-A152/Music/Adele - 19/10 My Same.mp3 Dec 27 16:28:48 volumio3b volumio[1224]: info: Preloading song: music-library/USB/6C52-A152/Music/Adele - 19/11 Tired.mp3 Dec 27 16:28:48 volumio3b volumio[1224]: info: Preloading song: music-library/USB/6C52-A152/Music/Adele - 19/12 Hometown Glory.mp3 Dec 27 16:28:48 volumio3b volumio[1224]: info: Exploding uri music-library/USB/6C52-A152/Music/Adele - 19/01 Daydreams.mp3 in service mpd Dec 27 16:28:48 volumio3b volumio[1224]: info: Exploding uri music-library/USB/6C52-A152/Music/Adele - 19/02 Best For Last.mp3 in service mpd Dec 27 16:28:48 volumio3b volumio[1224]: info: ALBUMART /albumart?cacheid=256&web=Adele/19/extralarge&path=%2Fmnt%2FUSB%2F6C52-A152%2FMusic%2FAdele%20-%2019%2F01%20Daydreams.mp3&metadata=false Dec 27 16:28:48 volumio3b volumio[1224]: info: URI /mnt/USB/6C52-A152/Music/Adele - 19/01 Daydreams.mp3 Dec 27 16:28:48 volumio3b volumio[1224]: info: Exploding uri music-library/USB/6C52-A152/Music/Adele - 19/03 Chasing Pavements.mp3 in service mpd Dec 27 16:28:48 volumio3b volumio[1224]: info: ALBUMART /albumart?cacheid=256&web=Adele/19/extralarge&path=%2Fmnt%2FUSB%2F6C52-A152%2FMusic%2FAdele%20-%2019%2F02%20Best%20For%20Last.mp3&metadata=false Dec 27 16:28:48 volumio3b volumio[1224]: info: URI /mnt/USB/6C52-A152/Music/Adele - 19/02 Best For Last.mp3 Dec 27 16:28:48 volumio3b volumio[1224]: info: Exploding uri music-library/USB/6C52-A152/Music/Adele - 19/04 Cold Shoulder.mp3 in service mpd Dec 27 16:28:48 volumio3b volumio[1224]: info: ALBUMART /albumart?cacheid=256&web=Adele/19/extralarge&path=%2Fmnt%2FUSB%2F6C52-A152%2FMusic%2FAdele%20-%2019%2F03%20Chasing%20Pavements.mp3&metadata=false Dec 27 16:28:48 volumio3b volumio[1224]: info: URI /mnt/USB/6C52-A152/Music/Adele - 19/03 Chasing Pavements.mp3 Dec 27 16:28:48 volumio3b volumio[1224]: info: ALBUMART /albumart?cacheid=256&web=Adele/19/extralarge&path=%2Fmnt%2FUSB%2F6C52-A152%2FMusic%2FAdele%20-%2019%2F04%20Cold%20Shoulder.mp3&metadata=false Dec 27 16:28:48 volumio3b volumio[1224]: info: URI /mnt/USB/6C52-A152/Music/Adele - 19/04 Cold Shoulder.mp3 Dec 27 16:28:48 volumio3b volumio[1224]: info: Exploding uri music-library/USB/6C52-A152/Music/Adele - 19/05 Crazy For You.mp3 in service mpd Dec 27 16:28:48 volumio3b volumio[1224]: info: ALBUMART /albumart?cacheid=256&web=Adele/19/extralarge&path=%2Fmnt%2FUSB%2F6C52-A152%2FMusic%2FAdele%20-%2019%2F05%20Crazy%20For%20You.mp3&metadata=false Dec 27 16:28:48 volumio3b volumio[1224]: info: URI /mnt/USB/6C52-A152/Music/Adele - 19/05 Crazy For You.mp3 Dec 27 16:28:48 volumio3b volumio[1224]: info: Exploding uri music-library/USB/6C52-A152/Music/Adele - 19/06 Melt My Heart To Stone.mp3 in service mpd Dec 27 16:28:48 volumio3b volumio[1224]: info: ALBUMART /albumart?cacheid=256&web=Adele/19/extralarge&path=%2Fmnt%2FUSB%2F6C52-A152%2FMusic%2FAdele%20-%2019%2F06%20Melt%20My%20Heart%20To%20Stone.mp3&metadata=false Dec 27 16:28:48 volumio3b volumio[1224]: info: URI /mnt/USB/6C52-A152/Music/Adele - 19/06 Melt My Heart To Stone.mp3 Dec 27 16:28:48 volumio3b volumio[1224]: info: Exploding uri music-library/USB/6C52-A152/Music/Adele - 19/07 First Love.mp3 in service mpd Dec 27 16:28:48 volumio3b volumio[1224]: info: ALBUMART /albumart?cacheid=256&web=Adele/19/extralarge&path=%2Fmnt%2FUSB%2F6C52-A152%2FMusic%2FAdele%20-%2019%2F07%20First%20Love.mp3&metadata=false Dec 27 16:28:48 volumio3b volumio[1224]: info: URI /mnt/USB/6C52-A152/Music/Adele - 19/07 First Love.mp3 Dec 27 16:28:48 volumio3b volumio[1224]: info: Exploding uri music-library/USB/6C52-A152/Music/Adele - 19/08 Right As Rain.mp3 in service mpd Dec 27 16:28:48 volumio3b volumio[1224]: info: ALBUMART /albumart?cacheid=256&web=Adele/19/extralarge&path=%2Fmnt%2FUSB%2F6C52-A152%2FMusic%2FAdele%20-%2019%2F08%20Right%20As%20Rain.mp3&metadata=false Dec 27 16:28:48 volumio3b volumio[1224]: info: URI /mnt/USB/6C52-A152/Music/Adele - 19/08 Right As Rain.mp3 Dec 27 16:28:48 volumio3b volumio[1224]: info: Exploding uri music-library/USB/6C52-A152/Music/Adele - 19/09 Make You Feel My Love.mp3 in service mpd Dec 27 16:28:48 volumio3b volumio[1224]: info: ALBUMART /albumart?cacheid=256&web=Adele/19/extralarge&path=%2Fmnt%2FUSB%2F6C52-A152%2FMusic%2FAdele%20-%2019%2F09%20Make%20You%20Feel%20My%20Love.mp3&metadata=false Dec 27 16:28:48 volumio3b volumio[1224]: info: URI /mnt/USB/6C52-A152/Music/Adele - 19/09 Make You Feel My Love.mp3 Dec 27 16:28:48 volumio3b volumio[1224]: info: Exploding uri music-library/USB/6C52-A152/Music/Adele - 19/10 My Same.mp3 in service mpd Dec 27 16:28:48 volumio3b volumio[1224]: info: ALBUMART /albumart?cacheid=256&web=Adele/19/extralarge&path=%2Fmnt%2FUSB%2F6C52-A152%2FMusic%2FAdele%20-%2019%2F10%20My%20Same.mp3&metadata=false Dec 27 16:28:48 volumio3b volumio[1224]: info: URI /mnt/USB/6C52-A152/Music/Adele - 19/10 My Same.mp3 Dec 27 16:28:48 volumio3b volumio[1224]: info: Exploding uri music-library/USB/6C52-A152/Music/Adele - 19/11 Tired.mp3 in service mpd Dec 27 16:28:48 volumio3b volumio[1224]: info: ALBUMART /albumart?cacheid=256&web=Adele/19/extralarge&path=%2Fmnt%2FUSB%2F6C52-A152%2FMusic%2FAdele%20-%2019%2F11%20Tired.mp3&metadata=false Dec 27 16:28:48 volumio3b volumio[1224]: info: URI /mnt/USB/6C52-A152/Music/Adele - 19/11 Tired.mp3 Dec 27 16:28:49 volumio3b volumio[1224]: info: Exploding uri music-library/USB/6C52-A152/Music/Adele - 19/12 Hometown Glory.mp3 in service mpd Dec 27 16:28:49 volumio3b volumio[1224]: info: ALBUMART /albumart?cacheid=256&web=Adele/19/extralarge&path=%2Fmnt%2FUSB%2F6C52-A152%2FMusic%2FAdele%20-%2019%2F12%20Hometown%20Glory.mp3&metadata=false Dec 27 16:28:49 volumio3b volumio[1224]: info: URI /mnt/USB/6C52-A152/Music/Adele - 19/12 Hometown Glory.mp3 Dec 27 16:28:50 volumio3b volumio[1224]: info: Preload queue cleared Dec 27 16:28:50 volumio3b volumio[1224]: info: CoreCommandRouter::volumioReplaceandPlayItems Dec 27 16:28:50 volumio3b volumio[1224]: info: CoreStateMachine::ClearQueue Dec 27 16:28:50 volumio3b volumio[1224]: info: CoreStateMachine::stop Dec 27 16:28:50 volumio3b volumio[1224]: info: CoreStateMachine::serviceStop Dec 27 16:28:50 volumio3b volumio[1224]: info: Received STOP, but no service to execute it Dec 27 16:28:50 volumio3b volumio[1224]: info: CorePlayQueue::clearPlayQueue Dec 27 16:28:50 volumio3b volumio[1224]: info: CorePlayQueue::saveQueue Dec 27 16:28:50 volumio3b volumio[1224]: info: CoreCommandRouter::volumioPushQueue Dec 27 16:28:50 volumio3b volumio[1224]: info: CoreStateMachine::addQueueItems Dec 27 16:28:50 volumio3b volumio[1224]: info: CorePlayQueue::addQueueItems Dec 27 16:28:50 volumio3b volumio[1224]: info: Preload queue cleared Dec 27 16:28:50 volumio3b volumio[1224]: info: Adding Item to queue: music-library/USB/6C52-A152/Music/Adele - 19/01 Daydreams.mp3 Dec 27 16:28:50 volumio3b volumio[1224]: info: Using cached record of: music-library/USB/6C52-A152/Music/Adele - 19/01 Daydreams.mp3 Dec 27 16:28:50 volumio3b volumio[1224]: info: CoreCommandRouter::volumioPushQueue Dec 27 16:28:50 volumio3b volumio[1224]: info: CorePlayQueue::saveQueue Dec 27 16:28:50 volumio3b volumio[1224]: info: CoreStateMachine::updateTrackBlock Dec 27 16:28:50 volumio3b volumio[1224]: info: CorePlayQueue::getTrackBlock Dec 27 16:28:50 volumio3b volumio[1224]: info: CoreCommandRouter::volumioGetState Dec 27 16:28:50 volumio3b volumio[1224]: info: CoreCommandRouter::executeOnPlugin: play , [object Object] Dec 27 16:28:50 volumio3b volumio[1224]: info: CoreCommandRouter::volumioPlay Dec 27 16:28:50 volumio3b volumio[1224]: verbose: UNSET VOLATILE: Service: undefined Dec 27 16:28:50 volumio3b volumio[1224]: ------------------------------------ BT MESSAGE: [FUNC] detachBluetooth Dec 27 16:28:50 volumio3b volumio[1224]: ------------------------------------ BT MESSAGE: [FUNC] btAudioOutput Dec 27 16:28:50 volumio3b volumio[1224]: ------------------------------------ BT MESSAGE: [dbus-next] Disabling Bluetooth Audio Output Dec 27 16:28:50 volumio3b volumio[1224]: info: CoreStateMachine::play index 0 Dec 27 16:28:50 volumio3b volumio[1224]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 27 16:28:50 volumio3b volumio[1224]: info: CoreStateMachine::addQueueItems Dec 27 16:28:50 volumio3b volumio[1224]: info: CorePlayQueue::addQueueItems Dec 27 16:28:50 volumio3b volumio[1224]: info: Preload queue cleared Dec 27 16:28:50 volumio3b volumio[1224]: info: Adding Item to queue: music-library/USB/6C52-A152/Music/Adele - 19/02 Best For Last.mp3 Dec 27 16:28:50 volumio3b volumio[1224]: info: Using cached record of: music-library/USB/6C52-A152/Music/Adele - 19/02 Best For Last.mp3 Dec 27 16:28:50 volumio3b volumio[1224]: info: Adding Item to queue: music-library/USB/6C52-A152/Music/Adele - 19/03 Chasing Pavements.mp3 Dec 27 16:28:50 volumio3b volumio[1224]: info: Using cached record of: music-library/USB/6C52-A152/Music/Adele - 19/03 Chasing Pavements.mp3 Dec 27 16:28:50 volumio3b volumio[1224]: info: Adding Item to queue: music-library/USB/6C52-A152/Music/Adele - 19/04 Cold Shoulder.mp3 Dec 27 16:28:50 volumio3b volumio[1224]: info: Using cached record of: music-library/USB/6C52-A152/Music/Adele - 19/04 Cold Shoulder.mp3 Dec 27 16:28:50 volumio3b volumio[1224]: info: Adding Item to queue: music-library/USB/6C52-A152/Music/Adele - 19/05 Crazy For You.mp3 Dec 27 16:28:50 volumio3b volumio[1224]: info: Using cached record of: music-library/USB/6C52-A152/Music/Adele - 19/05 Crazy For You.mp3 Dec 27 16:28:50 volumio3b volumio[1224]: info: Adding Item to queue: music-library/USB/6C52-A152/Music/Adele - 19/06 Melt My Heart To Stone.mp3 Dec 27 16:28:50 volumio3b volumio[1224]: info: Using cached record of: music-library/USB/6C52-A152/Music/Adele - 19/06 Melt My Heart To Stone.mp3 Dec 27 16:28:50 volumio3b volumio[1224]: info: Adding Item to queue: music-library/USB/6C52-A152/Music/Adele - 19/07 First Love.mp3 Dec 27 16:28:50 volumio3b volumio[1224]: info: Using cached record of: music-library/USB/6C52-A152/Music/Adele - 19/07 First Love.mp3 Dec 27 16:28:50 volumio3b volumio[1224]: info: Adding Item to queue: music-library/USB/6C52-A152/Music/Adele - 19/08 Right As Rain.mp3 Dec 27 16:28:50 volumio3b volumio[1224]: info: Using cached record of: music-library/USB/6C52-A152/Music/Adele - 19/08 Right As Rain.mp3 Dec 27 16:28:50 volumio3b volumio[1224]: info: Adding Item to queue: music-library/USB/6C52-A152/Music/Adele - 19/09 Make You Feel My Love.mp3 Dec 27 16:28:50 volumio3b volumio[1224]: info: Using cached record of: music-library/USB/6C52-A152/Music/Adele - 19/09 Make You Feel My Love.mp3 Dec 27 16:28:50 volumio3b volumio[1224]: info: Adding Item to queue: music-library/USB/6C52-A152/Music/Adele - 19/10 My Same.mp3 Dec 27 16:28:50 volumio3b volumio[1224]: info: Using cached record of: music-library/USB/6C52-A152/Music/Adele - 19/10 My Same.mp3 Dec 27 16:28:50 volumio3b volumio[1224]: info: Adding Item to queue: music-library/USB/6C52-A152/Music/Adele - 19/11 Tired.mp3 Dec 27 16:28:50 volumio3b volumio[1224]: info: Using cached record of: music-library/USB/6C52-A152/Music/Adele - 19/11 Tired.mp3 Dec 27 16:28:50 volumio3b volumio[1224]: info: Adding Item to queue: music-library/USB/6C52-A152/Music/Adele - 19/12 Hometown Glory.mp3 Dec 27 16:28:50 volumio3b volumio[1224]: info: Using cached record of: music-library/USB/6C52-A152/Music/Adele - 19/12 Hometown Glory.mp3 Dec 27 16:28:50 volumio3b volumio[1224]: ------------------------------------ BT MESSAGE: Bluetooth audio output disabled. Dec 27 16:28:50 volumio3b volumio[1224]: info: CoreStateMachine::stop Dec 27 16:28:50 volumio3b volumio[1224]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 27 16:28:50 volumio3b volumio[1224]: info: CoreCommandRouter::volumioPushQueue Dec 27 16:28:50 volumio3b volumio[1224]: info: CorePlayQueue::saveQueue Dec 27 16:28:50 volumio3b volumio[1224]: info: CoreStateMachine::resetVolumioState Dec 27 16:28:50 volumio3b volumio[1224]: info: CoreStateMachine::getcurrentVolume Dec 27 16:28:50 volumio3b volumio[1224]: info: CoreCommandRouter::volumioRetrievevolume Dec 27 16:28:50 volumio3b volumio[1224]: info: CoreStateMachine::play index undefined Dec 27 16:28:50 volumio3b volumio[1224]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 27 16:28:50 volumio3b volumio[1224]: info: CoreStateMachine::updateTrackBlock Dec 27 16:28:50 volumio3b volumio[1224]: info: CorePlayQueue::getTrackBlock Dec 27 16:28:50 volumio3b volumio[1224]: info: CoreCommandRouter::volumioStop Dec 27 16:28:50 volumio3b volumio[1224]: info: CoreStateMachine::stop Dec 27 16:28:50 volumio3b volumio[1224]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 27 16:28:50 volumio3b volumio[1224]: info: CorePlayQueue::getTrack 0 Dec 27 16:28:50 volumio3b volumio[1224]: info: CoreStateMachine::startPlaybackTimer Dec 27 16:28:50 volumio3b volumio[1224]: info: CorePlayQueue::getTrack 0 Dec 27 16:28:50 volumio3b volumio[1224]: verbose: ControllerMpd::clearAddPlayTracks USB/6C52-A152/Music/Adele - 19/01 Daydreams.mp3 Dec 27 16:28:50 volumio3b volumio[1224]: verbose: ControllerMpd::sendMpdCommand stop Dec 27 16:28:50 volumio3b volumio[1224]: info: sendMpdCommand stop took 130 milliseconds Dec 27 16:28:50 volumio3b volumio[1224]: verbose: ControllerMpd::sendMpdCommand clear Dec 27 16:28:50 volumio3b volumio[1224]: info: Dec 27 16:28:50 volumio3b volumio[1224]: ---------------------------- MPD announces system playlist update Dec 27 16:28:50 volumio3b volumio[1224]: info: Ignoring MPD Status Update Dec 27 16:28:50 volumio3b volumio[1224]: info: sendMpdCommand clear took 26 milliseconds Dec 27 16:28:50 volumio3b volumio[1224]: verbose: ControllerMpd::sendMpdCommand add "USB/6C52-A152/Music/Adele - 19/01 Daydreams.mp3" Dec 27 16:28:50 volumio3b volumio[1224]: info: Dec 27 16:28:50 volumio3b volumio[1224]: ---------------------------- MPD announces system playlist update Dec 27 16:28:50 volumio3b volumio[1224]: info: Ignoring MPD Status Update Dec 27 16:28:50 volumio3b volumio[1224]: info: Dec 27 16:28:50 volumio3b volumio[1224]: ---------------------------- MPD announces system playlist update Dec 27 16:28:50 volumio3b volumio[1224]: info: Ignoring MPD Status Update Dec 27 16:28:50 volumio3b volumio[1224]: error: updateQueue error: null Dec 27 16:28:50 volumio3b volumio[1224]: info: Dec 27 16:28:50 volumio3b volumio[1224]: ---------------------------- MPD announces system playlist update Dec 27 16:28:50 volumio3b volumio[1224]: info: Ignoring MPD Status Update Dec 27 16:28:50 volumio3b volumio[1224]: info: ------------------------------ 131ms Dec 27 16:28:50 volumio3b volumio[1224]: info: sendMpdCommand add "USB/6C52-A152/Music/Adele - 19/01 Daydreams.mp3" took 102 milliseconds Dec 27 16:28:50 volumio3b volumio[1224]: info: ------------------------------ 86ms Dec 27 16:28:50 volumio3b volumio[1224]: info: ------------------------------ 90ms Dec 27 16:28:50 volumio3b volumio[1224]: verbose: ControllerMpd::sendMpdCommand play Dec 27 16:28:50 volumio3b volumio[1224]: info: Dec 27 16:28:50 volumio3b volumio[1224]: ---------------------------- MPD announces system playlist update Dec 27 16:28:50 volumio3b volumio[1224]: info: Ignoring MPD Status Update Dec 27 16:28:50 volumio3b volumio[1224]: info: Dec 27 16:28:50 volumio3b volumio[1224]: ---------------------------- MPD announces system playlist update Dec 27 16:28:50 volumio3b volumio[1224]: info: Ignoring MPD Status Update Dec 27 16:28:51 volumio3b volumio[1224]: info: Dec 27 16:28:51 volumio3b volumio[1224]: ---------------------------- MPD announces state update: player Dec 27 16:28:51 volumio3b volumio[1224]: info: ------------------------------ 155ms Dec 27 16:28:51 volumio3b volumio[1224]: info: sendMpdCommand play took 126 milliseconds Dec 27 16:28:51 volumio3b volumio[1224]: info: ControllerMpd::getState Dec 27 16:28:51 volumio3b volumio[1224]: verbose: ControllerMpd::sendMpdCommand status Dec 27 16:28:51 volumio3b volumio[1224]: info: ------------------------------ 111ms Dec 27 16:28:51 volumio3b volumio[1224]: info: ------------------------------ 110ms Dec 27 16:28:51 volumio3b volumio[1224]: info: Dec 27 16:28:51 volumio3b volumio[1224]: ---------------------------- MPD announces state update: player Dec 27 16:28:51 volumio3b volumio[1224]: info: ControllerMpd::getState Dec 27 16:28:51 volumio3b volumio[1224]: verbose: ControllerMpd::sendMpdCommand status Dec 27 16:28:51 volumio3b volumio[1224]: info: Dec 27 16:28:51 volumio3b volumio[1224]: ---------------------------- MPD announces state update: player Dec 27 16:28:51 volumio3b volumio[1224]: info: ControllerMpd::getState Dec 27 16:28:51 volumio3b volumio[1224]: verbose: ControllerMpd::sendMpdCommand status Dec 27 16:28:51 volumio3b volumio[1224]: info: Dec 27 16:28:51 volumio3b volumio[1224]: ---------------------------- MPD announces state update: player Dec 27 16:28:51 volumio3b volumio[1224]: info: ControllerMpd::getState Dec 27 16:28:51 volumio3b volumio[1224]: verbose: ControllerMpd::sendMpdCommand status Dec 27 16:28:51 volumio3b volumio[1224]: info: sendMpdCommand status took 114 milliseconds Dec 27 16:28:51 volumio3b volumio[1224]: info: sendMpdCommand status took 75 milliseconds Dec 27 16:28:51 volumio3b volumio[1224]: info: sendMpdCommand status took 49 milliseconds Dec 27 16:28:51 volumio3b volumio[1224]: verbose: ControllerMpd::parseState Dec 27 16:28:51 volumio3b volumio[1224]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 27 16:28:51 volumio3b volumio[1224]: verbose: ControllerMpd::parseState Dec 27 16:28:51 volumio3b volumio[1224]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 27 16:28:51 volumio3b volumio[1224]: verbose: ControllerMpd::parseState Dec 27 16:28:51 volumio3b volumio[1224]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 27 16:28:51 volumio3b volumio[1224]: info: Dec 27 16:28:51 volumio3b volumio[1224]: ---------------------------- MPD announces state update: player Dec 27 16:28:51 volumio3b volumio[1224]: info: ControllerMpd::getState Dec 27 16:28:51 volumio3b volumio[1224]: verbose: ControllerMpd::sendMpdCommand status Dec 27 16:28:51 volumio3b volumio[1224]: info: Dec 27 16:28:51 volumio3b volumio[1224]: ---------------------------- MPD announces state update: player Dec 27 16:28:51 volumio3b volumio[1224]: info: ControllerMpd::getState Dec 27 16:28:51 volumio3b volumio[1224]: verbose: ControllerMpd::sendMpdCommand status Dec 27 16:28:51 volumio3b volumio[1224]: info: VolumeController:: Volume=86 Mute =false Dec 27 16:28:51 volumio3b volumio[1224]: info: CoreStateMachine::pushState Dec 27 16:28:51 volumio3b volumio[1224]: info: CorePlayQueue::getTrack 0 Dec 27 16:28:51 volumio3b volumio[1224]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 27 16:28:51 volumio3b volumio[1224]: info: CoreCommandRouter::volumioPushState Dec 27 16:28:51 volumio3b volumio[1224]: info: MRS: Pushing multiroomSync output update for this device Dec 27 16:28:51 volumio3b volumio[1224]: info: MRS: Pushing multiroomSync output Dec 27 16:28:51 volumio3b volumio[1224]: info: CoreCommandRouter::volumioGetState Dec 27 16:28:51 volumio3b volumio[1224]: info: CorePlayQueue::getTrack 0 Dec 27 16:28:51 volumio3b volumio[1224]: info: CoreStateMachine::updateTrackBlock Dec 27 16:28:51 volumio3b volumio[1224]: info: CorePlayQueue::getTrackBlock Dec 27 16:28:51 volumio3b volumio[1224]: info: CoreCommandRouter::volumioRetrievevolume Dec 27 16:28:51 volumio3b volumio[1224]: info: sendMpdCommand status took 335 milliseconds Dec 27 16:28:51 volumio3b volumio[1224]: info: sendMpdCommand playlistinfo took 296 milliseconds Dec 27 16:28:51 volumio3b volumio[1224]: info: sendMpdCommand playlistinfo took 300 milliseconds Dec 27 16:28:51 volumio3b volumio[1224]: info: sendMpdCommand playlistinfo took 299 milliseconds Dec 27 16:28:51 volumio3b volumio[1224]: info: sendMpdCommand status took 297 milliseconds Dec 27 16:28:51 volumio3b volumio[1224]: info: sendMpdCommand status took 259 milliseconds Dec 27 16:28:51 volumio3b volumio[1224]: verbose: ControllerMpd::parseState Dec 27 16:28:51 volumio3b volumio[1224]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 27 16:28:51 volumio3b volumio[1224]: verbose: ControllerMpd::parseTrackInfo Dec 27 16:28:51 volumio3b volumio[1224]: verbose: ControllerMpd::parseTrackInfo Dec 27 16:28:51 volumio3b volumio[1224]: verbose: ControllerMpd::parseTrackInfo Dec 27 16:28:51 volumio3b volumio[1224]: verbose: ControllerMpd::parseState Dec 27 16:28:51 volumio3b volumio[1224]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 27 16:28:51 volumio3b volumio[1224]: verbose: ControllerMpd::parseState Dec 27 16:28:51 volumio3b volumio[1224]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 27 16:28:51 volumio3b volumio[1224]: info: ControllerMpd::pushState Dec 27 16:28:51 volumio3b volumio[1224]: info: CoreCommandRouter::servicePushState Dec 27 16:28:51 volumio3b volumio[1224]: info: CorePlayQueue::getTrack 0 Dec 27 16:28:51 volumio3b volumio[1224]: verbose: STATE SERVICE {"status":"play","position":0,"seek":710,"duration":221,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"Daydreams","artist":"Adele","album":"19","uri":"USB/6C52-A152/Music/Adele - 19/01 Daydreams.mp3","trackType":"mp3"} Dec 27 16:28:51 volumio3b volumio[1224]: verbose: CURRENT POSITION 0 Dec 27 16:28:51 volumio3b volumio[1224]: info: CoreStateMachine::syncState stateService play Dec 27 16:28:51 volumio3b volumio[1224]: info: CoreStateMachine::syncState currentStatus stop Dec 27 16:28:51 volumio3b volumio[1224]: info: ControllerMpd::pushState Dec 27 16:28:51 volumio3b volumio[1224]: info: CoreCommandRouter::servicePushState Dec 27 16:28:51 volumio3b volumio[1224]: info: CorePlayQueue::getTrack 0 Dec 27 16:28:51 volumio3b volumio[1224]: verbose: STATE SERVICE {"status":"play","position":0,"seek":802,"duration":221,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"Daydreams","artist":"Adele","album":"19","uri":"USB/6C52-A152/Music/Adele - 19/01 Daydreams.mp3","trackType":"mp3"} Dec 27 16:28:51 volumio3b volumio[1224]: verbose: CURRENT POSITION 0 Dec 27 16:28:51 volumio3b volumio[1224]: info: CoreStateMachine::syncState stateService play Dec 27 16:28:51 volumio3b volumio[1224]: info: CoreStateMachine::syncState currentStatus play Dec 27 16:28:51 volumio3b volumio[1224]: info: Received an update from plugin. extracting info from payload Dec 27 16:28:51 volumio3b volumio[1224]: info: CoreStateMachine::pushState Dec 27 16:28:51 volumio3b volumio[1224]: info: CorePlayQueue::getTrack 0 Dec 27 16:28:51 volumio3b volumio[1224]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 27 16:28:51 volumio3b volumio[1224]: info: CoreCommandRouter::volumioPushState Dec 27 16:28:51 volumio3b volumio[1224]: info: MRS: Pushing multiroomSync output update for this device Dec 27 16:28:51 volumio3b volumio[1224]: info: MRS: Pushing multiroomSync output Dec 27 16:28:51 volumio3b volumio[1224]: info: CoreCommandRouter::volumioGetState Dec 27 16:28:51 volumio3b volumio[1224]: info: CorePlayQueue::getTrack 0 Dec 27 16:28:51 volumio3b volumio[1224]: info: CoreStateMachine::pushState Dec 27 16:28:51 volumio3b volumio[1224]: info: CorePlayQueue::getTrack 0 Dec 27 16:28:51 volumio3b volumio[1224]: info: CoreCommandRouter::volumioPushState Dec 27 16:28:51 volumio3b volumio[1224]: info: MRS: Pushing multiroomSync output update for this device Dec 27 16:28:51 volumio3b volumio[1224]: info: MRS: Pushing multiroomSync output Dec 27 16:28:51 volumio3b volumio[1224]: info: CoreCommandRouter::volumioGetState Dec 27 16:28:51 volumio3b volumio[1224]: info: CorePlayQueue::getTrack 0 Dec 27 16:28:51 volumio3b volumio[1224]: info: ControllerMpd::pushState Dec 27 16:28:51 volumio3b volumio[1224]: info: CoreCommandRouter::servicePushState Dec 27 16:28:51 volumio3b volumio[1224]: info: CorePlayQueue::getTrack 0 Dec 27 16:28:51 volumio3b volumio[1224]: verbose: STATE SERVICE {"status":"play","position":0,"seek":802,"duration":221,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"Daydreams","artist":"Adele","album":"19","uri":"USB/6C52-A152/Music/Adele - 19/01 Daydreams.mp3","trackType":"mp3"} Dec 27 16:28:51 volumio3b volumio[1224]: verbose: CURRENT POSITION 0 Dec 27 16:28:51 volumio3b volumio[1224]: info: CoreStateMachine::syncState stateService play Dec 27 16:28:51 volumio3b volumio[1224]: info: CoreStateMachine::syncState currentStatus play Dec 27 16:28:51 volumio3b volumio[1224]: info: Received an update from plugin. extracting info from payload Dec 27 16:28:51 volumio3b volumio[1224]: info: CoreStateMachine::pushState Dec 27 16:28:51 volumio3b volumio[1224]: info: CorePlayQueue::getTrack 0 Dec 27 16:28:51 volumio3b volumio[1224]: info: CoreCommandRouter::volumioPushState Dec 27 16:28:51 volumio3b volumio[1224]: info: MRS: Pushing multiroomSync output update for this device Dec 27 16:28:51 volumio3b volumio[1224]: info: MRS: Pushing multiroomSync output Dec 27 16:28:51 volumio3b volumio[1224]: info: CoreCommandRouter::volumioGetState Dec 27 16:28:51 volumio3b volumio[1224]: info: CorePlayQueue::getTrack 0 Dec 27 16:28:51 volumio3b volumio[1224]: info: CoreStateMachine::pushState Dec 27 16:28:51 volumio3b volumio[1224]: info: CorePlayQueue::getTrack 0 Dec 27 16:28:51 volumio3b volumio[1224]: info: CoreCommandRouter::volumioPushState Dec 27 16:28:51 volumio3b volumio[1224]: info: MRS: Pushing multiroomSync output update for this device Dec 27 16:28:51 volumio3b volumio[1224]: info: MRS: Pushing multiroomSync output Dec 27 16:28:51 volumio3b volumio[1224]: info: CoreCommandRouter::volumioGetState Dec 27 16:28:51 volumio3b volumio[1224]: info: CorePlayQueue::getTrack 0 Dec 27 16:28:51 volumio3b volumio[1224]: info: ------------------------------ 606ms Dec 27 16:28:51 volumio3b volumio[1224]: info: ------------------------------ 703ms Dec 27 16:28:51 volumio3b volumio[1224]: info: ------------------------------ 675ms Dec 27 16:28:51 volumio3b volumio[1224]: info: peppy_screensaver: pushState - status=stop service=mpd volatile=false Dec 27 16:28:51 volumio3b volumio[1224]: info: peppy_screensaver: pushState - status=play service=mpd volatile=false Dec 27 16:28:51 volumio3b volumio[1224]: info: peppy_screensaver: pushState - status=play service=mpd volatile=false Dec 27 16:28:51 volumio3b volumio[1224]: info: peppy_screensaver: pushState - status=play service=mpd volatile=false Dec 27 16:28:51 volumio3b volumio[1224]: info: peppy_screensaver: pushState - status=play service=mpd volatile=false Dec 27 16:28:51 volumio3b volumio[1224]: info: sendMpdCommand playlistinfo took 436 milliseconds Dec 27 16:28:51 volumio3b volumio[1224]: info: sendMpdCommand playlistinfo took 434 milliseconds Dec 27 16:28:51 volumio3b volumio[1224]: info: sendMpdCommand playlistinfo took 434 milliseconds Dec 27 16:28:51 volumio3b volumio[1224]: verbose: ControllerMpd::parseTrackInfo Dec 27 16:28:51 volumio3b volumio[1224]: verbose: ControllerMpd::parseTrackInfo Dec 27 16:28:51 volumio3b volumio[1224]: verbose: ControllerMpd::parseTrackInfo Dec 27 16:28:51 volumio3b volumio[1224]: info: ControllerMpd::pushState Dec 27 16:28:51 volumio3b volumio[1224]: info: CoreCommandRouter::servicePushState Dec 27 16:28:51 volumio3b volumio[1224]: info: CorePlayQueue::getTrack 0 Dec 27 16:28:51 volumio3b volumio[1224]: verbose: STATE SERVICE {"status":"play","position":0,"seek":802,"duration":221,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"Daydreams","artist":"Adele","album":"19","uri":"USB/6C52-A152/Music/Adele - 19/01 Daydreams.mp3","trackType":"mp3"} Dec 27 16:28:51 volumio3b volumio[1224]: verbose: CURRENT POSITION 0 Dec 27 16:28:51 volumio3b volumio[1224]: info: CoreStateMachine::syncState stateService play Dec 27 16:28:51 volumio3b volumio[1224]: info: CoreStateMachine::syncState currentStatus play Dec 27 16:28:51 volumio3b volumio[1224]: info: Received an update from plugin. extracting info from payload Dec 27 16:28:51 volumio3b volumio[1224]: info: CoreStateMachine::pushState Dec 27 16:28:51 volumio3b volumio[1224]: info: CorePlayQueue::getTrack 0 Dec 27 16:28:51 volumio3b volumio[1224]: info: CoreCommandRouter::volumioPushState Dec 27 16:28:51 volumio3b volumio[1224]: info: MRS: Pushing multiroomSync output update for this device Dec 27 16:28:51 volumio3b volumio[1224]: info: MRS: Pushing multiroomSync output Dec 27 16:28:51 volumio3b volumio[1224]: info: CoreCommandRouter::volumioGetState Dec 27 16:28:51 volumio3b volumio[1224]: info: CorePlayQueue::getTrack 0 Dec 27 16:28:51 volumio3b volumio[1224]: info: CoreStateMachine::pushState Dec 27 16:28:51 volumio3b volumio[1224]: info: CorePlayQueue::getTrack 0 Dec 27 16:28:52 volumio3b volumio[1224]: info: CoreCommandRouter::volumioPushState Dec 27 16:28:52 volumio3b volumio[1224]: info: MRS: Pushing multiroomSync output update for this device Dec 27 16:28:52 volumio3b volumio[1224]: info: MRS: Pushing multiroomSync output Dec 27 16:28:52 volumio3b volumio[1224]: info: CoreCommandRouter::volumioGetState Dec 27 16:28:52 volumio3b volumio[1224]: info: CorePlayQueue::getTrack 0 Dec 27 16:28:52 volumio3b volumio[1224]: info: ControllerMpd::pushState Dec 27 16:28:52 volumio3b volumio[1224]: info: CoreCommandRouter::servicePushState Dec 27 16:28:52 volumio3b volumio[1224]: info: CorePlayQueue::getTrack 0 Dec 27 16:28:52 volumio3b volumio[1224]: verbose: STATE SERVICE {"status":"play","position":0,"seek":894,"duration":221,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"Daydreams","artist":"Adele","album":"19","uri":"USB/6C52-A152/Music/Adele - 19/01 Daydreams.mp3","trackType":"mp3"} Dec 27 16:28:52 volumio3b volumio[1224]: verbose: CURRENT POSITION 0 Dec 27 16:28:52 volumio3b volumio[1224]: info: CoreStateMachine::syncState stateService play Dec 27 16:28:52 volumio3b volumio[1224]: info: CoreStateMachine::syncState currentStatus play Dec 27 16:28:52 volumio3b volumio[1224]: info: Received an update from plugin. extracting info from payload Dec 27 16:28:52 volumio3b volumio[1224]: info: CoreStateMachine::pushState Dec 27 16:28:52 volumio3b volumio[1224]: info: CorePlayQueue::getTrack 0 Dec 27 16:28:52 volumio3b volumio[1224]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 27 16:28:52 volumio3b volumio[1224]: info: CoreCommandRouter::volumioPushState Dec 27 16:28:52 volumio3b volumio[1224]: info: MRS: Pushing multiroomSync output update for this device Dec 27 16:28:52 volumio3b volumio[1224]: info: MRS: Pushing multiroomSync output Dec 27 16:28:52 volumio3b volumio[1224]: info: CoreCommandRouter::volumioGetState Dec 27 16:28:52 volumio3b volumio[1224]: info: CorePlayQueue::getTrack 0 Dec 27 16:28:52 volumio3b volumio[1224]: info: CoreStateMachine::pushState Dec 27 16:28:52 volumio3b volumio[1224]: info: CorePlayQueue::getTrack 0 Dec 27 16:28:52 volumio3b volumio[1224]: info: CoreCommandRouter::volumioPushState Dec 27 16:28:52 volumio3b volumio[1224]: info: MRS: Pushing multiroomSync output update for this device Dec 27 16:28:52 volumio3b volumio[1224]: info: MRS: Pushing multiroomSync output Dec 27 16:28:52 volumio3b volumio[1224]: info: CoreCommandRouter::volumioGetState Dec 27 16:28:52 volumio3b volumio[1224]: info: CorePlayQueue::getTrack 0 Dec 27 16:28:52 volumio3b volumio[1224]: info: ControllerMpd::pushState Dec 27 16:28:52 volumio3b volumio[1224]: info: CoreCommandRouter::servicePushState Dec 27 16:28:52 volumio3b volumio[1224]: info: CorePlayQueue::getTrack 0 Dec 27 16:28:52 volumio3b volumio[1224]: verbose: STATE SERVICE {"status":"play","position":0,"seek":894,"duration":221,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"Daydreams","artist":"Adele","album":"19","uri":"USB/6C52-A152/Music/Adele - 19/01 Daydreams.mp3","trackType":"mp3"} Dec 27 16:28:52 volumio3b volumio[1224]: verbose: CURRENT POSITION 0 Dec 27 16:28:52 volumio3b volumio[1224]: info: CoreStateMachine::syncState stateService play Dec 27 16:28:52 volumio3b volumio[1224]: info: CoreStateMachine::syncState currentStatus play Dec 27 16:28:52 volumio3b volumio[1224]: info: Received an update from plugin. extracting info from payload Dec 27 16:28:52 volumio3b volumio[1224]: info: CoreStateMachine::pushState Dec 27 16:28:52 volumio3b volumio[1224]: info: CorePlayQueue::getTrack 0 Dec 27 16:28:52 volumio3b volumio[1224]: info: CoreCommandRouter::volumioPushState Dec 27 16:28:52 volumio3b volumio[1224]: info: MRS: Pushing multiroomSync output update for this device Dec 27 16:28:52 volumio3b volumio[1224]: info: MRS: Pushing multiroomSync output Dec 27 16:28:52 volumio3b volumio[1224]: info: CoreCommandRouter::volumioGetState Dec 27 16:28:52 volumio3b volumio[1224]: info: CorePlayQueue::getTrack 0 Dec 27 16:28:52 volumio3b volumio[1224]: info: CoreStateMachine::pushState Dec 27 16:28:52 volumio3b volumio[1224]: info: CorePlayQueue::getTrack 0 Dec 27 16:28:52 volumio3b volumio[1224]: info: CoreCommandRouter::volumioPushState Dec 27 16:28:52 volumio3b volumio[1224]: info: MRS: Pushing multiroomSync output update for this device Dec 27 16:28:52 volumio3b volumio[1224]: info: MRS: Pushing multiroomSync output Dec 27 16:28:52 volumio3b volumio[1224]: info: CoreCommandRouter::volumioGetState Dec 27 16:28:52 volumio3b volumio[1224]: info: CorePlayQueue::getTrack 0 Dec 27 16:28:52 volumio3b volumio[1224]: info: ------------------------------ 1571ms Dec 27 16:28:52 volumio3b volumio[1224]: info: ------------------------------ 1529ms Dec 27 16:28:52 volumio3b volumio[1224]: info: ------------------------------ 1506ms Dec 27 16:28:52 volumio3b volumio[1224]: error: touch_display: Error waking up the screen: Error: Command failed: /usr/bin/xset -display : s reset dpms force on Dec 27 16:28:52 volumio3b volumio[1224]: /usr/bin/xset: unable to open display ":" Dec 27 16:28:52 volumio3b volumio[1224]: info: peppy_screensaver: pushState - status=play service=mpd volatile=false Dec 27 16:28:52 volumio3b volumio[1224]: info: peppy_screensaver: pushState - status=play service=mpd volatile=false Dec 27 16:28:52 volumio3b volumio[1224]: info: peppy_screensaver: pushState - status=play service=mpd volatile=false Dec 27 16:28:52 volumio3b volumio[1224]: info: peppy_screensaver: pushState - status=play service=mpd volatile=false Dec 27 16:28:52 volumio3b volumio[1224]: info: peppy_screensaver: pushState - status=play service=mpd volatile=false Dec 27 16:28:52 volumio3b volumio[1224]: info: peppy_screensaver: pushState - status=play service=mpd volatile=false Dec 27 16:28:52 volumio3b volumio[1224]: info: VolumeController:: Volume=86 Mute =false Dec 27 16:28:52 volumio3b volumio[1224]: info: CoreStateMachine::pushState Dec 27 16:28:52 volumio3b volumio[1224]: info: CorePlayQueue::getTrack 0 Dec 27 16:28:52 volumio3b volumio[1224]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 27 16:28:52 volumio3b volumio[1224]: info: CoreCommandRouter::volumioPushState Dec 27 16:28:53 volumio3b volumio[1224]: info: MRS: Pushing multiroomSync output update for this device Dec 27 16:28:53 volumio3b volumio[1224]: info: MRS: Pushing multiroomSync output Dec 27 16:28:53 volumio3b volumio[1224]: info: CoreCommandRouter::volumioGetState Dec 27 16:28:53 volumio3b volumio[1224]: info: CorePlayQueue::getTrack 0 Dec 27 16:28:53 volumio3b volumio[1224]: error: touch_display: Error setting screensaver timeout: Error: ENOENT: no such file or directory, stat '/tmp/.X11-unix/X' Dec 27 16:28:53 volumio3b volumio[1224]: info: peppy_screensaver: pushState - status=play service=mpd volatile=false Dec 27 16:28:58 volumio3b volumio[1224]: info: Preload queue cleared Dec 27 16:28:58 volumio3b volumio[1224]: info: CoreCommandRouter::volumioReplaceandPlayItems Dec 27 16:28:58 volumio3b volumio[1224]: info: CoreStateMachine::ClearQueue Dec 27 16:28:58 volumio3b volumio[1224]: info: CoreStateMachine::stop Dec 27 16:28:58 volumio3b volumio[1224]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 27 16:28:58 volumio3b volumio[1224]: info: CoreStateMachine::stPlaybackTimer Dec 27 16:28:58 volumio3b volumio[1224]: info: CoreStateMachine::updateTrackBlock Dec 27 16:28:58 volumio3b volumio[1224]: info: CorePlayQueue::getTrackBlock Dec 27 16:28:58 volumio3b volumio[1224]: info: CoreStateMachine::pushState Dec 27 16:28:58 volumio3b volumio[1224]: info: CorePlayQueue::getTrack 0 Dec 27 16:28:58 volumio3b volumio[1224]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 27 16:28:58 volumio3b volumio[1224]: info: CoreCommandRouter::volumioPushState Dec 27 16:28:58 volumio3b volumio[1224]: info: MRS: Pushing multiroomSync output update for this device Dec 27 16:28:58 volumio3b volumio[1224]: info: MRS: Pushing multiroomSync output Dec 27 16:28:58 volumio3b volumio[1224]: info: CoreCommandRouter::volumioGetState Dec 27 16:28:58 volumio3b volumio[1224]: info: CorePlayQueue::getTrack 0 Dec 27 16:28:58 volumio3b volumio[1224]: info: CoreStateMachine::serviceStop Dec 27 16:28:58 volumio3b volumio[1224]: info: CorePlayQueue::getTrack 0 Dec 27 16:28:58 volumio3b volumio[1224]: info: CoreCommandRouter::serviceStop Dec 27 16:28:58 volumio3b volumio[1224]: info: ControllerMpd::stop Dec 27 16:28:58 volumio3b volumio[1224]: verbose: ControllerMpd::sendMpdCommand stop Dec 27 16:28:58 volumio3b volumio[1224]: info: CorePlayQueue::clearPlayQueue Dec 27 16:28:58 volumio3b volumio[1224]: info: CorePlayQueue::saveQueue Dec 27 16:28:58 volumio3b volumio[1224]: info: CoreCommandRouter::volumioPushQueue Dec 27 16:28:58 volumio3b volumio[1224]: info: CoreStateMachine::addQueueItems Dec 27 16:28:58 volumio3b volumio[1224]: info: CorePlayQueue::addQueueItems Dec 27 16:28:58 volumio3b volumio[1224]: info: Preload queue cleared Dec 27 16:28:58 volumio3b volumio[1224]: info: Adding Item to queue: music-library/USB/6C52-A152/Music/Adele - 19/01 Daydreams.mp3 Dec 27 16:28:58 volumio3b volumio[1224]: info: Using cached record of: music-library/USB/6C52-A152/Music/Adele - 19/01 Daydreams.mp3 Dec 27 16:28:58 volumio3b volumio[1224]: info: CoreCommandRouter::volumioPushQueue Dec 27 16:28:58 volumio3b volumio[1224]: info: CorePlayQueue::saveQueue Dec 27 16:28:58 volumio3b volumio[1224]: info: CoreStateMachine::updateTrackBlock Dec 27 16:28:58 volumio3b volumio[1224]: info: CorePlayQueue::getTrackBlock Dec 27 16:28:58 volumio3b volumio[1224]: info: CoreCommandRouter::volumioGetState Dec 27 16:28:58 volumio3b volumio[1224]: info: CorePlayQueue::getTrack 0 Dec 27 16:28:58 volumio3b volumio[1224]: info: CoreCommandRouter::executeOnPlugin: play , [object Object] Dec 27 16:28:58 volumio3b volumio[1224]: info: CoreCommandRouter::volumioPlay Dec 27 16:28:58 volumio3b volumio[1224]: info: CoreStateMachine::play index 0 Dec 27 16:28:58 volumio3b volumio[1224]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 27 16:28:58 volumio3b volumio[1224]: info: CoreStateMachine::addQueueItems Dec 27 16:28:58 volumio3b volumio[1224]: info: CorePlayQueue::addQueueItems Dec 27 16:28:58 volumio3b volumio[1224]: info: Preload queue cleared Dec 27 16:28:58 volumio3b volumio[1224]: info: Adding Item to queue: music-library/USB/6C52-A152/Music/Adele - 19/02 Best For Last.mp3 Dec 27 16:28:58 volumio3b volumio[1224]: info: Using cached record of: music-library/USB/6C52-A152/Music/Adele - 19/02 Best For Last.mp3 Dec 27 16:28:58 volumio3b volumio[1224]: info: Adding Item to queue: music-library/USB/6C52-A152/Music/Adele - 19/03 Chasing Pavements.mp3 Dec 27 16:28:58 volumio3b volumio[1224]: info: Using cached record of: music-library/USB/6C52-A152/Music/Adele - 19/03 Chasing Pavements.mp3 Dec 27 16:28:58 volumio3b volumio[1224]: info: Adding Item to queue: music-library/USB/6C52-A152/Music/Adele - 19/04 Cold Shoulder.mp3 Dec 27 16:28:58 volumio3b volumio[1224]: info: Using cached record of: music-library/USB/6C52-A152/Music/Adele - 19/04 Cold Shoulder.mp3 Dec 27 16:28:58 volumio3b volumio[1224]: info: Adding Item to queue: music-library/USB/6C52-A152/Music/Adele - 19/05 Crazy For You.mp3 Dec 27 16:28:58 volumio3b volumio[1224]: info: Using cached record of: music-library/USB/6C52-A152/Music/Adele - 19/05 Crazy For You.mp3 Dec 27 16:28:58 volumio3b volumio[1224]: info: Adding Item to queue: music-library/USB/6C52-A152/Music/Adele - 19/06 Melt My Heart To Stone.mp3 Dec 27 16:28:58 volumio3b volumio[1224]: info: Using cached record of: music-library/USB/6C52-A152/Music/Adele - 19/06 Melt My Heart To Stone.mp3 Dec 27 16:28:58 volumio3b volumio[1224]: info: Adding Item to queue: music-library/USB/6C52-A152/Music/Adele - 19/07 First Love.mp3 Dec 27 16:28:58 volumio3b volumio[1224]: info: Using cached record of: music-library/USB/6C52-A152/Music/Adele - 19/07 First Love.mp3 Dec 27 16:28:58 volumio3b volumio[1224]: info: Adding Item to queue: music-library/USB/6C52-A152/Music/Adele - 19/08 Right As Rain.mp3 Dec 27 16:28:58 volumio3b volumio[1224]: info: Using cached record of: music-library/USB/6C52-A152/Music/Adele - 19/08 Right As Rain.mp3 Dec 27 16:28:58 volumio3b volumio[1224]: info: Adding Item to queue: music-library/USB/6C52-A152/Music/Adele - 19/09 Make You Feel My Love.mp3 Dec 27 16:28:58 volumio3b volumio[1224]: info: Using cached record of: music-library/USB/6C52-A152/Music/Adele - 19/09 Make You Feel My Love.mp3 Dec 27 16:28:58 volumio3b volumio[1224]: info: Adding Item to queue: music-library/USB/6C52-A152/Music/Adele - 19/10 My Same.mp3 Dec 27 16:28:58 volumio3b volumio[1224]: info: Using cached record of: music-library/USB/6C52-A152/Music/Adele - 19/10 My Same.mp3 Dec 27 16:28:58 volumio3b volumio[1224]: info: Adding Item to queue: music-library/USB/6C52-A152/Music/Adele - 19/11 Tired.mp3 Dec 27 16:28:58 volumio3b volumio[1224]: info: Using cached record of: music-library/USB/6C52-A152/Music/Adele - 19/11 Tired.mp3 Dec 27 16:28:58 volumio3b volumio[1224]: info: Adding Item to queue: music-library/USB/6C52-A152/Music/Adele - 19/12 Hometown Glory.mp3 Dec 27 16:28:58 volumio3b volumio[1224]: info: Using cached record of: music-library/USB/6C52-A152/Music/Adele - 19/12 Hometown Glory.mp3 Dec 27 16:28:58 volumio3b volumio[1224]: info: CoreStateMachine::stop Dec 27 16:28:58 volumio3b volumio[1224]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 27 16:28:58 volumio3b volumio[1224]: info: CoreCommandRouter::volumioPushQueue Dec 27 16:28:58 volumio3b volumio[1224]: info: CorePlayQueue::saveQueue Dec 27 16:28:58 volumio3b volumio[1224]: info: CoreStateMachine::play index undefined Dec 27 16:28:58 volumio3b volumio[1224]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 27 16:28:58 volumio3b volumio[1224]: info: CoreStateMachine::updateTrackBlock Dec 27 16:28:58 volumio3b volumio[1224]: info: CorePlayQueue::getTrackBlock Dec 27 16:28:58 volumio3b volumio[1224]: info: CorePlayQueue::getTrack 0 Dec 27 16:28:58 volumio3b volumio[1224]: info: CoreStateMachine::startPlaybackTimer Dec 27 16:28:58 volumio3b volumio[1224]: info: CorePlayQueue::getTrack 0 Dec 27 16:28:58 volumio3b volumio[1224]: verbose: ControllerMpd::clearAddPlayTracks USB/6C52-A152/Music/Adele - 19/01 Daydreams.mp3 Dec 27 16:28:58 volumio3b volumio[1224]: verbose: ControllerMpd::sendMpdCommand stop Dec 27 16:28:58 volumio3b volumio[1224]: info: peppy_screensaver: pushState - status=stop service=mpd volatile=false Dec 27 16:28:58 volumio3b volumio[1224]: info: Dec 27 16:28:58 volumio3b volumio[1224]: ---------------------------- MPD announces state update: player Dec 27 16:28:58 volumio3b volumio[1224]: info: sendMpdCommand stop took 349 milliseconds Dec 27 16:28:58 volumio3b volumio[1224]: info: ControllerMpd::getState Dec 27 16:28:58 volumio3b volumio[1224]: verbose: ControllerMpd::sendMpdCommand status Dec 27 16:28:58 volumio3b volumio[1224]: info: sendMpdCommand stop took 157 milliseconds Dec 27 16:28:58 volumio3b volumio[1224]: verbose: ControllerMpd::sendMpdCommand clear Dec 27 16:28:58 volumio3b volumio[1224]: info: Dec 27 16:28:58 volumio3b volumio[1224]: ---------------------------- MPD announces state update: player Dec 27 16:28:58 volumio3b volumio[1224]: info: ControllerMpd::getState Dec 27 16:28:58 volumio3b volumio[1224]: verbose: ControllerMpd::sendMpdCommand status Dec 27 16:28:58 volumio3b volumio[1224]: info: Dec 27 16:28:58 volumio3b volumio[1224]: ---------------------------- MPD announces state update: player Dec 27 16:28:58 volumio3b volumio[1224]: info: ControllerMpd::getState Dec 27 16:28:58 volumio3b volumio[1224]: verbose: ControllerMpd::sendMpdCommand status Dec 27 16:28:58 volumio3b volumio[1224]: info: Dec 27 16:28:58 volumio3b volumio[1224]: ---------------------------- MPD announces system playlist update Dec 27 16:28:58 volumio3b volumio[1224]: info: Ignoring MPD Status Update Dec 27 16:28:58 volumio3b volumio[1224]: info: sendMpdCommand status took 39 milliseconds Dec 27 16:28:58 volumio3b volumio[1224]: info: sendMpdCommand clear took 23 milliseconds Dec 27 16:28:58 volumio3b volumio[1224]: info: sendMpdCommand status took 20 milliseconds Dec 27 16:28:58 volumio3b volumio[1224]: info: sendMpdCommand status took 10 milliseconds Dec 27 16:28:58 volumio3b volumio[1224]: verbose: ControllerMpd::parseState Dec 27 16:28:58 volumio3b volumio[1224]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 27 16:28:58 volumio3b volumio[1224]: verbose: ControllerMpd::sendMpdCommand add "USB/6C52-A152/Music/Adele - 19/01 Daydreams.mp3" Dec 27 16:28:58 volumio3b volumio[1224]: verbose: ControllerMpd::parseState Dec 27 16:28:58 volumio3b volumio[1224]: verbose: ControllerMpd::parseState Dec 27 16:28:58 volumio3b volumio[1224]: info: ControllerMpd::pushState Dec 27 16:28:58 volumio3b volumio[1224]: info: CoreCommandRouter::servicePushState Dec 27 16:28:58 volumio3b volumio[1224]: info: CoreStateMachine::pushState Dec 27 16:28:58 volumio3b volumio[1224]: info: CorePlayQueue::getTrack 0 Dec 27 16:28:58 volumio3b volumio[1224]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 27 16:28:58 volumio3b volumio[1224]: info: CoreCommandRouter::volumioPushState Dec 27 16:28:58 volumio3b volumio[1224]: info: MRS: Pushing multiroomSync output update for this device Dec 27 16:28:58 volumio3b volumio[1224]: info: MRS: Pushing multiroomSync output Dec 27 16:28:58 volumio3b volumio[1224]: info: CoreCommandRouter::volumioGetState Dec 27 16:28:58 volumio3b volumio[1224]: info: CorePlayQueue::getTrack 0 Dec 27 16:28:58 volumio3b volumio[1224]: info: CorePlayQueue::getTrack 0 Dec 27 16:28:58 volumio3b volumio[1224]: 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 27 16:28:58 volumio3b volumio[1224]: verbose: CURRENT POSITION 0 Dec 27 16:28:58 volumio3b volumio[1224]: info: CoreStateMachine::syncState stateService stop Dec 27 16:28:58 volumio3b volumio[1224]: info: CoreStateMachine::syncState currentStatus stop Dec 27 16:28:58 volumio3b volumio[1224]: info: CoreStateMachine::pushState Dec 27 16:28:58 volumio3b volumio[1224]: info: CorePlayQueue::getTrack 0 Dec 27 16:28:58 volumio3b volumio[1224]: info: CoreCommandRouter::volumioPushState Dec 27 16:28:58 volumio3b volumio[1224]: info: MRS: Pushing multiroomSync output update for this device Dec 27 16:28:58 volumio3b volumio[1224]: info: MRS: Pushing multiroomSync output Dec 27 16:28:58 volumio3b volumio[1224]: info: CoreCommandRouter::volumioGetState Dec 27 16:28:58 volumio3b volumio[1224]: info: CorePlayQueue::getTrack 0 Dec 27 16:28:58 volumio3b volumio[1224]: info: No code Dec 27 16:28:58 volumio3b volumio[1224]: info: CoreStateMachine::pushState Dec 27 16:28:58 volumio3b volumio[1224]: info: CorePlayQueue::getTrack 0 Dec 27 16:28:58 volumio3b volumio[1224]: info: CoreCommandRouter::volumioPushState Dec 27 16:28:58 volumio3b volumio[1224]: info: MRS: Pushing multiroomSync output update for this device Dec 27 16:28:58 volumio3b volumio[1224]: info: MRS: Pushing multiroomSync output Dec 27 16:28:58 volumio3b volumio[1224]: info: CoreCommandRouter::volumioGetState Dec 27 16:28:58 volumio3b volumio[1224]: info: CorePlayQueue::getTrack 0 Dec 27 16:28:58 volumio3b volumio[1224]: info: ControllerMpd::pushState Dec 27 16:28:58 volumio3b volumio[1224]: info: CoreCommandRouter::servicePushState Dec 27 16:28:58 volumio3b volumio[1224]: info: CoreStateMachine::pushState Dec 27 16:28:58 volumio3b volumio[1224]: info: CorePlayQueue::getTrack 0 Dec 27 16:28:58 volumio3b volumio[1224]: info: CoreCommandRouter::volumioPushState Dec 27 16:28:58 volumio3b volumio[1224]: info: MRS: Pushing multiroomSync output update for this device Dec 27 16:28:58 volumio3b volumio[1224]: info: MRS: Pushing multiroomSync output Dec 27 16:28:58 volumio3b volumio[1224]: info: CoreCommandRouter::volumioGetState Dec 27 16:28:58 volumio3b volumio[1224]: info: CorePlayQueue::getTrack 0 Dec 27 16:28:58 volumio3b volumio[1224]: info: CorePlayQueue::getTrack 0 Dec 27 16:28:58 volumio3b volumio[1224]: 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 27 16:28:58 volumio3b volumio[1224]: verbose: CURRENT POSITION 0 Dec 27 16:28:58 volumio3b volumio[1224]: info: CoreStateMachine::syncState stateService stop Dec 27 16:28:58 volumio3b volumio[1224]: info: CoreStateMachine::syncState currentStatus stop Dec 27 16:28:58 volumio3b volumio[1224]: info: CoreStateMachine::pushState Dec 27 16:28:58 volumio3b volumio[1224]: info: CorePlayQueue::getTrack 0 Dec 27 16:28:59 volumio3b volumio[1224]: info: CoreCommandRouter::volumioPushState Dec 27 16:28:59 volumio3b volumio[1224]: info: MRS: Pushing multiroomSync output update for this device Dec 27 16:28:59 volumio3b volumio[1224]: info: MRS: Pushing multiroomSync output Dec 27 16:28:59 volumio3b volumio[1224]: info: CoreCommandRouter::volumioGetState Dec 27 16:28:59 volumio3b volumio[1224]: info: CorePlayQueue::getTrack 0 Dec 27 16:28:59 volumio3b volumio[1224]: info: No code Dec 27 16:28:59 volumio3b volumio[1224]: info: CoreStateMachine::pushState Dec 27 16:28:59 volumio3b volumio[1224]: info: CorePlayQueue::getTrack 0 Dec 27 16:28:59 volumio3b volumio[1224]: info: CoreCommandRouter::volumioPushState Dec 27 16:28:59 volumio3b volumio[1224]: info: MRS: Pushing multiroomSync output update for this device Dec 27 16:28:59 volumio3b volumio[1224]: info: MRS: Pushing multiroomSync output Dec 27 16:28:59 volumio3b volumio[1224]: info: CoreCommandRouter::volumioGetState Dec 27 16:28:59 volumio3b volumio[1224]: info: CorePlayQueue::getTrack 0 Dec 27 16:28:59 volumio3b volumio[1224]: info: ------------------------------ 1093ms Dec 27 16:28:59 volumio3b volumio[1224]: info: ------------------------------ 1090ms Dec 27 16:28:59 volumio3b volumio[1224]: info: Dec 27 16:28:59 volumio3b volumio[1224]: ---------------------------- MPD announces system playlist update Dec 27 16:28:59 volumio3b volumio[1224]: info: Ignoring MPD Status Update Dec 27 16:28:59 volumio3b volumio[1224]: info: Dec 27 16:28:59 volumio3b volumio[1224]: ---------------------------- MPD announces system playlist update Dec 27 16:28:59 volumio3b volumio[1224]: info: Ignoring MPD Status Update Dec 27 16:28:59 volumio3b volumio[1224]: error: touch_display: Error setting screensaver timeout: Error: ENOENT: no such file or directory, stat '/tmp/.X11-unix/X' Dec 27 16:29:00 volumio3b volumio[1224]: error: updateQueue error: null Dec 27 16:29:00 volumio3b volumio[1224]: info: Dec 27 16:29:00 volumio3b volumio[1224]: ---------------------------- MPD announces system playlist update Dec 27 16:29:00 volumio3b volumio[1224]: info: Ignoring MPD Status Update Dec 27 16:29:00 volumio3b volumio[1224]: info: ------------------------------ 1229ms Dec 27 16:29:00 volumio3b volumio[1224]: info: sendMpdCommand playlistinfo took 1227 milliseconds Dec 27 16:29:00 volumio3b volumio[1224]: info: sendMpdCommand add "USB/6C52-A152/Music/Adele - 19/01 Daydreams.mp3" took 1227 milliseconds Dec 27 16:29:00 volumio3b volumio[1224]: info: ------------------------------ 144ms Dec 27 16:29:00 volumio3b volumio[1224]: info: ------------------------------ 137ms Dec 27 16:29:00 volumio3b volumio[1224]: verbose: ControllerMpd::parseTrackInfo Dec 27 16:29:00 volumio3b volumio[1224]: verbose: ControllerMpd::sendMpdCommand play Dec 27 16:29:00 volumio3b volumio[1224]: error: ControllerMpd::pushError: TypeError: Cannot read properties of undefined (reading 'split') Dec 27 16:29:00 volumio3b volumio[1224]: info: ------------------------------ 1277ms Dec 27 16:29:00 volumio3b volumio[1224]: info: Dec 27 16:29:00 volumio3b volumio[1224]: ---------------------------- MPD announces system playlist update Dec 27 16:29:00 volumio3b volumio[1224]: info: Ignoring MPD Status Update Dec 27 16:29:00 volumio3b volumio[1224]: info: Dec 27 16:29:00 volumio3b volumio[1224]: ---------------------------- MPD announces system playlist update Dec 27 16:29:00 volumio3b volumio[1224]: info: Ignoring MPD Status Update Dec 27 16:29:00 volumio3b volumio[1224]: info: peppy_screensaver: pushState - status=stop service=mpd volatile=false Dec 27 16:29:00 volumio3b volumio[1224]: info: peppy_screensaver: pushState - status=stop service=mpd volatile=false Dec 27 16:29:00 volumio3b volumio[1224]: info: peppy_screensaver: pushState - status=stop service=mpd volatile=false Dec 27 16:29:00 volumio3b volumio[1224]: info: peppy_screensaver: pushState - status=stop service=mpd volatile=false Dec 27 16:29:00 volumio3b volumio[1224]: info: peppy_screensaver: pushState - status=stop service=mpd volatile=false Dec 27 16:29:00 volumio3b volumio[1224]: info: peppy_screensaver: pushState - status=stop service=mpd volatile=false Dec 27 16:29:01 volumio3b volumio[1224]: info: Dec 27 16:29:01 volumio3b volumio[1224]: ---------------------------- MPD announces state update: player Dec 27 16:29:01 volumio3b volumio[1224]: info: Dec 27 16:29:01 volumio3b volumio[1224]: ---------------------------- MPD announces state update: player Dec 27 16:29:01 volumio3b volumio[1224]: info: ------------------------------ 1122ms Dec 27 16:29:01 volumio3b volumio[1224]: info: sendMpdCommand play took 1095 milliseconds Dec 27 16:29:01 volumio3b volumio[1224]: info: ControllerMpd::getState Dec 27 16:29:01 volumio3b volumio[1224]: verbose: ControllerMpd::sendMpdCommand status Dec 27 16:29:01 volumio3b volumio[1224]: info: ------------------------------ 1037ms Dec 27 16:29:01 volumio3b volumio[1224]: info: ControllerMpd::getState Dec 27 16:29:01 volumio3b volumio[1224]: verbose: ControllerMpd::sendMpdCommand status Dec 27 16:29:01 volumio3b volumio[1224]: info: ------------------------------ 1036ms Dec 27 16:29:01 volumio3b volumio[1224]: info: Dec 27 16:29:01 volumio3b volumio[1224]: ---------------------------- MPD announces state update: player Dec 27 16:29:01 volumio3b volumio[1224]: info: ControllerMpd::getState Dec 27 16:29:01 volumio3b volumio[1224]: verbose: ControllerMpd::sendMpdCommand status Dec 27 16:29:01 volumio3b volumio[1224]: info: Dec 27 16:29:01 volumio3b volumio[1224]: ---------------------------- MPD announces state update: player Dec 27 16:29:01 volumio3b volumio[1224]: info: ControllerMpd::getState Dec 27 16:29:01 volumio3b volumio[1224]: verbose: ControllerMpd::sendMpdCommand status Dec 27 16:29:01 volumio3b volumio[1224]: info: sendMpdCommand status took 61 milliseconds Dec 27 16:29:01 volumio3b volumio[1224]: info: sendMpdCommand status took 61 milliseconds Dec 27 16:29:01 volumio3b volumio[1224]: info: sendMpdCommand status took 23 milliseconds Dec 27 16:29:01 volumio3b volumio[1224]: info: sendMpdCommand status took 47 milliseconds Dec 27 16:29:01 volumio3b volumio[1224]: verbose: ControllerMpd::parseState Dec 27 16:29:01 volumio3b volumio[1224]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 27 16:29:01 volumio3b volumio[1224]: verbose: ControllerMpd::parseState Dec 27 16:29:01 volumio3b volumio[1224]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 27 16:29:01 volumio3b volumio[1224]: verbose: ControllerMpd::parseState Dec 27 16:29:01 volumio3b volumio[1224]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 27 16:29:01 volumio3b volumio[1224]: verbose: ControllerMpd::parseState Dec 27 16:29:01 volumio3b volumio[1224]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 27 16:29:01 volumio3b volumio[1224]: info: sendMpdCommand playlistinfo took 34 milliseconds Dec 27 16:29:01 volumio3b volumio[1224]: info: sendMpdCommand playlistinfo took 54 milliseconds Dec 27 16:29:01 volumio3b volumio[1224]: info: sendMpdCommand playlistinfo took 55 milliseconds Dec 27 16:29:01 volumio3b volumio[1224]: info: sendMpdCommand playlistinfo took 55 milliseconds Dec 27 16:29:01 volumio3b volumio[1224]: verbose: ControllerMpd::parseTrackInfo Dec 27 16:29:01 volumio3b volumio[1224]: verbose: ControllerMpd::parseTrackInfo Dec 27 16:29:01 volumio3b volumio[1224]: verbose: ControllerMpd::parseTrackInfo Dec 27 16:29:01 volumio3b volumio[1224]: verbose: ControllerMpd::parseTrackInfo Dec 27 16:29:01 volumio3b volumio[1224]: info: ControllerMpd::pushState Dec 27 16:29:01 volumio3b volumio[1224]: info: CoreCommandRouter::servicePushState Dec 27 16:29:01 volumio3b volumio[1224]: info: CorePlayQueue::getTrack 0 Dec 27 16:29:01 volumio3b volumio[1224]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1719,"duration":221,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"Daydreams","artist":"Adele","album":"19","uri":"USB/6C52-A152/Music/Adele - 19/01 Daydreams.mp3","trackType":"mp3"} Dec 27 16:29:01 volumio3b volumio[1224]: verbose: CURRENT POSITION 0 Dec 27 16:29:01 volumio3b volumio[1224]: info: CoreStateMachine::syncState stateService play Dec 27 16:29:01 volumio3b volumio[1224]: info: CoreStateMachine::syncState currentStatus stop Dec 27 16:29:01 volumio3b volumio[1224]: info: ControllerMpd::pushState Dec 27 16:29:01 volumio3b volumio[1224]: info: CoreCommandRouter::servicePushState Dec 27 16:29:01 volumio3b volumio[1224]: info: CorePlayQueue::getTrack 0 Dec 27 16:29:01 volumio3b volumio[1224]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1719,"duration":221,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"Daydreams","artist":"Adele","album":"19","uri":"USB/6C52-A152/Music/Adele - 19/01 Daydreams.mp3","trackType":"mp3"} Dec 27 16:29:01 volumio3b volumio[1224]: verbose: CURRENT POSITION 0 Dec 27 16:29:01 volumio3b volumio[1224]: info: CoreStateMachine::syncState stateService play Dec 27 16:29:01 volumio3b volumio[1224]: info: CoreStateMachine::syncState currentStatus play Dec 27 16:29:01 volumio3b volumio[1224]: info: Received an update from plugin. extracting info from payload Dec 27 16:29:01 volumio3b volumio[1224]: info: CoreStateMachine::pushState Dec 27 16:29:01 volumio3b volumio[1224]: info: CorePlayQueue::getTrack 0 Dec 27 16:29:01 volumio3b volumio[1224]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 27 16:29:01 volumio3b volumio[1224]: info: CoreCommandRouter::volumioPushState Dec 27 16:29:01 volumio3b volumio[1224]: info: MRS: Pushing multiroomSync output update for this device Dec 27 16:29:01 volumio3b volumio[1224]: info: MRS: Pushing multiroomSync output Dec 27 16:29:01 volumio3b volumio[1224]: info: CoreCommandRouter::volumioGetState Dec 27 16:29:01 volumio3b volumio[1224]: info: CorePlayQueue::getTrack 0 Dec 27 16:29:01 volumio3b volumio[1224]: info: CoreStateMachine::pushState Dec 27 16:29:01 volumio3b volumio[1224]: info: CorePlayQueue::getTrack 0 Dec 27 16:29:01 volumio3b volumio[1224]: info: CoreCommandRouter::volumioPushState Dec 27 16:29:01 volumio3b volumio[1224]: info: MRS: Pushing multiroomSync output update for this device Dec 27 16:29:01 volumio3b volumio[1224]: info: MRS: Pushing multiroomSync output Dec 27 16:29:01 volumio3b volumio[1224]: info: CoreCommandRouter::volumioGetState Dec 27 16:29:01 volumio3b volumio[1224]: info: CorePlayQueue::getTrack 0 Dec 27 16:29:01 volumio3b volumio[1224]: info: ControllerMpd::pushState Dec 27 16:29:01 volumio3b volumio[1224]: info: CoreCommandRouter::servicePushState Dec 27 16:29:01 volumio3b volumio[1224]: info: CorePlayQueue::getTrack 0 Dec 27 16:29:01 volumio3b volumio[1224]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1719,"duration":221,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"Daydreams","artist":"Adele","album":"19","uri":"USB/6C52-A152/Music/Adele - 19/01 Daydreams.mp3","trackType":"mp3"} Dec 27 16:29:01 volumio3b volumio[1224]: verbose: CURRENT POSITION 0 Dec 27 16:29:01 volumio3b volumio[1224]: info: CoreStateMachine::syncState stateService play Dec 27 16:29:01 volumio3b volumio[1224]: info: CoreStateMachine::syncState currentStatus play Dec 27 16:29:01 volumio3b volumio[1224]: info: Received an update from plugin. extracting info from payload Dec 27 16:29:01 volumio3b volumio[1224]: info: CoreStateMachine::pushState Dec 27 16:29:01 volumio3b volumio[1224]: info: CorePlayQueue::getTrack 0 Dec 27 16:29:01 volumio3b volumio[1224]: info: CoreCommandRouter::volumioPushState Dec 27 16:29:01 volumio3b volumio[1224]: info: MRS: Pushing multiroomSync output update for this device Dec 27 16:29:01 volumio3b volumio[1224]: info: MRS: Pushing multiroomSync output Dec 27 16:29:01 volumio3b volumio[1224]: info: CoreCommandRouter::volumioGetState Dec 27 16:29:01 volumio3b volumio[1224]: info: CorePlayQueue::getTrack 0 Dec 27 16:29:01 volumio3b volumio[1224]: info: CoreStateMachine::pushState Dec 27 16:29:01 volumio3b volumio[1224]: info: CorePlayQueue::getTrack 0 Dec 27 16:29:01 volumio3b volumio[1224]: info: CoreCommandRouter::volumioPushState Dec 27 16:29:01 volumio3b volumio[1224]: info: MRS: Pushing multiroomSync output update for this device Dec 27 16:29:01 volumio3b volumio[1224]: info: MRS: Pushing multiroomSync output Dec 27 16:29:01 volumio3b volumio[1224]: info: CoreCommandRouter::volumioGetState Dec 27 16:29:01 volumio3b volumio[1224]: info: CorePlayQueue::getTrack 0 Dec 27 16:29:01 volumio3b volumio[1224]: info: ControllerMpd::pushState Dec 27 16:29:01 volumio3b volumio[1224]: info: CoreCommandRouter::servicePushState Dec 27 16:29:01 volumio3b volumio[1224]: info: CorePlayQueue::getTrack 0 Dec 27 16:29:01 volumio3b volumio[1224]: verbose: STATE SERVICE {"status":"play","position":0,"seek":1719,"duration":221,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"192 Kbps","isStreaming":false,"title":"Daydreams","artist":"Adele","album":"19","uri":"USB/6C52-A152/Music/Adele - 19/01 Daydreams.mp3","trackType":"mp3"} Dec 27 16:29:01 volumio3b volumio[1224]: verbose: CURRENT POSITION 0 Dec 27 16:29:01 volumio3b volumio[1224]: info: CoreStateMachine::syncState stateService play Dec 27 16:29:01 volumio3b volumio[1224]: info: CoreStateMachine::syncState currentStatus play Dec 27 16:29:01 volumio3b volumio[1224]: info: Received an update from plugin. extracting info from payload Dec 27 16:29:01 volumio3b volumio[1224]: info: CoreStateMachine::pushState Dec 27 16:29:01 volumio3b volumio[1224]: info: CorePlayQueue::getTrack 0 Dec 27 16:29:01 volumio3b volumio[1224]: info: CoreCommandRouter::volumioPushState Dec 27 16:29:01 volumio3b volumio[1224]: info: MRS: Pushing multiroomSync output update for this device Dec 27 16:29:01 volumio3b volumio[1224]: info: MRS: Pushing multiroomSync output Dec 27 16:29:01 volumio3b volumio[1224]: info: CoreCommandRouter::volumioGetState Dec 27 16:29:01 volumio3b volumio[1224]: info: CorePlayQueue::getTrack 0 Dec 27 16:29:01 volumio3b volumio[1224]: info: CoreStateMachine::pushState Dec 27 16:29:01 volumio3b volumio[1224]: info: CorePlayQueue::getTrack 0 Dec 27 16:29:01 volumio3b volumio[1224]: info: CoreCommandRouter::volumioPushState Dec 27 16:29:01 volumio3b volumio[1224]: info: MRS: Pushing multiroomSync output update for this device Dec 27 16:29:01 volumio3b volumio[1224]: info: MRS: Pushing multiroomSync output Dec 27 16:29:01 volumio3b volumio[1224]: info: CoreCommandRouter::volumioGetState Dec 27 16:29:01 volumio3b volumio[1224]: info: CorePlayQueue::getTrack 0 Dec 27 16:29:01 volumio3b volumio[1224]: info: ------------------------------ 515ms Dec 27 16:29:02 volumio3b volumio[1224]: info: ------------------------------ 1229ms Dec 27 16:29:02 volumio3b volumio[1224]: info: ------------------------------ 1191ms Dec 27 16:29:02 volumio3b volumio[1224]: info: ------------------------------ 1190ms Dec 27 16:29:02 volumio3b volumio[1224]: info: peppy_screensaver: pushState - status=play service=mpd volatile=false Dec 27 16:29:02 volumio3b volumio[1224]: info: peppy_screensaver: pushState - status=play service=mpd volatile=false Dec 27 16:29:02 volumio3b volumio[1224]: info: peppy_screensaver: pushState - status=play service=mpd volatile=false Dec 27 16:29:02 volumio3b volumio[1224]: info: peppy_screensaver: pushState - status=play service=mpd volatile=false Dec 27 16:29:02 volumio3b volumio[1224]: info: peppy_screensaver: pushState - status=play service=mpd volatile=false Dec 27 16:29:02 volumio3b volumio[1224]: info: peppy_screensaver: pushState - status=play service=mpd volatile=false Dec 27 16:29:03 volumio3b volumio[1224]: error: touch_display: Error waking up the screen: Error: Command failed: /usr/bin/xset -display : s reset dpms force on Dec 27 16:29:03 volumio3b volumio[1224]: /usr/bin/xset: unable to open display ":" Dec 27 16:29:03 volumio3b volumio[1224]: error: touch_display: Error setting screensaver timeout: Error: ENOENT: no such file or directory, stat '/tmp/.X11-unix/X' Dec 27 16:29:04 volumio3b volumio[1224]: info: CoreCommandRouter::volumioGetState Dec 27 16:29:04 volumio3b volumio[1224]: info: CorePlayQueue::getTrack 0 Dec 27 16:29:06 volumio3b volumio[1224]: info: Executing endpoint metavolumio Dec 27 16:29:06 volumio3b volumio[1224]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Dec 27 16:29:06 volumio3b volumio[1224]: info: Executing endpoint metavolumio Dec 27 16:29:06 volumio3b volumio[1224]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Dec 27 16:29:06 volumio3b volumio[1224]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 27 16:29:06 volumio3b volumio[1224]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Dec 27 16:29:06 volumio3b volumio[1224]: info: Executing endpoint metavolumio Dec 27 16:29:06 volumio3b volumio[1224]: info: CoreCommandRouter::executeOnPlugin: metavolumio , requestToMetaVolumio Dec 27 16:29:09 volumio3b volumio[1224]: info: touch_display: Un-/commenting gpu_mem settings in /boot/config.txt. Dec 27 16:29:09 volumio3b sudo[3072]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/chmod a+rw /etc/X11/xorg.conf.d/95-touch_display-plugin.conf Dec 27 16:29:09 volumio3b sudo[3072]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 27 16:29:09 volumio3b sudo[3072]: pam_unix(sudo:session): session closed for user root Dec 27 16:29:09 volumio3b volumio[1224]: info: touch_display: Using /boot/config.txt instead of /boot/userconfig.txt. Dec 27 16:29:09 volumio3b sudo[3074]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start getty@tty1.service Dec 27 16:29:09 volumio3b sudo[3074]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 27 16:29:10 volumio3b sudo[3079]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volumio-kiosk.service Dec 27 16:29:10 volumio3b sudo[3079]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 27 16:29:10 volumio3b sudo[3077]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl enable getty@tty1.service Dec 27 16:29:10 volumio3b volumio[1224]: info: touch_display: File permissions for /etc/X11/xorg.conf.d/95-touch_display-plugin.conf set. Dec 27 16:29:10 volumio3b sudo[3077]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Dec 27 16:29:10 volumio3b volumio[1224]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 27 16:29:10 volumio3b systemd[1]: Reloading. Dec 27 16:29:10 volumio3b sudo[3079]: pam_unix(sudo:session): session closed for user root Dec 27 16:29:10 volumio3b volumio[1224]: TypeError: Cannot read properties of undefined (reading 'split') Dec 27 16:29:10 volumio3b volumio[1224]: at /data/plugins/user_interface/touch_display/index.js:1298:37 Dec 27 16:29:10 volumio3b volumio[1224]: at ChildProcess.exithandler (node:child_process:413:7) Dec 27 16:29:10 volumio3b volumio[1224]: at ChildProcess.emit (node:events:514:28) Dec 27 16:29:10 volumio3b volumio[1224]: at maybeClose (node:internal/child_process:1105:16) Dec 27 16:29:10 volumio3b volumio[1224]: at Socket. (node:internal/child_process:457:11) Dec 27 16:29:10 volumio3b volumio[1224]: at Socket.emit (node:events:514:28) Dec 27 16:29:10 volumio3b volumio[1224]: at Pipe. (node:net:337:12) Dec 27 16:29:10 volumio3b volumio[1224]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 27 16:29:11 volumio3b systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 27 16:29:11 volumio3b systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Dec 27 16:29:12 volumio3b sudo[3077]: pam_unix(sudo:session): session closed for user root Dec 27 16:29:12 volumio3b systemd[1]: Created slice system-getty.slice - Slice /system/getty. Dec 27 16:29:12 volumio3b systemd[1]: Started getty@tty1.service - Getty on tty1. Dec 27 16:29:12 volumio3b sudo[3074]: pam_unix(sudo:session): session closed for user root Dec 27 16:29:17 volumio3b sudo[3132]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-12-27 16:28' Dec 27 16:29:17 volumio3b sudo[3132]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm 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="cfdc872d40b979cca36352a7333c940c38dc64b5" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="6cbc2303e10f00c3a01cb7f02c6d12448bd32c62" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri Dec 5 20:42:14 UTC 2025" VOLUMIO_VERSION="4.073" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="67fdc5f60f00b7a328ccd8c4ad441086"