-- Logs begin at Thu 2019-02-14 13:11:59 MSK, end at Thu 2025-12-25 13:14:20 MSK. -- Dec 25 13:13:00 volumio sudo[1904]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 25 13:13:00 volumio sudo[1904]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 25 13:13:00 volumio sudo[1904]: pam_unix(sudo:session): session closed for user root Dec 25 13:13:00 volumio sudo[1906]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 25 13:13:00 volumio sudo[1906]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 25 13:13:00 volumio sudo[1906]: pam_unix(sudo:session): session closed for user root Dec 25 13:13:00 volumio volumio[755]: verbose: New Socket.io Connection to 192.168.1.73 from 192.168.1.3 UA: Mozilla/5.0 (Linux; Android 16; SM-S911B Build/BP2A.250605.031.A3; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/143.0.7499.34 Mobile Safari/537.36 Total Clients: 6 Dec 25 13:13:00 volumio volumio[755]: info: Discovery: adding 19488168-7635-4d2a-b7f5-9ba37f0afde5 Dec 25 13:13:00 volumio volumio[755]: info: Discovery: Found device VolumioRED Dec 25 13:13:00 volumio volumio[755]: info: Discovery: Connecting to remote: 192.168.1.10 Dec 25 13:13:00 volumio volumio[755]: info: CoreCommandRouter::volumioGetState Dec 25 13:13:00 volumio volumio[755]: info: CorePlayQueue::getTrack 0 Dec 25 13:13:00 volumio volumio[755]: info: Discovery: Connected to remote: 192.168.1.10 Dec 25 13:13:00 volumio volumio[755]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Dec 25 13:13:00 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Dec 25 13:13:00 volumio volumio[755]: info: Listing playlists Dec 25 13:13:00 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Dec 25 13:13:00 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Dec 25 13:13:00 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Dec 25 13:13:00 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Dec 25 13:13:00 volumio volumio[755]: info: Updating MyVolumio device info Dec 25 13:13:00 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 25 13:13:00 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 25 13:13:00 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 25 13:13:01 volumio volumio[755]: info: CoreCommandRouter::volumioPause Dec 25 13:13:01 volumio volumio[755]: info: CoreStateMachine::pause Dec 25 13:13:01 volumio volumio[755]: info: CoreStateMachine::stPlaybackTimer Dec 25 13:13:01 volumio volumio[755]: info: CoreStateMachine::servicePause Dec 25 13:13:01 volumio volumio[755]: info: CorePlayQueue::getTrack 0 Dec 25 13:13:01 volumio volumio[755]: info: CoreCommandRouter::servicePause Dec 25 13:13:01 volumio volumio[755]: info: ControllerMpd::pause Dec 25 13:13:01 volumio volumio[755]: verbose: ControllerMpd::sendMpdCommand pause Dec 25 13:13:01 volumio volumio[755]: info: sendMpdCommand pause took 11 milliseconds Dec 25 13:13:01 volumio volumio[755]: info: Dec 25 13:13:01 volumio volumio[755]: ---------------------------- MPD announces state update: player Dec 25 13:13:01 volumio volumio[755]: info: ControllerMpd::getState Dec 25 13:13:01 volumio volumio[755]: verbose: ControllerMpd::sendMpdCommand status Dec 25 13:13:01 volumio volumio[755]: info: Dec 25 13:13:01 volumio volumio[755]: ---------------------------- MPD announces state update: player Dec 25 13:13:01 volumio volumio[755]: info: ControllerMpd::getState Dec 25 13:13:01 volumio volumio[755]: verbose: ControllerMpd::sendMpdCommand status Dec 25 13:13:01 volumio volumio[755]: info: sendMpdCommand status took 3 milliseconds Dec 25 13:13:01 volumio volumio[755]: info: sendMpdCommand status took 2 milliseconds Dec 25 13:13:01 volumio volumio[755]: verbose: ControllerMpd::parseState Dec 25 13:13:01 volumio volumio[755]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 25 13:13:01 volumio volumio[755]: verbose: ControllerMpd::parseState Dec 25 13:13:01 volumio volumio[755]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 25 13:13:01 volumio volumio[755]: info: sendMpdCommand playlistinfo took 2 milliseconds Dec 25 13:13:01 volumio volumio[755]: info: sendMpdCommand playlistinfo took 2 milliseconds Dec 25 13:13:01 volumio volumio[755]: verbose: ControllerMpd::parseTrackInfo Dec 25 13:13:01 volumio volumio[755]: verbose: ControllerMpd::parseTrackInfo Dec 25 13:13:01 volumio volumio[755]: info: ControllerMpd::pushState Dec 25 13:13:01 volumio volumio[755]: info: CoreCommandRouter::servicePushState Dec 25 13:13:01 volumio volumio[755]: info: CorePlayQueue::getTrack 0 Dec 25 13:13:01 volumio volumio[755]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":46262,"duration":2792,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"734 Kbps","isStreaming":false,"title":"Green Bullfrog - The Green Bullfrog Sessions [NSP CD 503].flac","artist":"Green Bullfrog","album":"The Green Bullfrog Sessions [NSP CD 503]","uri":"NAS/DISKSTATION3/DEEP PURPLE/Rainbow - Blackmore/1971 The Green Bullfrog Sessions (1991 Connoisseur Collection)/Green Bullfrog - The Green Bullfrog Sessions [NSP CD 503].flac","trackType":"flac"} Dec 25 13:13:01 volumio volumio[755]: verbose: CURRENT POSITION 0 Dec 25 13:13:01 volumio volumio[755]: info: CoreStateMachine::syncState stateService pause Dec 25 13:13:01 volumio volumio[755]: info: CoreStateMachine::syncState currentStatus pause Dec 25 13:13:01 volumio volumio[755]: info: CoreStateMachine::pushState Dec 25 13:13:01 volumio volumio[755]: info: CorePlayQueue::getTrack 0 Dec 25 13:13:01 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 25 13:13:01 volumio volumio[755]: info: CoreCommandRouter::volumioPushState Dec 25 13:13:01 volumio volumio[755]: info: CoreStateMachine::stPlaybackTimer Dec 25 13:13:01 volumio volumio[755]: info: ControllerMpd::pushState Dec 25 13:13:01 volumio volumio[755]: info: CoreCommandRouter::servicePushState Dec 25 13:13:01 volumio volumio[755]: info: CorePlayQueue::getTrack 0 Dec 25 13:13:01 volumio volumio[755]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":46262,"duration":2792,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"734 Kbps","isStreaming":false,"title":"Green Bullfrog - The Green Bullfrog Sessions [NSP CD 503].flac","artist":"Green Bullfrog","album":"The Green Bullfrog Sessions [NSP CD 503]","uri":"NAS/DISKSTATION3/DEEP PURPLE/Rainbow - Blackmore/1971 The Green Bullfrog Sessions (1991 Connoisseur Collection)/Green Bullfrog - The Green Bullfrog Sessions [NSP CD 503].flac","trackType":"flac"} Dec 25 13:13:01 volumio volumio[755]: verbose: CURRENT POSITION 0 Dec 25 13:13:01 volumio volumio[755]: info: CoreStateMachine::syncState stateService pause Dec 25 13:13:01 volumio volumio[755]: info: CoreStateMachine::syncState currentStatus pause Dec 25 13:13:01 volumio volumio[755]: info: CoreStateMachine::pushState Dec 25 13:13:01 volumio volumio[755]: info: CorePlayQueue::getTrack 0 Dec 25 13:13:01 volumio volumio[755]: info: CoreCommandRouter::volumioPushState Dec 25 13:13:01 volumio volumio[755]: info: CoreStateMachine::stPlaybackTimer Dec 25 13:13:01 volumio volumio[755]: info: ------------------------------ 34ms Dec 25 13:13:01 volumio volumio[755]: info: ------------------------------ 33ms Dec 25 13:13:01 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] on:pushState: previous state was "play" - next is pause Dec 25 13:13:01 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] processResponse: Amp Status is now {"volume":-96,"mute":false,"power":"on","source":"05","Powering":""} Dec 25 13:13:01 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] on:pushState: previous state was "pause" - next is pause Dec 25 13:13:01 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] processResponse: Amp Status is now {"volume":-96,"mute":false,"power":"on","source":"05","Powering":""} Dec 25 13:13:01 volumio volumio[755]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Dec 25 13:13:02 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 25 13:13:02 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Dec 25 13:13:02 volumio python3[524]: Terminated Dec 25 13:13:04 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Dec 25 13:13:04 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Dec 25 13:13:04 volumio sudo[1938]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 25 13:13:04 volumio sudo[1938]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 25 13:13:04 volumio sudo[1938]: pam_unix(sudo:session): session closed for user root Dec 25 13:13:04 volumio sudo[1940]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 25 13:13:04 volumio sudo[1940]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 25 13:13:04 volumio sudo[1940]: pam_unix(sudo:session): session closed for user root Dec 25 13:13:04 volumio volumio[755]: verbose: New Socket.io Connection to 192.168.1.73 from 192.168.1.3 UA: Mozilla/5.0 (Linux; Android 16; SM-S911B Build/BP2A.250605.031.A3; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/143.0.7499.34 Mobile Safari/537.36 Total Clients: 6 Dec 25 13:13:04 volumio volumio[755]: info: [SERIALAMPCONTROLLER] openTcpIp: Connected to: 192.168.1.101:14999 Dec 25 13:13:04 volumio volumio[755]: info: [SERIALAMPCONTROLLER] attachParser: Port is now open. Connecting Parser with delimiter: ; Dec 25 13:13:04 volumio volumio[755]: info: [SERIALAMPCONTROLLER] getAmpStatus: sending status requests to Amp Dec 25 13:13:04 volumio volumio[755]: info: [SERIALAMPCONTROLLER] sendStatusRequest: Sent command for "reqModel": IDM?; Dec 25 13:13:04 volumio volumio[755]: info: [SERIALAMPCONTROLLER] sendStatusRequest: Sent command for "reqPower": Z1POW?; Dec 25 13:13:04 volumio volumio[755]: info: [SERIALAMPCONTROLLER] sendStatusRequest: Sent command for "reqVolume": Z1VOL?; Dec 25 13:13:04 volumio volumio[755]: info: [SERIALAMPCONTROLLER] sendStatusRequest: Sent command for "reqMute": Z1MUT?; Dec 25 13:13:04 volumio volumio[755]: info: [SERIALAMPCONTROLLER] sendStatusRequest: Sent command for "reqSource": Z1INP?; Dec 25 13:13:04 volumio volumio[755]: info: [SERIALAMPCONTROLLER7v1] alsavolume: Set volume "-55" [object Object] Dec 25 13:13:04 volumio volumio[755]: info: [SERIALAMPCONTROLLER7v4] alsavolume: set volume to integer value -140.55 Dec 25 13:13:04 volumio volumio[755]: info: [SERIALAMPCONTROLLER] sendCommand: send volValue,-140.55 Dec 25 13:13:04 volumio volumio[755]: info: [SERIALAMPCONTROLLER] sendCommand: now sending cmdString: Z1VOL-140.0; Dec 25 13:13:04 volumio volumio[755]: info: [SERIALAMPCONTROLLER] sendCommand: sent cmdString: Z1VOL-140.0; Dec 25 13:13:04 volumio volumio[755]: info: [SERIALAMPCONTROLLER] [parser:data]: Listener received: IDMSTR IA Dec 25 13:13:04 volumio volumio[755]: info: [SERIALAMPCONTROLLER] parser:data: no matching regex for: IDMSTR IA Dec 25 13:13:04 volumio volumio[755]: info: [SERIALAMPCONTROLLER] [parser:data]: Listener received: Z1POW1 Dec 25 13:13:04 volumio volumio[755]: info: [SERIALAMPCONTROLLER] parser:data: call processResponse with: respPowerOn Dec 25 13:13:04 volumio volumio[755]: info: [SERIALAMPCONTROLLER] processResponse: Amp signaled PowerOn. Previous state is: on Dec 25 13:13:04 volumio volumio[755]: info: [SERIALAMPCONTROLLER] processResponse: Amp Status is now {"volume":-96,"mute":false,"power":"on","source":"05","Powering":""} Dec 25 13:13:04 volumio volumio[755]: info: [SERIALAMPCONTROLLER] [parser:data]: Listener received: Z1VOL-51.0 Dec 25 13:13:04 volumio volumio[755]: info: [SERIALAMPCONTROLLER] parser:data: call processResponse with: respVolume Dec 25 13:13:04 volumio volumio[755]: info: [SERIALAMPCONTROLLER] processResponse: Amp signaled volume is -51 Dec 25 13:13:04 volumio volumio[755]: info: [SERIALAMPCONTROLLER] getVolumeObject: {"mute":false,"currentDisableVolumeControl":false,"vol":55} Dec 25 13:13:04 volumio volumio[755]: info: CoreStateMachine::pushState Dec 25 13:13:04 volumio volumio[755]: info: CorePlayQueue::getTrack 0 Dec 25 13:13:04 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 25 13:13:04 volumio volumio[755]: info: CoreCommandRouter::volumioPushState Dec 25 13:13:04 volumio volumio[755]: info: [SERIALAMPCONTROLLER] getVolumeObject: {"mute":false,"currentDisableVolumeControl":false,"vol":55} Dec 25 13:13:04 volumio volumio[755]: info: [SERIALAMPCONTROLLER] processResponse: Amp Status is now {"volume":-51,"mute":false,"power":"on","source":"05","Powering":""} Dec 25 13:13:04 volumio volumio[755]: info: [SERIALAMPCONTROLLER] parser:data: call processResponse with: undefined Dec 25 13:13:04 volumio volumio[755]: info: [SERIALAMPCONTROLLER] processResponse: unhandled response "undefined" Dec 25 13:13:04 volumio volumio[755]: info: [SERIALAMPCONTROLLER] processResponse: Amp Status is now {"volume":-51,"mute":false,"power":"on","source":"05","Powering":""} Dec 25 13:13:04 volumio volumio[755]: info: [SERIALAMPCONTROLLER] [parser:data]: Listener received: Z1MUT0 Dec 25 13:13:04 volumio volumio[755]: info: [SERIALAMPCONTROLLER] parser:data: call processResponse with: respMuteOff Dec 25 13:13:04 volumio volumio[755]: info: [SERIALAMPCONTROLLER] processResponse: Amp signaled MuteOff Dec 25 13:13:04 volumio volumio[755]: info: [SERIALAMPCONTROLLER] getVolumeObject: {"mute":false,"currentDisableVolumeControl":false,"vol":55} Dec 25 13:13:04 volumio volumio[755]: info: CoreStateMachine::pushState Dec 25 13:13:04 volumio volumio[755]: info: CorePlayQueue::getTrack 0 Dec 25 13:13:04 volumio volumio[755]: info: CoreCommandRouter::volumioPushState Dec 25 13:13:04 volumio volumio[755]: info: [SERIALAMPCONTROLLER] processResponse: Amp Status is now {"volume":-51,"mute":false,"power":"on","source":"05","Powering":""} Dec 25 13:13:04 volumio volumio[755]: info: [SERIALAMPCONTROLLER] [parser:data]: Listener received: Z1INP05 Dec 25 13:13:04 volumio volumio[755]: info: [SERIALAMPCONTROLLER] parser:data: call processResponse with: respSource Dec 25 13:13:04 volumio volumio[755]: info: [SERIALAMPCONTROLLER] processResponse: Amp signaled source is 05 Dec 25 13:13:04 volumio volumio[755]: info: [SERIALAMPCONTROLLER] processResponse: Amp Status is now {"volume":-51,"mute":false,"power":"on","source":"05","Powering":""} Dec 25 13:13:04 volumio volumio[755]: info: CoreStateMachine::pushState Dec 25 13:13:04 volumio volumio[755]: info: CorePlayQueue::getTrack 0 Dec 25 13:13:04 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 25 13:13:04 volumio volumio[755]: info: CoreCommandRouter::volumioPushState Dec 25 13:13:04 volumio volumio[755]: info: CoreStateMachine::pushState Dec 25 13:13:04 volumio volumio[755]: info: CorePlayQueue::getTrack 0 Dec 25 13:13:04 volumio volumio[755]: info: CoreCommandRouter::volumioPushState Dec 25 13:13:04 volumio volumio[755]: info: CoreStateMachine::pushState Dec 25 13:13:04 volumio volumio[755]: info: CorePlayQueue::getTrack 0 Dec 25 13:13:04 volumio volumio[755]: info: CoreCommandRouter::volumioPushState Dec 25 13:13:04 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 25 13:13:04 volumio volumio[755]: info: [SERIALAMPCONTROLLER] initVolumeSettings: getAlsaCards "2" Dec 25 13:13:04 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getAlsaCards Dec 25 13:13:04 volumio volumio[755]: info: [SERIALAMPCONTROLLER] initVolumeSettings: getAlsaCards [{"id":"0","alsacard":"b1","name":"HDMI"},{"id":"1","alsacard":"Headphones","name":"Headphones"},{"id":"2","alsacard":"sndrpihifiberry","name":"snd_rpi_hifiberry_digi"}] Dec 25 13:13:04 volumio volumio[755]: info: CoreCommandRouter::volumioUpdateVolumeSettings Dec 25 13:13:04 volumio volumio[755]: info: Updating Volume Controller Parameters: Device: 2 Name: snd_rpi_hifiberry_digi Mixer: Max Vol: -15 Vol Curve; Vol Steps: 1 Dec 25 13:13:04 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Dec 25 13:13:04 volumio volumio[755]: info: Enabling external Volume Control Dec 25 13:13:04 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: serialampcontroller , updateVolumeSettings Dec 25 13:13:04 volumio volumio[755]: info: [SERIALAMPCONTROLLER] updateVolumeSettings: received {"pluginType":"system_hardware","pluginName":"serialampcontroller","volumeOverride":true,"device":"2","name":"snd_rpi_hifiberry_digi","devicename":"Anthem - STR","mixer":"","mixertype":"None","maxvolume":-15,"volumecurve":"","volumesteps":1} Dec 25 13:13:04 volumio volumio[755]: info: [SERIALAMPCONTROLLER] retrieveVolume: Dec 25 13:13:04 volumio volumio[755]: info: [SERIALAMPCONTROLLER] getVolumeObject: {"mute":false,"currentDisableVolumeControl":false,"vol":55} Dec 25 13:13:04 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: serialampcontroller , retrievevolume Dec 25 13:13:04 volumio volumio[755]: info: [SERIALAMPCONTROLLER] retrieveVolume: Dec 25 13:13:04 volumio volumio[755]: info: [SERIALAMPCONTROLLER] getVolumeObject: {"mute":false,"currentDisableVolumeControl":false,"vol":55} Dec 25 13:13:04 volumio volumio[755]: info: CoreStateMachine::pushState Dec 25 13:13:04 volumio volumio[755]: info: CorePlayQueue::getTrack 0 Dec 25 13:13:04 volumio volumio[755]: info: CoreCommandRouter::volumioPushState Dec 25 13:13:04 volumio volumio[755]: info: CoreStateMachine::pushState Dec 25 13:13:04 volumio volumio[755]: info: CorePlayQueue::getTrack 0 Dec 25 13:13:04 volumio volumio[755]: info: CoreCommandRouter::volumioPushState Dec 25 13:13:04 volumio volumio[755]: info: MYVOLUMIO: Adding device Dec 25 13:13:04 volumio volumio[755]: info: MYVOLUMIO: Evaluating Server Dec 25 13:13:04 volumio volumio[755]: info: [SERIALAMPCONTROLLER] [parser:data]: Listener received: Z1VOL-96.0 Dec 25 13:13:04 volumio volumio[755]: info: [SERIALAMPCONTROLLER] parser:data: call processResponse with: respVolume Dec 25 13:13:04 volumio volumio[755]: info: [SERIALAMPCONTROLLER] processResponse: Amp signaled volume is -96 Dec 25 13:13:04 volumio volumio[755]: info: [SERIALAMPCONTROLLER] getVolumeObject: {"mute":false,"currentDisableVolumeControl":false,"vol":0} Dec 25 13:13:04 volumio volumio[755]: info: CoreStateMachine::pushState Dec 25 13:13:04 volumio volumio[755]: info: CorePlayQueue::getTrack 0 Dec 25 13:13:04 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 25 13:13:04 volumio volumio[755]: info: CoreCommandRouter::volumioPushState Dec 25 13:13:04 volumio volumio[755]: info: [SERIALAMPCONTROLLER] processResponse: Amp Status is now {"volume":-96,"mute":false,"power":"on","source":"05","Powering":""} Dec 25 13:13:04 volumio volumio[755]: info: [SERIALAMPCONTROLLER] parser:data: call processResponse with: undefined Dec 25 13:13:04 volumio volumio[755]: info: [SERIALAMPCONTROLLER] processResponse: unhandled response "undefined" Dec 25 13:13:04 volumio volumio[755]: info: [SERIALAMPCONTROLLER] processResponse: Amp Status is now {"volume":-96,"mute":false,"power":"on","source":"05","Powering":""} Dec 25 13:13:04 volumio volumio[755]: info: CoreStateMachine::pushState Dec 25 13:13:04 volumio volumio[755]: info: CorePlayQueue::getTrack 0 Dec 25 13:13:04 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 25 13:13:04 volumio volumio[755]: info: CoreCommandRouter::volumioPushState Dec 25 13:13:04 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] on:pushState: previous state was "pause" - next is pause Dec 25 13:13:04 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] processResponse: Amp Status is now {"volume":-96,"mute":false,"power":"on","source":"05","Powering":""} Dec 25 13:13:04 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] on:pushState: previous state was "pause" - next is pause Dec 25 13:13:04 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] processResponse: Amp Status is now {"volume":-96,"mute":false,"power":"on","source":"05","Powering":""} Dec 25 13:13:04 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] on:pushState: previous state was "pause" - next is pause Dec 25 13:13:04 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] processResponse: Amp Status is now {"volume":-96,"mute":false,"power":"on","source":"05","Powering":""} Dec 25 13:13:04 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] on:pushState: previous state was "pause" - next is pause Dec 25 13:13:04 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] processResponse: Amp Status is now {"volume":-96,"mute":false,"power":"on","source":"05","Powering":""} Dec 25 13:13:04 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] on:pushState: previous state was "pause" - next is pause Dec 25 13:13:04 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] processResponse: Amp Status is now {"volume":-96,"mute":false,"power":"on","source":"05","Powering":""} Dec 25 13:13:04 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] on:pushState: previous state was "pause" - next is pause Dec 25 13:13:04 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] processResponse: Amp Status is now {"volume":-96,"mute":false,"power":"on","source":"05","Powering":""} Dec 25 13:13:04 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] on:pushState: previous state was "pause" - next is pause Dec 25 13:13:04 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] processResponse: Amp Status is now {"volume":-96,"mute":false,"power":"on","source":"05","Powering":""} Dec 25 13:13:04 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] on:pushState: previous state was "pause" - next is pause Dec 25 13:13:04 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] processResponse: Amp Status is now {"volume":-96,"mute":false,"power":"on","source":"05","Powering":""} Dec 25 13:13:04 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] on:pushState: previous state was "pause" - next is pause Dec 25 13:13:04 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] processResponse: Amp Status is now {"volume":-96,"mute":false,"power":"on","source":"05","Powering":""} Dec 25 13:13:04 volumio volumio[755]: info: CoreCommandRouter::volumioPlay Dec 25 13:13:04 volumio volumio[755]: info: CoreStateMachine::play index undefined Dec 25 13:13:04 volumio volumio[755]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 25 13:13:04 volumio volumio[755]: info: CorePlayQueue::getTrack 0 Dec 25 13:13:04 volumio volumio[755]: info: CoreStateMachine::startPlaybackTimer Dec 25 13:13:04 volumio volumio[755]: info: CorePlayQueue::getTrack 0 Dec 25 13:13:04 volumio volumio[755]: info: ControllerMpd::resume Dec 25 13:13:04 volumio volumio[755]: verbose: ControllerMpd::sendMpdCommand play Dec 25 13:13:04 volumio sudo[1946]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 25 13:13:04 volumio sudo[1946]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 25 13:13:04 volumio volumio[755]: info: Dec 25 13:13:04 volumio volumio[755]: ---------------------------- MPD announces state update: player Dec 25 13:13:04 volumio volumio[755]: info: sendMpdCommand play took 52 milliseconds Dec 25 13:13:04 volumio volumio[755]: info: ControllerMpd::getState Dec 25 13:13:04 volumio volumio[755]: verbose: ControllerMpd::sendMpdCommand status Dec 25 13:13:04 volumio sudo[1946]: pam_unix(sudo:session): session closed for user root Dec 25 13:13:04 volumio volumio[755]: info: Dec 25 13:13:04 volumio volumio[755]: ---------------------------- MPD announces state update: player Dec 25 13:13:04 volumio volumio[755]: info: ControllerMpd::getState Dec 25 13:13:04 volumio volumio[755]: verbose: ControllerMpd::sendMpdCommand status Dec 25 13:13:04 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 25 13:13:04 volumio volumio[755]: info: [SERIALAMPCONTROLLER] initVolumeSettings: getAlsaCards "2" Dec 25 13:13:04 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getAlsaCards Dec 25 13:13:04 volumio sudo[1949]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 25 13:13:04 volumio sudo[1949]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 25 13:13:04 volumio sudo[1949]: pam_unix(sudo:session): session closed for user root Dec 25 13:13:04 volumio volumio[755]: info: [SERIALAMPCONTROLLER] initVolumeSettings: getAlsaCards [{"id":"0","alsacard":"b1","name":"HDMI"},{"id":"1","alsacard":"Headphones","name":"Headphones"},{"id":"2","alsacard":"sndrpihifiberry","name":"snd_rpi_hifiberry_digi"}] Dec 25 13:13:04 volumio volumio[755]: info: CoreCommandRouter::volumioUpdateVolumeSettings Dec 25 13:13:04 volumio volumio[755]: info: Updating Volume Controller Parameters: Device: 2 Name: snd_rpi_hifiberry_digi Mixer: Max Vol: -15 Vol Curve; Vol Steps: 1 Dec 25 13:13:04 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Dec 25 13:13:04 volumio volumio[755]: info: Enabling external Volume Control Dec 25 13:13:04 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: serialampcontroller , updateVolumeSettings Dec 25 13:13:04 volumio volumio[755]: info: [SERIALAMPCONTROLLER] updateVolumeSettings: received {"pluginType":"system_hardware","pluginName":"serialampcontroller","volumeOverride":true,"device":"2","name":"snd_rpi_hifiberry_digi","devicename":"Anthem - STR","mixer":"","mixertype":"None","maxvolume":-15,"volumecurve":"","volumesteps":1} Dec 25 13:13:04 volumio volumio[755]: info: [SERIALAMPCONTROLLER] retrieveVolume: Dec 25 13:13:04 volumio volumio[755]: info: [SERIALAMPCONTROLLER] getVolumeObject: {"mute":false,"currentDisableVolumeControl":false,"vol":0} Dec 25 13:13:04 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: serialampcontroller , retrievevolume Dec 25 13:13:04 volumio volumio[755]: info: [SERIALAMPCONTROLLER] retrieveVolume: Dec 25 13:13:04 volumio volumio[755]: info: [SERIALAMPCONTROLLER] getVolumeObject: {"mute":false,"currentDisableVolumeControl":false,"vol":0} Dec 25 13:13:04 volumio volumio[755]: info: CoreStateMachine::pushState Dec 25 13:13:04 volumio volumio[755]: info: CorePlayQueue::getTrack 0 Dec 25 13:13:04 volumio volumio[755]: info: CoreCommandRouter::volumioPushState Dec 25 13:13:04 volumio volumio[755]: info: CoreStateMachine::pushState Dec 25 13:13:04 volumio volumio[755]: info: CorePlayQueue::getTrack 0 Dec 25 13:13:04 volumio volumio[755]: info: CoreCommandRouter::volumioPushState Dec 25 13:13:04 volumio volumio[755]: info: sendMpdCommand status took 75 milliseconds Dec 25 13:13:04 volumio volumio[755]: info: sendMpdCommand status took 74 milliseconds Dec 25 13:13:04 volumio volumio[755]: verbose: ControllerMpd::parseState Dec 25 13:13:04 volumio volumio[755]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 25 13:13:04 volumio volumio[755]: verbose: ControllerMpd::parseState Dec 25 13:13:04 volumio volumio[755]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 25 13:13:04 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] on:pushState: previous state was "pause" - next is pause Dec 25 13:13:04 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] processResponse: Amp Status is now {"volume":-96,"mute":false,"power":"on","source":"05","Powering":""} Dec 25 13:13:04 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] on:pushState: previous state was "pause" - next is pause Dec 25 13:13:04 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] processResponse: Amp Status is now {"volume":-96,"mute":false,"power":"on","source":"05","Powering":""} Dec 25 13:13:04 volumio volumio[755]: info: sendMpdCommand playlistinfo took 14 milliseconds Dec 25 13:13:04 volumio volumio[755]: info: sendMpdCommand playlistinfo took 13 milliseconds Dec 25 13:13:04 volumio volumio[755]: verbose: ControllerMpd::parseTrackInfo Dec 25 13:13:04 volumio volumio[755]: verbose: ControllerMpd::parseTrackInfo Dec 25 13:13:04 volumio volumio[755]: info: ControllerMpd::pushState Dec 25 13:13:04 volumio volumio[755]: info: CoreCommandRouter::servicePushState Dec 25 13:13:04 volumio volumio[755]: info: CorePlayQueue::getTrack 0 Dec 25 13:13:04 volumio volumio[755]: verbose: STATE SERVICE {"status":"play","position":0,"seek":47154,"duration":2792,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"745 Kbps","isStreaming":false,"title":"Green Bullfrog - The Green Bullfrog Sessions [NSP CD 503].flac","artist":"Green Bullfrog","album":"The Green Bullfrog Sessions [NSP CD 503]","uri":"NAS/DISKSTATION3/DEEP PURPLE/Rainbow - Blackmore/1971 The Green Bullfrog Sessions (1991 Connoisseur Collection)/Green Bullfrog - The Green Bullfrog Sessions [NSP CD 503].flac","trackType":"flac"} Dec 25 13:13:04 volumio volumio[755]: verbose: CURRENT POSITION 0 Dec 25 13:13:04 volumio volumio[755]: info: CoreStateMachine::syncState stateService play Dec 25 13:13:04 volumio volumio[755]: info: CoreStateMachine::syncState currentStatus pause Dec 25 13:13:04 volumio volumio[755]: info: CoreStateMachine::pushState Dec 25 13:13:04 volumio volumio[755]: info: CorePlayQueue::getTrack 0 Dec 25 13:13:04 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 25 13:13:04 volumio volumio[755]: info: CoreCommandRouter::volumioPushState Dec 25 13:13:04 volumio volumio[755]: info: ControllerMpd::pushState Dec 25 13:13:04 volumio volumio[755]: info: CoreCommandRouter::servicePushState Dec 25 13:13:04 volumio volumio[755]: info: CorePlayQueue::getTrack 0 Dec 25 13:13:04 volumio volumio[755]: verbose: STATE SERVICE {"status":"play","position":0,"seek":47154,"duration":2792,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"745 Kbps","isStreaming":false,"title":"Green Bullfrog - The Green Bullfrog Sessions [NSP CD 503].flac","artist":"Green Bullfrog","album":"The Green Bullfrog Sessions [NSP CD 503]","uri":"NAS/DISKSTATION3/DEEP PURPLE/Rainbow - Blackmore/1971 The Green Bullfrog Sessions (1991 Connoisseur Collection)/Green Bullfrog - The Green Bullfrog Sessions [NSP CD 503].flac","trackType":"flac"} Dec 25 13:13:04 volumio volumio[755]: verbose: CURRENT POSITION 0 Dec 25 13:13:04 volumio volumio[755]: info: CoreStateMachine::syncState stateService play Dec 25 13:13:04 volumio volumio[755]: info: CoreStateMachine::syncState currentStatus play Dec 25 13:13:04 volumio volumio[755]: info: Received an update from plugin. extracting info from payload Dec 25 13:13:04 volumio volumio[755]: info: CoreStateMachine::pushState Dec 25 13:13:04 volumio volumio[755]: info: CorePlayQueue::getTrack 0 Dec 25 13:13:04 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 25 13:13:04 volumio volumio[755]: info: CoreCommandRouter::volumioPushState Dec 25 13:13:04 volumio volumio[755]: info: CoreStateMachine::pushState Dec 25 13:13:04 volumio volumio[755]: info: CorePlayQueue::getTrack 0 Dec 25 13:13:04 volumio volumio[755]: info: CoreCommandRouter::volumioPushState Dec 25 13:13:04 volumio volumio[755]: info: ------------------------------ 132ms Dec 25 13:13:04 volumio volumio[755]: info: ------------------------------ 129ms Dec 25 13:13:04 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] on:pushState: previous state was "pause" - next is play Dec 25 13:13:04 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] processResponse: Amp Status is now {"volume":-96,"mute":false,"power":"on","source":"05","Powering":""} Dec 25 13:13:04 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] getAmpStatus: sending request to determine power status Dec 25 13:13:04 volumio volumio[755]: info: [SERIALAMPCONTROLLER] on:pushState: Powering not up Dec 25 13:13:04 volumio volumio[755]: info: [SERIALAMPCONTROLLER6] on:pushState: amp in standby - send powerup after play pressed Dec 25 13:13:04 volumio volumio[755]: info: [SERIALAMPCONTROLLER] sendCommand: send powerOn Dec 25 13:13:04 volumio volumio[755]: info: [SERIALAMPCONTROLLER] sendCommand: now sending cmdString: Z1POW1; Dec 25 13:13:04 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] on:pushState: previous state was "play" - next is play Dec 25 13:13:04 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] processResponse: Amp Status is now {"volume":-96,"mute":false,"power":"on","source":"05","Powering":"up"} Dec 25 13:13:04 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] on:pushState: previous state was "play" - next is play Dec 25 13:13:04 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] processResponse: Amp Status is now {"volume":-96,"mute":false,"power":"on","source":"05","Powering":"up"} Dec 25 13:13:04 volumio volumio[755]: info: [SERIALAMPCONTROLLER] sendStatusRequest: Sent command for "reqPower": Z1POW?; Dec 25 13:13:04 volumio volumio[755]: info: [SERIALAMPCONTROLLER] sendCommand: sent cmdString: Z1POW1; Dec 25 13:13:04 volumio volumio[755]: info: [SERIALAMPCONTROLLER] sendCommand: send source,XLRDir Dec 25 13:13:04 volumio volumio[755]: info: [SERIALAMPCONTROLLER] sendCommand: switch to source: XLRDir Dec 25 13:13:04 volumio volumio[755]: info: [SERIALAMPCONTROLLER] sendCommand: now sending cmdString: Z1INP05; Dec 25 13:13:04 volumio volumio[755]: info: [SERIALAMPCONTROLLER] sendCommand: sent cmdString: Z1INP05; Dec 25 13:13:04 volumio volumio[755]: verbose: New Socket.io Connection to 192.168.1.73 from 192.168.1.3 UA: Mozilla/5.0 (Linux; Android 16; SM-S911B Build/BP2A.250605.031.A3; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/143.0.7499.34 Mobile Safari/537.36 Total Clients: 7 Dec 25 13:13:04 volumio volumio[755]: info: [SERIALAMPCONTROLLER] [parser:data]: Listener received: Z1POW1 Dec 25 13:13:04 volumio volumio[755]: info: [SERIALAMPCONTROLLER] parser:data: call processResponse with: respPowerOn Dec 25 13:13:04 volumio volumio[755]: info: [SERIALAMPCONTROLLER] processResponse: Amp signaled PowerOn. Previous state is: on Dec 25 13:13:04 volumio volumio[755]: info: [SERIALAMPCONTROLLER] processResponse: Amp Status is now {"volume":-96,"mute":false,"power":"on","source":"05","Powering":""} Dec 25 13:13:04 volumio volumio[755]: info: CoreCommandRouter::volumioGetState Dec 25 13:13:04 volumio volumio[755]: info: CorePlayQueue::getTrack 0 Dec 25 13:13:04 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Dec 25 13:13:04 volumio volumio[755]: info: Listing playlists Dec 25 13:13:04 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Dec 25 13:13:04 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Dec 25 13:13:04 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Dec 25 13:13:04 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Dec 25 13:13:05 volumio python3[524]: INFO mpdlcd.lcdrunner LCD screen is 20x4 Dec 25 13:13:05 volumio python3[524]: INFO mpdlcd.lcdrunner MPD screen added to lcdproc. Dec 25 13:13:06 volumio volumio[755]: info: CoreCommandRouter::volumioPause Dec 25 13:13:06 volumio volumio[755]: info: CoreStateMachine::pause Dec 25 13:13:06 volumio volumio[755]: info: CoreStateMachine::stPlaybackTimer Dec 25 13:13:06 volumio volumio[755]: info: CoreStateMachine::servicePause Dec 25 13:13:06 volumio volumio[755]: info: CorePlayQueue::getTrack 0 Dec 25 13:13:06 volumio volumio[755]: info: CoreCommandRouter::servicePause Dec 25 13:13:06 volumio volumio[755]: info: ControllerMpd::pause Dec 25 13:13:06 volumio volumio[755]: verbose: ControllerMpd::sendMpdCommand pause Dec 25 13:13:06 volumio volumio[755]: info: Dec 25 13:13:06 volumio volumio[755]: ---------------------------- MPD announces state update: player Dec 25 13:13:06 volumio volumio[755]: info: sendMpdCommand pause took 32 milliseconds Dec 25 13:13:06 volumio volumio[755]: info: ControllerMpd::getState Dec 25 13:13:06 volumio volumio[755]: verbose: ControllerMpd::sendMpdCommand status Dec 25 13:13:06 volumio volumio[755]: info: Dec 25 13:13:06 volumio volumio[755]: ---------------------------- MPD announces state update: player Dec 25 13:13:06 volumio volumio[755]: info: ControllerMpd::getState Dec 25 13:13:06 volumio volumio[755]: verbose: ControllerMpd::sendMpdCommand status Dec 25 13:13:06 volumio volumio[755]: info: sendMpdCommand status took 4 milliseconds Dec 25 13:13:06 volumio volumio[755]: info: sendMpdCommand status took 2 milliseconds Dec 25 13:13:06 volumio volumio[755]: verbose: ControllerMpd::parseState Dec 25 13:13:06 volumio volumio[755]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 25 13:13:06 volumio volumio[755]: verbose: ControllerMpd::parseState Dec 25 13:13:06 volumio volumio[755]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 25 13:13:06 volumio volumio[755]: info: sendMpdCommand playlistinfo took 3 milliseconds Dec 25 13:13:06 volumio volumio[755]: info: sendMpdCommand playlistinfo took 3 milliseconds Dec 25 13:13:06 volumio volumio[755]: verbose: ControllerMpd::parseTrackInfo Dec 25 13:13:06 volumio volumio[755]: verbose: ControllerMpd::parseTrackInfo Dec 25 13:13:06 volumio volumio[755]: info: ControllerMpd::pushState Dec 25 13:13:06 volumio volumio[755]: info: CoreCommandRouter::servicePushState Dec 25 13:13:06 volumio volumio[755]: info: CorePlayQueue::getTrack 0 Dec 25 13:13:06 volumio volumio[755]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":48548,"duration":2792,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"787 Kbps","isStreaming":false,"title":"Green Bullfrog - The Green Bullfrog Sessions [NSP CD 503].flac","artist":"Green Bullfrog","album":"The Green Bullfrog Sessions [NSP CD 503]","uri":"NAS/DISKSTATION3/DEEP PURPLE/Rainbow - Blackmore/1971 The Green Bullfrog Sessions (1991 Connoisseur Collection)/Green Bullfrog - The Green Bullfrog Sessions [NSP CD 503].flac","trackType":"flac"} Dec 25 13:13:06 volumio volumio[755]: verbose: CURRENT POSITION 0 Dec 25 13:13:06 volumio volumio[755]: info: CoreStateMachine::syncState stateService pause Dec 25 13:13:06 volumio volumio[755]: info: CoreStateMachine::syncState currentStatus pause Dec 25 13:13:06 volumio volumio[755]: info: CoreStateMachine::pushState Dec 25 13:13:06 volumio volumio[755]: info: CorePlayQueue::getTrack 0 Dec 25 13:13:06 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 25 13:13:06 volumio volumio[755]: info: CoreCommandRouter::volumioPushState Dec 25 13:13:06 volumio volumio[755]: info: CoreStateMachine::stPlaybackTimer Dec 25 13:13:06 volumio volumio[755]: info: ControllerMpd::pushState Dec 25 13:13:06 volumio volumio[755]: info: CoreCommandRouter::servicePushState Dec 25 13:13:06 volumio volumio[755]: info: CorePlayQueue::getTrack 0 Dec 25 13:13:06 volumio volumio[755]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":48548,"duration":2792,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"787 Kbps","isStreaming":false,"title":"Green Bullfrog - The Green Bullfrog Sessions [NSP CD 503].flac","artist":"Green Bullfrog","album":"The Green Bullfrog Sessions [NSP CD 503]","uri":"NAS/DISKSTATION3/DEEP PURPLE/Rainbow - Blackmore/1971 The Green Bullfrog Sessions (1991 Connoisseur Collection)/Green Bullfrog - The Green Bullfrog Sessions [NSP CD 503].flac","trackType":"flac"} Dec 25 13:13:06 volumio volumio[755]: verbose: CURRENT POSITION 0 Dec 25 13:13:06 volumio volumio[755]: info: CoreStateMachine::syncState stateService pause Dec 25 13:13:06 volumio volumio[755]: info: CoreStateMachine::syncState currentStatus pause Dec 25 13:13:06 volumio volumio[755]: info: CoreStateMachine::pushState Dec 25 13:13:06 volumio volumio[755]: info: CorePlayQueue::getTrack 0 Dec 25 13:13:06 volumio volumio[755]: info: CoreCommandRouter::volumioPushState Dec 25 13:13:06 volumio volumio[755]: info: CoreStateMachine::stPlaybackTimer Dec 25 13:13:06 volumio volumio[755]: info: ------------------------------ 34ms Dec 25 13:13:06 volumio volumio[755]: info: ------------------------------ 32ms Dec 25 13:13:06 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] on:pushState: previous state was "play" - next is pause Dec 25 13:13:06 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] processResponse: Amp Status is now {"volume":-96,"mute":false,"power":"on","source":"05","Powering":""} Dec 25 13:13:06 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] on:pushState: previous state was "pause" - next is pause Dec 25 13:13:06 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] processResponse: Amp Status is now {"volume":-96,"mute":false,"power":"on","source":"05","Powering":""} Dec 25 13:13:06 volumio python3[524]: INFO mpdlcd.mpdwrapper Connecting to MPD server at localhost:6600 Dec 25 13:13:06 volumio python3[524]: INFO mpd.base Calling MPD connect('localhost', 6600, timeout=None) Dec 25 13:13:06 volumio python3[524]: INFO mpdlcd.lcdrunner Starting update loop. Dec 25 13:13:06 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 25 13:13:06 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Dec 25 13:13:07 volumio volumio[755]: info: Setting Geolocation for MyVolumio to eu2 Dec 25 13:13:07 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 25 13:13:07 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 25 13:13:07 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 25 13:13:07 volumio volumio[755]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Dec 25 13:13:07 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Dec 25 13:13:07 volumio volumio[755]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Total Clients: 8 Dec 25 13:13:07 volumio volumio[755]: info: CoreCommandRouter::volumioGetState Dec 25 13:13:07 volumio volumio[755]: info: CorePlayQueue::getTrack 0 Dec 25 13:13:07 volumio python3[524]: Terminated Dec 25 13:13:08 volumio volumio[755]: info: Updating MyVolumio device info Dec 25 13:13:08 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 25 13:13:08 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 25 13:13:08 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Dec 25 13:13:08 volumio volumio[755]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Dec 25 13:13:09 volumio volumio[755]: info: [SERIALAMPCONTROLLER] onTcpClose: Port has closed, removing listeners. Dec 25 13:13:10 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 25 13:13:12 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 25 13:13:12 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 25 13:13:12 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Dec 25 13:13:12 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Dec 25 13:13:12 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Dec 25 13:13:12 volumio volumio[755]: info: CoreCommandRouter::volumioGetBrowseSources Dec 25 13:13:12 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 25 13:13:14 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 25 13:13:14 volumio volumio[755]: info: [SERIALAMPCONTROLLER] initVolumeSettings: getAlsaCards "2" Dec 25 13:13:14 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getAlsaCards Dec 25 13:13:14 volumio volumio[755]: info: [SERIALAMPCONTROLLER] initVolumeSettings: getAlsaCards [{"id":"0","alsacard":"b1","name":"HDMI"},{"id":"1","alsacard":"Headphones","name":"Headphones"},{"id":"2","alsacard":"sndrpihifiberry","name":"snd_rpi_hifiberry_digi"}] Dec 25 13:13:14 volumio volumio[755]: info: CoreCommandRouter::volumioUpdateVolumeSettings Dec 25 13:13:14 volumio volumio[755]: info: Updating Volume Controller Parameters: Device: 2 Name: snd_rpi_hifiberry_digi Mixer: Max Vol: -15 Vol Curve; Vol Steps: 1 Dec 25 13:13:14 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Dec 25 13:13:14 volumio volumio[755]: info: Enabling external Volume Control Dec 25 13:13:14 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: serialampcontroller , updateVolumeSettings Dec 25 13:13:14 volumio volumio[755]: info: [SERIALAMPCONTROLLER] updateVolumeSettings: received {"pluginType":"system_hardware","pluginName":"serialampcontroller","volumeOverride":true,"device":"2","name":"snd_rpi_hifiberry_digi","devicename":"Anthem - STR","mixer":"","mixertype":"None","maxvolume":-15,"volumecurve":"","volumesteps":1} Dec 25 13:13:14 volumio volumio[755]: info: [SERIALAMPCONTROLLER] retrieveVolume: Dec 25 13:13:14 volumio volumio[755]: info: [SERIALAMPCONTROLLER] getVolumeObject: {"mute":false,"currentDisableVolumeControl":false,"vol":0} Dec 25 13:13:14 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: serialampcontroller , retrievevolume Dec 25 13:13:14 volumio volumio[755]: info: [SERIALAMPCONTROLLER] retrieveVolume: Dec 25 13:13:14 volumio volumio[755]: info: [SERIALAMPCONTROLLER] getVolumeObject: {"mute":false,"currentDisableVolumeControl":false,"vol":0} Dec 25 13:13:14 volumio volumio[755]: info: CoreStateMachine::pushState Dec 25 13:13:14 volumio volumio[755]: info: CorePlayQueue::getTrack 0 Dec 25 13:13:14 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 25 13:13:14 volumio volumio[755]: info: CoreCommandRouter::volumioPushState Dec 25 13:13:14 volumio volumio[755]: info: CoreStateMachine::pushState Dec 25 13:13:14 volumio volumio[755]: info: CorePlayQueue::getTrack 0 Dec 25 13:13:14 volumio volumio[755]: info: CoreCommandRouter::volumioPushState Dec 25 13:13:14 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] on:pushState: previous state was "pause" - next is pause Dec 25 13:13:14 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] processResponse: Amp Status is now {"volume":-96,"mute":false,"power":"on","source":"05","Powering":""} Dec 25 13:13:14 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] on:pushState: previous state was "pause" - next is pause Dec 25 13:13:14 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] processResponse: Amp Status is now {"volume":-96,"mute":false,"power":"on","source":"05","Powering":""} Dec 25 13:13:14 volumio volumio[755]: info: [SERIALAMPCONTROLLER] openTcpIp: Connected to: 192.168.1.101:14999 Dec 25 13:13:14 volumio volumio[755]: info: [SERIALAMPCONTROLLER] attachParser: Port is now open. Connecting Parser with delimiter: ; Dec 25 13:13:14 volumio volumio[755]: info: [SERIALAMPCONTROLLER] getAmpStatus: sending status requests to Amp Dec 25 13:13:14 volumio volumio[755]: info: [SERIALAMPCONTROLLER] sendStatusRequest: Sent command for "reqModel": IDM?; Dec 25 13:13:14 volumio volumio[755]: info: [SERIALAMPCONTROLLER] sendStatusRequest: Sent command for "reqPower": Z1POW?; Dec 25 13:13:14 volumio volumio[755]: info: [SERIALAMPCONTROLLER] sendStatusRequest: Sent command for "reqVolume": Z1VOL?; Dec 25 13:13:14 volumio volumio[755]: info: [SERIALAMPCONTROLLER] sendStatusRequest: Sent command for "reqMute": Z1MUT?; Dec 25 13:13:14 volumio volumio[755]: info: [SERIALAMPCONTROLLER] sendStatusRequest: Sent command for "reqSource": Z1INP?; Dec 25 13:13:14 volumio volumio[755]: info: [SERIALAMPCONTROLLER7v1] alsavolume: Set volume "-55" [object Object] Dec 25 13:13:14 volumio volumio[755]: info: [SERIALAMPCONTROLLER7v4] alsavolume: set volume to integer value -140.55 Dec 25 13:13:14 volumio volumio[755]: info: [SERIALAMPCONTROLLER] sendCommand: send volValue,-140.55 Dec 25 13:13:14 volumio volumio[755]: info: [SERIALAMPCONTROLLER] sendCommand: now sending cmdString: Z1VOL-140.0; Dec 25 13:13:14 volumio volumio[755]: info: [SERIALAMPCONTROLLER] sendCommand: sent cmdString: Z1VOL-140.0; Dec 25 13:13:14 volumio volumio[755]: info: [SERIALAMPCONTROLLER] [parser:data]: Listener received: IDMSTR IA Dec 25 13:13:14 volumio volumio[755]: info: [SERIALAMPCONTROLLER] parser:data: no matching regex for: IDMSTR IA Dec 25 13:13:14 volumio volumio[755]: info: [SERIALAMPCONTROLLER] [parser:data]: Listener received: Z1POW1 Dec 25 13:13:14 volumio volumio[755]: info: [SERIALAMPCONTROLLER] parser:data: call processResponse with: respPowerOn Dec 25 13:13:14 volumio volumio[755]: info: [SERIALAMPCONTROLLER] processResponse: Amp signaled PowerOn. Previous state is: on Dec 25 13:13:14 volumio volumio[755]: info: [SERIALAMPCONTROLLER] processResponse: Amp Status is now {"volume":-96,"mute":false,"power":"on","source":"05","Powering":""} Dec 25 13:13:14 volumio volumio[755]: info: [SERIALAMPCONTROLLER] [parser:data]: Listener received: Z1VOL-51.0 Dec 25 13:13:14 volumio volumio[755]: info: [SERIALAMPCONTROLLER] parser:data: call processResponse with: respVolume Dec 25 13:13:14 volumio volumio[755]: info: [SERIALAMPCONTROLLER] processResponse: Amp signaled volume is -51 Dec 25 13:13:14 volumio volumio[755]: info: [SERIALAMPCONTROLLER] getVolumeObject: {"mute":false,"currentDisableVolumeControl":false,"vol":55} Dec 25 13:13:14 volumio volumio[755]: info: CoreStateMachine::pushState Dec 25 13:13:14 volumio volumio[755]: info: CorePlayQueue::getTrack 0 Dec 25 13:13:14 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 25 13:13:14 volumio volumio[755]: info: CoreCommandRouter::volumioPushState Dec 25 13:13:14 volumio volumio[755]: info: [SERIALAMPCONTROLLER] getVolumeObject: {"mute":false,"currentDisableVolumeControl":false,"vol":55} Dec 25 13:13:14 volumio volumio[755]: info: [SERIALAMPCONTROLLER] processResponse: Amp Status is now {"volume":-51,"mute":false,"power":"on","source":"05","Powering":""} Dec 25 13:13:14 volumio volumio[755]: info: [SERIALAMPCONTROLLER] parser:data: call processResponse with: undefined Dec 25 13:13:14 volumio volumio[755]: info: [SERIALAMPCONTROLLER] processResponse: unhandled response "undefined" Dec 25 13:13:14 volumio volumio[755]: info: [SERIALAMPCONTROLLER] processResponse: Amp Status is now {"volume":-51,"mute":false,"power":"on","source":"05","Powering":""} Dec 25 13:13:14 volumio volumio[755]: info: [SERIALAMPCONTROLLER] [parser:data]: Listener received: Z1MUT0 Dec 25 13:13:14 volumio volumio[755]: info: [SERIALAMPCONTROLLER] parser:data: call processResponse with: respMuteOff Dec 25 13:13:14 volumio volumio[755]: info: [SERIALAMPCONTROLLER] processResponse: Amp signaled MuteOff Dec 25 13:13:14 volumio volumio[755]: info: [SERIALAMPCONTROLLER] getVolumeObject: {"mute":false,"currentDisableVolumeControl":false,"vol":55} Dec 25 13:13:14 volumio volumio[755]: info: CoreStateMachine::pushState Dec 25 13:13:14 volumio volumio[755]: info: CorePlayQueue::getTrack 0 Dec 25 13:13:14 volumio volumio[755]: info: CoreCommandRouter::volumioPushState Dec 25 13:13:14 volumio volumio[755]: info: [SERIALAMPCONTROLLER] processResponse: Amp Status is now {"volume":-51,"mute":false,"power":"on","source":"05","Powering":""} Dec 25 13:13:14 volumio volumio[755]: info: [SERIALAMPCONTROLLER] [parser:data]: Listener received: Z1INP05 Dec 25 13:13:14 volumio volumio[755]: info: [SERIALAMPCONTROLLER] parser:data: call processResponse with: respSource Dec 25 13:13:14 volumio volumio[755]: info: [SERIALAMPCONTROLLER] processResponse: Amp signaled source is 05 Dec 25 13:13:14 volumio volumio[755]: info: [SERIALAMPCONTROLLER] processResponse: Amp Status is now {"volume":-51,"mute":false,"power":"on","source":"05","Powering":""} Dec 25 13:13:14 volumio volumio[755]: info: CoreStateMachine::pushState Dec 25 13:13:14 volumio volumio[755]: info: CorePlayQueue::getTrack 0 Dec 25 13:13:14 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 25 13:13:14 volumio volumio[755]: info: CoreCommandRouter::volumioPushState Dec 25 13:13:14 volumio volumio[755]: info: CoreStateMachine::pushState Dec 25 13:13:14 volumio volumio[755]: info: CorePlayQueue::getTrack 0 Dec 25 13:13:14 volumio volumio[755]: info: CoreCommandRouter::volumioPushState Dec 25 13:13:14 volumio volumio[755]: info: CoreStateMachine::pushState Dec 25 13:13:14 volumio volumio[755]: info: CorePlayQueue::getTrack 0 Dec 25 13:13:14 volumio volumio[755]: info: CoreCommandRouter::volumioPushState Dec 25 13:13:14 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 25 13:13:14 volumio volumio[755]: info: [SERIALAMPCONTROLLER] initVolumeSettings: getAlsaCards "2" Dec 25 13:13:14 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getAlsaCards Dec 25 13:13:14 volumio volumio[755]: info: [SERIALAMPCONTROLLER] initVolumeSettings: getAlsaCards [{"id":"0","alsacard":"b1","name":"HDMI"},{"id":"1","alsacard":"Headphones","name":"Headphones"},{"id":"2","alsacard":"sndrpihifiberry","name":"snd_rpi_hifiberry_digi"}] Dec 25 13:13:14 volumio volumio[755]: info: CoreCommandRouter::volumioUpdateVolumeSettings Dec 25 13:13:14 volumio volumio[755]: info: Updating Volume Controller Parameters: Device: 2 Name: snd_rpi_hifiberry_digi Mixer: Max Vol: -15 Vol Curve; Vol Steps: 1 Dec 25 13:13:14 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Dec 25 13:13:14 volumio volumio[755]: info: Enabling external Volume Control Dec 25 13:13:14 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: serialampcontroller , updateVolumeSettings Dec 25 13:13:14 volumio volumio[755]: info: [SERIALAMPCONTROLLER] updateVolumeSettings: received {"pluginType":"system_hardware","pluginName":"serialampcontroller","volumeOverride":true,"device":"2","name":"snd_rpi_hifiberry_digi","devicename":"Anthem - STR","mixer":"","mixertype":"None","maxvolume":-15,"volumecurve":"","volumesteps":1} Dec 25 13:13:14 volumio volumio[755]: info: [SERIALAMPCONTROLLER] retrieveVolume: Dec 25 13:13:14 volumio volumio[755]: info: [SERIALAMPCONTROLLER] getVolumeObject: {"mute":false,"currentDisableVolumeControl":false,"vol":55} Dec 25 13:13:14 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: serialampcontroller , retrievevolume Dec 25 13:13:14 volumio volumio[755]: info: [SERIALAMPCONTROLLER] retrieveVolume: Dec 25 13:13:14 volumio volumio[755]: info: [SERIALAMPCONTROLLER] getVolumeObject: {"mute":false,"currentDisableVolumeControl":false,"vol":55} Dec 25 13:13:14 volumio volumio[755]: info: CoreStateMachine::pushState Dec 25 13:13:14 volumio volumio[755]: info: CorePlayQueue::getTrack 0 Dec 25 13:13:14 volumio volumio[755]: info: CoreCommandRouter::volumioPushState Dec 25 13:13:14 volumio volumio[755]: info: CoreStateMachine::pushState Dec 25 13:13:14 volumio volumio[755]: info: CorePlayQueue::getTrack 0 Dec 25 13:13:14 volumio volumio[755]: info: CoreCommandRouter::volumioPushState Dec 25 13:13:14 volumio volumio[755]: info: [SERIALAMPCONTROLLER] [parser:data]: Listener received: Z1VOL-96.0 Dec 25 13:13:14 volumio volumio[755]: info: [SERIALAMPCONTROLLER] parser:data: call processResponse with: respVolume Dec 25 13:13:14 volumio volumio[755]: info: [SERIALAMPCONTROLLER] processResponse: Amp signaled volume is -96 Dec 25 13:13:14 volumio volumio[755]: info: [SERIALAMPCONTROLLER] getVolumeObject: {"mute":false,"currentDisableVolumeControl":false,"vol":0} Dec 25 13:13:14 volumio volumio[755]: info: CoreStateMachine::pushState Dec 25 13:13:14 volumio volumio[755]: info: CorePlayQueue::getTrack 0 Dec 25 13:13:14 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 25 13:13:14 volumio volumio[755]: info: CoreCommandRouter::volumioPushState Dec 25 13:13:14 volumio volumio[755]: info: [SERIALAMPCONTROLLER] processResponse: Amp Status is now {"volume":-96,"mute":false,"power":"on","source":"05","Powering":""} Dec 25 13:13:14 volumio volumio[755]: info: [SERIALAMPCONTROLLER] parser:data: call processResponse with: undefined Dec 25 13:13:14 volumio volumio[755]: info: [SERIALAMPCONTROLLER] processResponse: unhandled response "undefined" Dec 25 13:13:14 volumio volumio[755]: info: [SERIALAMPCONTROLLER] processResponse: Amp Status is now {"volume":-96,"mute":false,"power":"on","source":"05","Powering":""} Dec 25 13:13:14 volumio volumio[755]: info: CoreStateMachine::pushState Dec 25 13:13:14 volumio volumio[755]: info: CorePlayQueue::getTrack 0 Dec 25 13:13:14 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 25 13:13:14 volumio volumio[755]: info: CoreCommandRouter::volumioPushState Dec 25 13:13:14 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] on:pushState: previous state was "pause" - next is pause Dec 25 13:13:14 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] processResponse: Amp Status is now {"volume":-96,"mute":false,"power":"on","source":"05","Powering":""} Dec 25 13:13:14 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] on:pushState: previous state was "pause" - next is pause Dec 25 13:13:14 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] processResponse: Amp Status is now {"volume":-96,"mute":false,"power":"on","source":"05","Powering":""} Dec 25 13:13:14 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] on:pushState: previous state was "pause" - next is pause Dec 25 13:13:14 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] processResponse: Amp Status is now {"volume":-96,"mute":false,"power":"on","source":"05","Powering":""} Dec 25 13:13:14 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] on:pushState: previous state was "pause" - next is pause Dec 25 13:13:14 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] processResponse: Amp Status is now {"volume":-96,"mute":false,"power":"on","source":"05","Powering":""} Dec 25 13:13:14 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] on:pushState: previous state was "pause" - next is pause Dec 25 13:13:14 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] processResponse: Amp Status is now {"volume":-96,"mute":false,"power":"on","source":"05","Powering":""} Dec 25 13:13:14 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] on:pushState: previous state was "pause" - next is pause Dec 25 13:13:14 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] processResponse: Amp Status is now {"volume":-96,"mute":false,"power":"on","source":"05","Powering":""} Dec 25 13:13:14 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] on:pushState: previous state was "pause" - next is pause Dec 25 13:13:14 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] processResponse: Amp Status is now {"volume":-96,"mute":false,"power":"on","source":"05","Powering":""} Dec 25 13:13:14 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] on:pushState: previous state was "pause" - next is pause Dec 25 13:13:14 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] processResponse: Amp Status is now {"volume":-96,"mute":false,"power":"on","source":"05","Powering":""} Dec 25 13:13:14 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] on:pushState: previous state was "pause" - next is pause Dec 25 13:13:14 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] processResponse: Amp Status is now {"volume":-96,"mute":false,"power":"on","source":"05","Powering":""} Dec 25 13:13:14 volumio volumio[755]: info: CoreCommandRouter::volumioPlay Dec 25 13:13:14 volumio volumio[755]: info: CoreStateMachine::play index undefined Dec 25 13:13:14 volumio volumio[755]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 25 13:13:14 volumio volumio[755]: info: CorePlayQueue::getTrack 0 Dec 25 13:13:14 volumio volumio[755]: info: CoreStateMachine::startPlaybackTimer Dec 25 13:13:14 volumio volumio[755]: info: CorePlayQueue::getTrack 0 Dec 25 13:13:14 volumio volumio[755]: info: ControllerMpd::resume Dec 25 13:13:14 volumio volumio[755]: verbose: ControllerMpd::sendMpdCommand play Dec 25 13:13:14 volumio kernel: bcm2835-i2s 3f203000.i2s: I2S SYNC error! Dec 25 13:13:14 volumio volumio[755]: info: sendMpdCommand play took 6 milliseconds Dec 25 13:13:14 volumio volumio[755]: info: Dec 25 13:13:14 volumio volumio[755]: ---------------------------- MPD announces state update: player Dec 25 13:13:14 volumio volumio[755]: info: ControllerMpd::getState Dec 25 13:13:14 volumio volumio[755]: verbose: ControllerMpd::sendMpdCommand status Dec 25 13:13:14 volumio volumio[755]: info: Dec 25 13:13:14 volumio volumio[755]: ---------------------------- MPD announces state update: player Dec 25 13:13:14 volumio volumio[755]: info: ControllerMpd::getState Dec 25 13:13:14 volumio volumio[755]: verbose: ControllerMpd::sendMpdCommand status Dec 25 13:13:14 volumio volumio[755]: info: sendMpdCommand status took 4 milliseconds Dec 25 13:13:14 volumio volumio[755]: info: sendMpdCommand status took 1 milliseconds Dec 25 13:13:14 volumio volumio[755]: verbose: ControllerMpd::parseState Dec 25 13:13:14 volumio volumio[755]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 25 13:13:14 volumio volumio[755]: verbose: ControllerMpd::parseState Dec 25 13:13:14 volumio volumio[755]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 25 13:13:14 volumio volumio[755]: info: sendMpdCommand playlistinfo took 3 milliseconds Dec 25 13:13:14 volumio volumio[755]: info: sendMpdCommand playlistinfo took 2 milliseconds Dec 25 13:13:14 volumio volumio[755]: verbose: ControllerMpd::parseTrackInfo Dec 25 13:13:14 volumio volumio[755]: verbose: ControllerMpd::parseTrackInfo Dec 25 13:13:14 volumio volumio[755]: info: ControllerMpd::pushState Dec 25 13:13:14 volumio volumio[755]: info: CoreCommandRouter::servicePushState Dec 25 13:13:14 volumio volumio[755]: info: CorePlayQueue::getTrack 0 Dec 25 13:13:14 volumio volumio[755]: verbose: STATE SERVICE {"status":"play","position":0,"seek":49439,"duration":2792,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"642 Kbps","isStreaming":false,"title":"Green Bullfrog - The Green Bullfrog Sessions [NSP CD 503].flac","artist":"Green Bullfrog","album":"The Green Bullfrog Sessions [NSP CD 503]","uri":"NAS/DISKSTATION3/DEEP PURPLE/Rainbow - Blackmore/1971 The Green Bullfrog Sessions (1991 Connoisseur Collection)/Green Bullfrog - The Green Bullfrog Sessions [NSP CD 503].flac","trackType":"flac"} Dec 25 13:13:14 volumio volumio[755]: verbose: CURRENT POSITION 0 Dec 25 13:13:14 volumio volumio[755]: info: CoreStateMachine::syncState stateService play Dec 25 13:13:14 volumio volumio[755]: info: CoreStateMachine::syncState currentStatus pause Dec 25 13:13:14 volumio volumio[755]: info: CoreStateMachine::pushState Dec 25 13:13:14 volumio volumio[755]: info: CorePlayQueue::getTrack 0 Dec 25 13:13:14 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 25 13:13:14 volumio volumio[755]: info: CoreCommandRouter::volumioPushState Dec 25 13:13:14 volumio volumio[755]: info: ControllerMpd::pushState Dec 25 13:13:14 volumio volumio[755]: info: CoreCommandRouter::servicePushState Dec 25 13:13:14 volumio volumio[755]: info: CorePlayQueue::getTrack 0 Dec 25 13:13:14 volumio volumio[755]: verbose: STATE SERVICE {"status":"play","position":0,"seek":49439,"duration":2792,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"642 Kbps","isStreaming":false,"title":"Green Bullfrog - The Green Bullfrog Sessions [NSP CD 503].flac","artist":"Green Bullfrog","album":"The Green Bullfrog Sessions [NSP CD 503]","uri":"NAS/DISKSTATION3/DEEP PURPLE/Rainbow - Blackmore/1971 The Green Bullfrog Sessions (1991 Connoisseur Collection)/Green Bullfrog - The Green Bullfrog Sessions [NSP CD 503].flac","trackType":"flac"} Dec 25 13:13:14 volumio volumio[755]: verbose: CURRENT POSITION 0 Dec 25 13:13:14 volumio volumio[755]: info: CoreStateMachine::syncState stateService play Dec 25 13:13:14 volumio volumio[755]: info: CoreStateMachine::syncState currentStatus play Dec 25 13:13:14 volumio volumio[755]: info: Received an update from plugin. extracting info from payload Dec 25 13:13:14 volumio volumio[755]: info: CoreStateMachine::pushState Dec 25 13:13:14 volumio volumio[755]: info: CorePlayQueue::getTrack 0 Dec 25 13:13:14 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 25 13:13:14 volumio volumio[755]: info: CoreCommandRouter::volumioPushState Dec 25 13:13:14 volumio volumio[755]: info: CoreStateMachine::pushState Dec 25 13:13:14 volumio volumio[755]: info: CorePlayQueue::getTrack 0 Dec 25 13:13:14 volumio volumio[755]: info: CoreCommandRouter::volumioPushState Dec 25 13:13:14 volumio volumio[755]: info: ------------------------------ 48ms Dec 25 13:13:14 volumio volumio[755]: info: ------------------------------ 46ms Dec 25 13:13:14 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] on:pushState: previous state was "pause" - next is play Dec 25 13:13:14 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] processResponse: Amp Status is now {"volume":-96,"mute":false,"power":"on","source":"05","Powering":""} Dec 25 13:13:14 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] getAmpStatus: sending request to determine power status Dec 25 13:13:14 volumio volumio[755]: info: [SERIALAMPCONTROLLER] on:pushState: Powering not up Dec 25 13:13:14 volumio volumio[755]: info: [SERIALAMPCONTROLLER6] on:pushState: amp in standby - send powerup after play pressed Dec 25 13:13:14 volumio volumio[755]: info: [SERIALAMPCONTROLLER] sendCommand: send powerOn Dec 25 13:13:14 volumio volumio[755]: info: [SERIALAMPCONTROLLER] sendCommand: now sending cmdString: Z1POW1; Dec 25 13:13:14 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] on:pushState: previous state was "play" - next is play Dec 25 13:13:14 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] processResponse: Amp Status is now {"volume":-96,"mute":false,"power":"on","source":"05","Powering":"up"} Dec 25 13:13:14 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] on:pushState: previous state was "play" - next is play Dec 25 13:13:14 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] processResponse: Amp Status is now {"volume":-96,"mute":false,"power":"on","source":"05","Powering":"up"} Dec 25 13:13:14 volumio volumio[755]: info: [SERIALAMPCONTROLLER] sendStatusRequest: Sent command for "reqPower": Z1POW?; Dec 25 13:13:14 volumio volumio[755]: info: [SERIALAMPCONTROLLER] sendCommand: sent cmdString: Z1POW1; Dec 25 13:13:14 volumio volumio[755]: info: [SERIALAMPCONTROLLER] sendCommand: send source,XLRDir Dec 25 13:13:14 volumio volumio[755]: info: [SERIALAMPCONTROLLER] sendCommand: switch to source: XLRDir Dec 25 13:13:14 volumio volumio[755]: info: [SERIALAMPCONTROLLER] sendCommand: now sending cmdString: Z1INP05; Dec 25 13:13:14 volumio volumio[755]: info: [SERIALAMPCONTROLLER] sendCommand: sent cmdString: Z1INP05; Dec 25 13:13:14 volumio volumio[755]: info: [SERIALAMPCONTROLLER] [parser:data]: Listener received: Z1POW1 Dec 25 13:13:14 volumio volumio[755]: info: [SERIALAMPCONTROLLER] parser:data: call processResponse with: respPowerOn Dec 25 13:13:14 volumio volumio[755]: info: [SERIALAMPCONTROLLER] processResponse: Amp signaled PowerOn. Previous state is: on Dec 25 13:13:14 volumio volumio[755]: info: [SERIALAMPCONTROLLER] processResponse: Amp Status is now {"volume":-96,"mute":false,"power":"on","source":"05","Powering":""} Dec 25 13:13:14 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 25 13:13:14 volumio volumio[755]: info: [SERIALAMPCONTROLLER] initVolumeSettings: getAlsaCards "2" Dec 25 13:13:14 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getAlsaCards Dec 25 13:13:14 volumio volumio[755]: info: [SERIALAMPCONTROLLER] initVolumeSettings: getAlsaCards [{"id":"0","alsacard":"b1","name":"HDMI"},{"id":"1","alsacard":"Headphones","name":"Headphones"},{"id":"2","alsacard":"sndrpihifiberry","name":"snd_rpi_hifiberry_digi"}] Dec 25 13:13:14 volumio volumio[755]: info: CoreCommandRouter::volumioUpdateVolumeSettings Dec 25 13:13:14 volumio volumio[755]: info: Updating Volume Controller Parameters: Device: 2 Name: snd_rpi_hifiberry_digi Mixer: Max Vol: -15 Vol Curve; Vol Steps: 1 Dec 25 13:13:14 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Dec 25 13:13:14 volumio volumio[755]: info: Enabling external Volume Control Dec 25 13:13:14 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: serialampcontroller , updateVolumeSettings Dec 25 13:13:14 volumio volumio[755]: info: [SERIALAMPCONTROLLER] updateVolumeSettings: received {"pluginType":"system_hardware","pluginName":"serialampcontroller","volumeOverride":true,"device":"2","name":"snd_rpi_hifiberry_digi","devicename":"Anthem - STR","mixer":"","mixertype":"None","maxvolume":-15,"volumecurve":"","volumesteps":1} Dec 25 13:13:14 volumio volumio[755]: info: [SERIALAMPCONTROLLER] retrieveVolume: Dec 25 13:13:14 volumio volumio[755]: info: [SERIALAMPCONTROLLER] getVolumeObject: {"mute":false,"currentDisableVolumeControl":false,"vol":0} Dec 25 13:13:14 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: serialampcontroller , retrievevolume Dec 25 13:13:14 volumio volumio[755]: info: [SERIALAMPCONTROLLER] retrieveVolume: Dec 25 13:13:14 volumio volumio[755]: info: [SERIALAMPCONTROLLER] getVolumeObject: {"mute":false,"currentDisableVolumeControl":false,"vol":0} Dec 25 13:13:14 volumio volumio[755]: info: CoreStateMachine::pushState Dec 25 13:13:14 volumio volumio[755]: info: CorePlayQueue::getTrack 0 Dec 25 13:13:14 volumio volumio[755]: info: CoreCommandRouter::volumioPushState Dec 25 13:13:14 volumio volumio[755]: info: CoreStateMachine::pushState Dec 25 13:13:14 volumio volumio[755]: info: CorePlayQueue::getTrack 0 Dec 25 13:13:14 volumio volumio[755]: info: CoreCommandRouter::volumioPushState Dec 25 13:13:15 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] on:pushState: previous state was "play" - next is play Dec 25 13:13:15 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] processResponse: Amp Status is now {"volume":-96,"mute":false,"power":"on","source":"05","Powering":""} Dec 25 13:13:15 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] on:pushState: previous state was "play" - next is play Dec 25 13:13:15 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] processResponse: Amp Status is now {"volume":-96,"mute":false,"power":"on","source":"05","Powering":""} Dec 25 13:13:15 volumio python3[524]: INFO mpdlcd.lcdrunner LCD screen is 20x4 Dec 25 13:13:15 volumio python3[524]: INFO mpdlcd.lcdrunner MPD screen added to lcdproc. Dec 25 13:13:16 volumio python3[524]: INFO mpdlcd.mpdwrapper Connecting to MPD server at localhost:6600 Dec 25 13:13:16 volumio python3[524]: INFO mpd.base Calling MPD connect('localhost', 6600, timeout=None) Dec 25 13:13:16 volumio python3[524]: INFO mpdlcd.lcdrunner Starting update loop. Dec 25 13:13:19 volumio volumio[755]: info: [SERIALAMPCONTROLLER] onTcpClose: Port has closed, removing listeners. Dec 25 13:13:23 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Dec 25 13:13:23 volumio volumio[755]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Dec 25 13:13:23 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Dec 25 13:13:23 volumio volumio[755]: info: Received Get System Version Dec 25 13:13:23 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 25 13:13:23 volumio volumio[755]: info: Received Get System Info Dec 25 13:13:23 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 25 13:13:23 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 25 13:13:23 volumio volumio[755]: info: Discovery: Getting this device information Dec 25 13:13:23 volumio volumio[755]: info: CoreCommandRouter::volumioGetState Dec 25 13:13:23 volumio volumio[755]: info: CorePlayQueue::getTrack 0 Dec 25 13:13:23 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 25 13:13:24 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 25 13:13:24 volumio volumio[755]: info: [SERIALAMPCONTROLLER] initVolumeSettings: getAlsaCards "2" Dec 25 13:13:24 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getAlsaCards Dec 25 13:13:24 volumio volumio[755]: info: [SERIALAMPCONTROLLER] initVolumeSettings: getAlsaCards [{"id":"0","alsacard":"b1","name":"HDMI"},{"id":"1","alsacard":"Headphones","name":"Headphones"},{"id":"2","alsacard":"sndrpihifiberry","name":"snd_rpi_hifiberry_digi"}] Dec 25 13:13:24 volumio volumio[755]: info: CoreCommandRouter::volumioUpdateVolumeSettings Dec 25 13:13:24 volumio volumio[755]: info: Updating Volume Controller Parameters: Device: 2 Name: snd_rpi_hifiberry_digi Mixer: Max Vol: -15 Vol Curve; Vol Steps: 1 Dec 25 13:13:24 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Dec 25 13:13:24 volumio volumio[755]: info: Enabling external Volume Control Dec 25 13:13:24 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: serialampcontroller , updateVolumeSettings Dec 25 13:13:24 volumio volumio[755]: info: [SERIALAMPCONTROLLER] updateVolumeSettings: received {"pluginType":"system_hardware","pluginName":"serialampcontroller","volumeOverride":true,"device":"2","name":"snd_rpi_hifiberry_digi","devicename":"Anthem - STR","mixer":"","mixertype":"None","maxvolume":-15,"volumecurve":"","volumesteps":1} Dec 25 13:13:24 volumio volumio[755]: info: [SERIALAMPCONTROLLER] retrieveVolume: Dec 25 13:13:24 volumio volumio[755]: info: [SERIALAMPCONTROLLER] getVolumeObject: {"mute":false,"currentDisableVolumeControl":false,"vol":0} Dec 25 13:13:24 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: serialampcontroller , retrievevolume Dec 25 13:13:24 volumio volumio[755]: info: [SERIALAMPCONTROLLER] retrieveVolume: Dec 25 13:13:24 volumio volumio[755]: info: [SERIALAMPCONTROLLER] getVolumeObject: {"mute":false,"currentDisableVolumeControl":false,"vol":0} Dec 25 13:13:24 volumio volumio[755]: info: CoreStateMachine::pushState Dec 25 13:13:24 volumio volumio[755]: info: CorePlayQueue::getTrack 0 Dec 25 13:13:24 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 25 13:13:24 volumio volumio[755]: info: CoreCommandRouter::volumioPushState Dec 25 13:13:24 volumio volumio[755]: info: CoreStateMachine::pushState Dec 25 13:13:24 volumio volumio[755]: info: CorePlayQueue::getTrack 0 Dec 25 13:13:24 volumio volumio[755]: info: CoreCommandRouter::volumioPushState Dec 25 13:13:24 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] on:pushState: previous state was "play" - next is play Dec 25 13:13:24 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] processResponse: Amp Status is now {"volume":-96,"mute":false,"power":"on","source":"05","Powering":""} Dec 25 13:13:24 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] on:pushState: previous state was "play" - next is play Dec 25 13:13:24 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] processResponse: Amp Status is now {"volume":-96,"mute":false,"power":"on","source":"05","Powering":""} Dec 25 13:13:24 volumio volumio[755]: info: [SERIALAMPCONTROLLER] openTcpIp: Connected to: 192.168.1.101:14999 Dec 25 13:13:24 volumio volumio[755]: info: [SERIALAMPCONTROLLER] attachParser: Port is now open. Connecting Parser with delimiter: ; Dec 25 13:13:24 volumio volumio[755]: info: [SERIALAMPCONTROLLER] getAmpStatus: sending status requests to Amp Dec 25 13:13:24 volumio volumio[755]: info: [SERIALAMPCONTROLLER] sendStatusRequest: Sent command for "reqModel": IDM?; Dec 25 13:13:24 volumio volumio[755]: info: [SERIALAMPCONTROLLER] sendStatusRequest: Sent command for "reqPower": Z1POW?; Dec 25 13:13:24 volumio volumio[755]: info: [SERIALAMPCONTROLLER] sendStatusRequest: Sent command for "reqVolume": Z1VOL?; Dec 25 13:13:24 volumio volumio[755]: info: [SERIALAMPCONTROLLER] sendStatusRequest: Sent command for "reqMute": Z1MUT?; Dec 25 13:13:24 volumio volumio[755]: info: [SERIALAMPCONTROLLER] sendStatusRequest: Sent command for "reqSource": Z1INP?; Dec 25 13:13:24 volumio volumio[755]: info: [SERIALAMPCONTROLLER7v1] alsavolume: Set volume "-55" [object Object] Dec 25 13:13:24 volumio volumio[755]: info: [SERIALAMPCONTROLLER7v4] alsavolume: set volume to integer value -140.55 Dec 25 13:13:24 volumio volumio[755]: info: [SERIALAMPCONTROLLER] sendCommand: send volValue,-140.55 Dec 25 13:13:24 volumio volumio[755]: info: [SERIALAMPCONTROLLER] sendCommand: now sending cmdString: Z1VOL-140.0; Dec 25 13:13:24 volumio volumio[755]: info: [SERIALAMPCONTROLLER] sendCommand: sent cmdString: Z1VOL-140.0; Dec 25 13:13:24 volumio volumio[755]: info: [SERIALAMPCONTROLLER] [parser:data]: Listener received: IDMSTR IA Dec 25 13:13:24 volumio volumio[755]: info: [SERIALAMPCONTROLLER] parser:data: no matching regex for: IDMSTR IA Dec 25 13:13:24 volumio volumio[755]: info: [SERIALAMPCONTROLLER] [parser:data]: Listener received: Z1POW1 Dec 25 13:13:24 volumio volumio[755]: info: [SERIALAMPCONTROLLER] parser:data: call processResponse with: respPowerOn Dec 25 13:13:24 volumio volumio[755]: info: [SERIALAMPCONTROLLER] processResponse: Amp signaled PowerOn. Previous state is: on Dec 25 13:13:24 volumio volumio[755]: info: [SERIALAMPCONTROLLER] processResponse: Amp Status is now {"volume":-96,"mute":false,"power":"on","source":"05","Powering":""} Dec 25 13:13:24 volumio volumio[755]: info: [SERIALAMPCONTROLLER] [parser:data]: Listener received: Z1VOL-51.0 Dec 25 13:13:24 volumio volumio[755]: info: [SERIALAMPCONTROLLER] parser:data: call processResponse with: respVolume Dec 25 13:13:24 volumio volumio[755]: info: [SERIALAMPCONTROLLER] processResponse: Amp signaled volume is -51 Dec 25 13:13:24 volumio volumio[755]: info: [SERIALAMPCONTROLLER] getVolumeObject: {"mute":false,"currentDisableVolumeControl":false,"vol":55} Dec 25 13:13:24 volumio volumio[755]: info: CoreStateMachine::pushState Dec 25 13:13:24 volumio volumio[755]: info: CorePlayQueue::getTrack 0 Dec 25 13:13:24 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 25 13:13:24 volumio volumio[755]: info: CoreCommandRouter::volumioPushState Dec 25 13:13:24 volumio volumio[755]: info: [SERIALAMPCONTROLLER] getVolumeObject: {"mute":false,"currentDisableVolumeControl":false,"vol":55} Dec 25 13:13:24 volumio volumio[755]: info: [SERIALAMPCONTROLLER] processResponse: Amp Status is now {"volume":-51,"mute":false,"power":"on","source":"05","Powering":""} Dec 25 13:13:24 volumio volumio[755]: info: [SERIALAMPCONTROLLER] parser:data: call processResponse with: undefined Dec 25 13:13:24 volumio volumio[755]: info: [SERIALAMPCONTROLLER] processResponse: unhandled response "undefined" Dec 25 13:13:24 volumio volumio[755]: info: [SERIALAMPCONTROLLER] processResponse: Amp Status is now {"volume":-51,"mute":false,"power":"on","source":"05","Powering":""} Dec 25 13:13:24 volumio volumio[755]: info: [SERIALAMPCONTROLLER] [parser:data]: Listener received: Z1MUT0 Dec 25 13:13:24 volumio volumio[755]: info: [SERIALAMPCONTROLLER] parser:data: call processResponse with: respMuteOff Dec 25 13:13:24 volumio volumio[755]: info: [SERIALAMPCONTROLLER] processResponse: Amp signaled MuteOff Dec 25 13:13:24 volumio volumio[755]: info: [SERIALAMPCONTROLLER] getVolumeObject: {"mute":false,"currentDisableVolumeControl":false,"vol":55} Dec 25 13:13:24 volumio volumio[755]: info: CoreStateMachine::pushState Dec 25 13:13:24 volumio volumio[755]: info: CorePlayQueue::getTrack 0 Dec 25 13:13:24 volumio volumio[755]: info: CoreCommandRouter::volumioPushState Dec 25 13:13:24 volumio volumio[755]: info: [SERIALAMPCONTROLLER] processResponse: Amp Status is now {"volume":-51,"mute":false,"power":"on","source":"05","Powering":""} Dec 25 13:13:24 volumio volumio[755]: info: [SERIALAMPCONTROLLER] [parser:data]: Listener received: Z1INP05 Dec 25 13:13:24 volumio volumio[755]: info: [SERIALAMPCONTROLLER] parser:data: call processResponse with: respSource Dec 25 13:13:24 volumio volumio[755]: info: [SERIALAMPCONTROLLER] processResponse: Amp signaled source is 05 Dec 25 13:13:24 volumio volumio[755]: info: [SERIALAMPCONTROLLER] processResponse: Amp Status is now {"volume":-51,"mute":false,"power":"on","source":"05","Powering":""} Dec 25 13:13:24 volumio volumio[755]: info: CoreStateMachine::pushState Dec 25 13:13:24 volumio volumio[755]: info: CorePlayQueue::getTrack 0 Dec 25 13:13:24 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 25 13:13:24 volumio volumio[755]: info: CoreCommandRouter::volumioPushState Dec 25 13:13:24 volumio volumio[755]: info: CoreStateMachine::pushState Dec 25 13:13:24 volumio volumio[755]: info: CorePlayQueue::getTrack 0 Dec 25 13:13:24 volumio volumio[755]: info: CoreCommandRouter::volumioPushState Dec 25 13:13:24 volumio volumio[755]: info: CoreStateMachine::pushState Dec 25 13:13:24 volumio volumio[755]: info: CorePlayQueue::getTrack 0 Dec 25 13:13:24 volumio volumio[755]: info: CoreCommandRouter::volumioPushState Dec 25 13:13:24 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 25 13:13:24 volumio volumio[755]: info: [SERIALAMPCONTROLLER] initVolumeSettings: getAlsaCards "2" Dec 25 13:13:24 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getAlsaCards Dec 25 13:13:24 volumio volumio[755]: info: [SERIALAMPCONTROLLER] initVolumeSettings: getAlsaCards [{"id":"0","alsacard":"b1","name":"HDMI"},{"id":"1","alsacard":"Headphones","name":"Headphones"},{"id":"2","alsacard":"sndrpihifiberry","name":"snd_rpi_hifiberry_digi"}] Dec 25 13:13:24 volumio volumio[755]: info: CoreCommandRouter::volumioUpdateVolumeSettings Dec 25 13:13:24 volumio volumio[755]: info: Updating Volume Controller Parameters: Device: 2 Name: snd_rpi_hifiberry_digi Mixer: Max Vol: -15 Vol Curve; Vol Steps: 1 Dec 25 13:13:24 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Dec 25 13:13:24 volumio volumio[755]: info: Enabling external Volume Control Dec 25 13:13:24 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: serialampcontroller , updateVolumeSettings Dec 25 13:13:24 volumio volumio[755]: info: [SERIALAMPCONTROLLER] updateVolumeSettings: received {"pluginType":"system_hardware","pluginName":"serialampcontroller","volumeOverride":true,"device":"2","name":"snd_rpi_hifiberry_digi","devicename":"Anthem - STR","mixer":"","mixertype":"None","maxvolume":-15,"volumecurve":"","volumesteps":1} Dec 25 13:13:24 volumio volumio[755]: info: [SERIALAMPCONTROLLER] retrieveVolume: Dec 25 13:13:24 volumio volumio[755]: info: [SERIALAMPCONTROLLER] getVolumeObject: {"mute":false,"currentDisableVolumeControl":false,"vol":55} Dec 25 13:13:24 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: serialampcontroller , retrievevolume Dec 25 13:13:24 volumio volumio[755]: info: [SERIALAMPCONTROLLER] retrieveVolume: Dec 25 13:13:24 volumio volumio[755]: info: [SERIALAMPCONTROLLER] getVolumeObject: {"mute":false,"currentDisableVolumeControl":false,"vol":55} Dec 25 13:13:24 volumio volumio[755]: info: CoreStateMachine::pushState Dec 25 13:13:24 volumio volumio[755]: info: CorePlayQueue::getTrack 0 Dec 25 13:13:24 volumio volumio[755]: info: CoreCommandRouter::volumioPushState Dec 25 13:13:24 volumio volumio[755]: info: CoreStateMachine::pushState Dec 25 13:13:24 volumio volumio[755]: info: CorePlayQueue::getTrack 0 Dec 25 13:13:24 volumio volumio[755]: info: CoreCommandRouter::volumioPushState Dec 25 13:13:24 volumio volumio[755]: info: [SERIALAMPCONTROLLER] [parser:data]: Listener received: Z1VOL-96.0 Dec 25 13:13:24 volumio volumio[755]: info: [SERIALAMPCONTROLLER] parser:data: call processResponse with: respVolume Dec 25 13:13:24 volumio volumio[755]: info: [SERIALAMPCONTROLLER] processResponse: Amp signaled volume is -96 Dec 25 13:13:24 volumio volumio[755]: info: [SERIALAMPCONTROLLER] getVolumeObject: {"mute":false,"currentDisableVolumeControl":false,"vol":0} Dec 25 13:13:24 volumio volumio[755]: info: CoreStateMachine::pushState Dec 25 13:13:24 volumio volumio[755]: info: CorePlayQueue::getTrack 0 Dec 25 13:13:24 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 25 13:13:24 volumio volumio[755]: info: CoreCommandRouter::volumioPushState Dec 25 13:13:24 volumio volumio[755]: info: [SERIALAMPCONTROLLER] processResponse: Amp Status is now {"volume":-96,"mute":false,"power":"on","source":"05","Powering":""} Dec 25 13:13:24 volumio volumio[755]: info: [SERIALAMPCONTROLLER] parser:data: call processResponse with: undefined Dec 25 13:13:24 volumio volumio[755]: info: [SERIALAMPCONTROLLER] processResponse: unhandled response "undefined" Dec 25 13:13:24 volumio volumio[755]: info: [SERIALAMPCONTROLLER] processResponse: Amp Status is now {"volume":-96,"mute":false,"power":"on","source":"05","Powering":""} Dec 25 13:13:24 volumio volumio[755]: info: CoreStateMachine::pushState Dec 25 13:13:24 volumio volumio[755]: info: CorePlayQueue::getTrack 0 Dec 25 13:13:24 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 25 13:13:24 volumio volumio[755]: info: CoreCommandRouter::volumioPushState Dec 25 13:13:24 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] on:pushState: previous state was "play" - next is play Dec 25 13:13:24 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] processResponse: Amp Status is now {"volume":-96,"mute":false,"power":"on","source":"05","Powering":""} Dec 25 13:13:24 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] on:pushState: previous state was "play" - next is play Dec 25 13:13:24 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] processResponse: Amp Status is now {"volume":-96,"mute":false,"power":"on","source":"05","Powering":""} Dec 25 13:13:24 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] on:pushState: previous state was "play" - next is play Dec 25 13:13:24 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] processResponse: Amp Status is now {"volume":-96,"mute":false,"power":"on","source":"05","Powering":""} Dec 25 13:13:24 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] on:pushState: previous state was "play" - next is play Dec 25 13:13:24 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] processResponse: Amp Status is now {"volume":-96,"mute":false,"power":"on","source":"05","Powering":""} Dec 25 13:13:24 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] on:pushState: previous state was "play" - next is play Dec 25 13:13:24 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] processResponse: Amp Status is now {"volume":-96,"mute":false,"power":"on","source":"05","Powering":""} Dec 25 13:13:24 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] on:pushState: previous state was "play" - next is play Dec 25 13:13:24 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] processResponse: Amp Status is now {"volume":-96,"mute":false,"power":"on","source":"05","Powering":""} Dec 25 13:13:24 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] on:pushState: previous state was "play" - next is play Dec 25 13:13:24 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] processResponse: Amp Status is now {"volume":-96,"mute":false,"power":"on","source":"05","Powering":""} Dec 25 13:13:24 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] on:pushState: previous state was "play" - next is play Dec 25 13:13:24 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] processResponse: Amp Status is now {"volume":-96,"mute":false,"power":"on","source":"05","Powering":""} Dec 25 13:13:24 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] on:pushState: previous state was "play" - next is play Dec 25 13:13:24 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] processResponse: Amp Status is now {"volume":-96,"mute":false,"power":"on","source":"05","Powering":""} Dec 25 13:13:24 volumio volumio[755]: info: CoreCommandRouter::volumioPlay Dec 25 13:13:24 volumio volumio[755]: info: CoreStateMachine::play index undefined Dec 25 13:13:24 volumio volumio[755]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 25 13:13:24 volumio volumio[755]: info: CorePlayQueue::getTrack 0 Dec 25 13:13:24 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 25 13:13:24 volumio volumio[755]: info: [SERIALAMPCONTROLLER] initVolumeSettings: getAlsaCards "2" Dec 25 13:13:24 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getAlsaCards Dec 25 13:13:24 volumio volumio[755]: info: [SERIALAMPCONTROLLER] initVolumeSettings: getAlsaCards [{"id":"0","alsacard":"b1","name":"HDMI"},{"id":"1","alsacard":"Headphones","name":"Headphones"},{"id":"2","alsacard":"sndrpihifiberry","name":"snd_rpi_hifiberry_digi"}] Dec 25 13:13:24 volumio volumio[755]: info: CoreCommandRouter::volumioUpdateVolumeSettings Dec 25 13:13:24 volumio volumio[755]: info: Updating Volume Controller Parameters: Device: 2 Name: snd_rpi_hifiberry_digi Mixer: Max Vol: -15 Vol Curve; Vol Steps: 1 Dec 25 13:13:24 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Dec 25 13:13:24 volumio volumio[755]: info: Enabling external Volume Control Dec 25 13:13:24 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: serialampcontroller , updateVolumeSettings Dec 25 13:13:24 volumio volumio[755]: info: [SERIALAMPCONTROLLER] updateVolumeSettings: received {"pluginType":"system_hardware","pluginName":"serialampcontroller","volumeOverride":true,"device":"2","name":"snd_rpi_hifiberry_digi","devicename":"Anthem - STR","mixer":"","mixertype":"None","maxvolume":-15,"volumecurve":"","volumesteps":1} Dec 25 13:13:24 volumio volumio[755]: info: [SERIALAMPCONTROLLER] retrieveVolume: Dec 25 13:13:24 volumio volumio[755]: info: [SERIALAMPCONTROLLER] getVolumeObject: {"mute":false,"currentDisableVolumeControl":false,"vol":0} Dec 25 13:13:24 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: serialampcontroller , retrievevolume Dec 25 13:13:24 volumio volumio[755]: info: [SERIALAMPCONTROLLER] retrieveVolume: Dec 25 13:13:24 volumio volumio[755]: info: [SERIALAMPCONTROLLER] getVolumeObject: {"mute":false,"currentDisableVolumeControl":false,"vol":0} Dec 25 13:13:24 volumio volumio[755]: info: CoreStateMachine::pushState Dec 25 13:13:24 volumio volumio[755]: info: CorePlayQueue::getTrack 0 Dec 25 13:13:24 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 25 13:13:24 volumio volumio[755]: info: CoreCommandRouter::volumioPushState Dec 25 13:13:24 volumio volumio[755]: info: CoreStateMachine::pushState Dec 25 13:13:24 volumio volumio[755]: info: CorePlayQueue::getTrack 0 Dec 25 13:13:24 volumio volumio[755]: info: CoreCommandRouter::volumioPushState Dec 25 13:13:25 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] on:pushState: previous state was "play" - next is play Dec 25 13:13:25 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] processResponse: Amp Status is now {"volume":-96,"mute":false,"power":"on","source":"05","Powering":""} Dec 25 13:13:25 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] on:pushState: previous state was "play" - next is play Dec 25 13:13:25 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] processResponse: Amp Status is now {"volume":-96,"mute":false,"power":"on","source":"05","Powering":""} Dec 25 13:13:29 volumio volumio[755]: info: [SERIALAMPCONTROLLER] onTcpClose: Port has closed, removing listeners. Dec 25 13:13:34 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 25 13:13:34 volumio volumio[755]: info: [SERIALAMPCONTROLLER] initVolumeSettings: getAlsaCards "2" Dec 25 13:13:34 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getAlsaCards Dec 25 13:13:34 volumio volumio[755]: info: [SERIALAMPCONTROLLER] initVolumeSettings: getAlsaCards [{"id":"0","alsacard":"b1","name":"HDMI"},{"id":"1","alsacard":"Headphones","name":"Headphones"},{"id":"2","alsacard":"sndrpihifiberry","name":"snd_rpi_hifiberry_digi"}] Dec 25 13:13:34 volumio volumio[755]: info: CoreCommandRouter::volumioUpdateVolumeSettings Dec 25 13:13:34 volumio volumio[755]: info: Updating Volume Controller Parameters: Device: 2 Name: snd_rpi_hifiberry_digi Mixer: Max Vol: -15 Vol Curve; Vol Steps: 1 Dec 25 13:13:34 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Dec 25 13:13:34 volumio volumio[755]: info: Enabling external Volume Control Dec 25 13:13:34 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: serialampcontroller , updateVolumeSettings Dec 25 13:13:34 volumio volumio[755]: info: [SERIALAMPCONTROLLER] updateVolumeSettings: received {"pluginType":"system_hardware","pluginName":"serialampcontroller","volumeOverride":true,"device":"2","name":"snd_rpi_hifiberry_digi","devicename":"Anthem - STR","mixer":"","mixertype":"None","maxvolume":-15,"volumecurve":"","volumesteps":1} Dec 25 13:13:34 volumio volumio[755]: info: [SERIALAMPCONTROLLER] retrieveVolume: Dec 25 13:13:34 volumio volumio[755]: info: [SERIALAMPCONTROLLER] getVolumeObject: {"mute":false,"currentDisableVolumeControl":false,"vol":0} Dec 25 13:13:34 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: serialampcontroller , retrievevolume Dec 25 13:13:34 volumio volumio[755]: info: [SERIALAMPCONTROLLER] retrieveVolume: Dec 25 13:13:34 volumio volumio[755]: info: [SERIALAMPCONTROLLER] getVolumeObject: {"mute":false,"currentDisableVolumeControl":false,"vol":0} Dec 25 13:13:34 volumio volumio[755]: info: CoreStateMachine::pushState Dec 25 13:13:34 volumio volumio[755]: info: CorePlayQueue::getTrack 0 Dec 25 13:13:34 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 25 13:13:34 volumio volumio[755]: info: CoreCommandRouter::volumioPushState Dec 25 13:13:34 volumio volumio[755]: info: CoreStateMachine::pushState Dec 25 13:13:34 volumio volumio[755]: info: CorePlayQueue::getTrack 0 Dec 25 13:13:34 volumio volumio[755]: info: CoreCommandRouter::volumioPushState Dec 25 13:13:34 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] on:pushState: previous state was "play" - next is play Dec 25 13:13:34 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] processResponse: Amp Status is now {"volume":-96,"mute":false,"power":"on","source":"05","Powering":""} Dec 25 13:13:34 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] on:pushState: previous state was "play" - next is play Dec 25 13:13:34 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] processResponse: Amp Status is now {"volume":-96,"mute":false,"power":"on","source":"05","Powering":""} Dec 25 13:13:34 volumio volumio[755]: info: [SERIALAMPCONTROLLER] openTcpIp: Connected to: 192.168.1.101:14999 Dec 25 13:13:34 volumio volumio[755]: info: [SERIALAMPCONTROLLER] attachParser: Port is now open. Connecting Parser with delimiter: ; Dec 25 13:13:34 volumio volumio[755]: info: [SERIALAMPCONTROLLER] getAmpStatus: sending status requests to Amp Dec 25 13:13:34 volumio volumio[755]: info: [SERIALAMPCONTROLLER] sendStatusRequest: Sent command for "reqModel": IDM?; Dec 25 13:13:34 volumio volumio[755]: info: [SERIALAMPCONTROLLER] sendStatusRequest: Sent command for "reqPower": Z1POW?; Dec 25 13:13:34 volumio volumio[755]: info: [SERIALAMPCONTROLLER] sendStatusRequest: Sent command for "reqVolume": Z1VOL?; Dec 25 13:13:34 volumio volumio[755]: info: [SERIALAMPCONTROLLER] sendStatusRequest: Sent command for "reqMute": Z1MUT?; Dec 25 13:13:34 volumio volumio[755]: info: [SERIALAMPCONTROLLER] sendStatusRequest: Sent command for "reqSource": Z1INP?; Dec 25 13:13:34 volumio volumio[755]: info: [SERIALAMPCONTROLLER7v1] alsavolume: Set volume "-55" [object Object] Dec 25 13:13:34 volumio volumio[755]: info: [SERIALAMPCONTROLLER7v4] alsavolume: set volume to integer value -140.55 Dec 25 13:13:34 volumio volumio[755]: info: [SERIALAMPCONTROLLER] sendCommand: send volValue,-140.55 Dec 25 13:13:34 volumio volumio[755]: info: [SERIALAMPCONTROLLER] sendCommand: now sending cmdString: Z1VOL-140.0; Dec 25 13:13:34 volumio volumio[755]: info: [SERIALAMPCONTROLLER] sendCommand: sent cmdString: Z1VOL-140.0; Dec 25 13:13:34 volumio volumio[755]: info: [SERIALAMPCONTROLLER] [parser:data]: Listener received: IDMSTR IA Dec 25 13:13:34 volumio volumio[755]: info: [SERIALAMPCONTROLLER] parser:data: no matching regex for: IDMSTR IA Dec 25 13:13:34 volumio volumio[755]: info: [SERIALAMPCONTROLLER] [parser:data]: Listener received: Z1POW1 Dec 25 13:13:34 volumio volumio[755]: info: [SERIALAMPCONTROLLER] parser:data: call processResponse with: respPowerOn Dec 25 13:13:34 volumio volumio[755]: info: [SERIALAMPCONTROLLER] processResponse: Amp signaled PowerOn. Previous state is: on Dec 25 13:13:34 volumio volumio[755]: info: [SERIALAMPCONTROLLER] processResponse: Amp Status is now {"volume":-96,"mute":false,"power":"on","source":"05","Powering":""} Dec 25 13:13:34 volumio volumio[755]: info: [SERIALAMPCONTROLLER] [parser:data]: Listener received: Z1VOL-51.0 Dec 25 13:13:34 volumio volumio[755]: info: [SERIALAMPCONTROLLER] parser:data: call processResponse with: respVolume Dec 25 13:13:34 volumio volumio[755]: info: [SERIALAMPCONTROLLER] processResponse: Amp signaled volume is -51 Dec 25 13:13:34 volumio volumio[755]: info: [SERIALAMPCONTROLLER] getVolumeObject: {"mute":false,"currentDisableVolumeControl":false,"vol":55} Dec 25 13:13:34 volumio volumio[755]: info: CoreStateMachine::pushState Dec 25 13:13:34 volumio volumio[755]: info: CorePlayQueue::getTrack 0 Dec 25 13:13:34 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 25 13:13:34 volumio volumio[755]: info: CoreCommandRouter::volumioPushState Dec 25 13:13:34 volumio volumio[755]: info: [SERIALAMPCONTROLLER] getVolumeObject: {"mute":false,"currentDisableVolumeControl":false,"vol":55} Dec 25 13:13:34 volumio volumio[755]: info: [SERIALAMPCONTROLLER] processResponse: Amp Status is now {"volume":-51,"mute":false,"power":"on","source":"05","Powering":""} Dec 25 13:13:34 volumio volumio[755]: info: [SERIALAMPCONTROLLER] parser:data: call processResponse with: undefined Dec 25 13:13:34 volumio volumio[755]: info: [SERIALAMPCONTROLLER] processResponse: unhandled response "undefined" Dec 25 13:13:34 volumio volumio[755]: info: [SERIALAMPCONTROLLER] processResponse: Amp Status is now {"volume":-51,"mute":false,"power":"on","source":"05","Powering":""} Dec 25 13:13:34 volumio volumio[755]: info: [SERIALAMPCONTROLLER] [parser:data]: Listener received: Z1MUT0 Dec 25 13:13:34 volumio volumio[755]: info: [SERIALAMPCONTROLLER] parser:data: call processResponse with: respMuteOff Dec 25 13:13:34 volumio volumio[755]: info: [SERIALAMPCONTROLLER] processResponse: Amp signaled MuteOff Dec 25 13:13:34 volumio volumio[755]: info: [SERIALAMPCONTROLLER] getVolumeObject: {"mute":false,"currentDisableVolumeControl":false,"vol":55} Dec 25 13:13:34 volumio volumio[755]: info: CoreStateMachine::pushState Dec 25 13:13:34 volumio volumio[755]: info: CorePlayQueue::getTrack 0 Dec 25 13:13:34 volumio volumio[755]: info: CoreCommandRouter::volumioPushState Dec 25 13:13:34 volumio volumio[755]: info: [SERIALAMPCONTROLLER] processResponse: Amp Status is now {"volume":-51,"mute":false,"power":"on","source":"05","Powering":""} Dec 25 13:13:34 volumio volumio[755]: info: [SERIALAMPCONTROLLER] [parser:data]: Listener received: Z1INP05 Dec 25 13:13:34 volumio volumio[755]: info: [SERIALAMPCONTROLLER] parser:data: call processResponse with: respSource Dec 25 13:13:34 volumio volumio[755]: info: [SERIALAMPCONTROLLER] processResponse: Amp signaled source is 05 Dec 25 13:13:34 volumio volumio[755]: info: [SERIALAMPCONTROLLER] processResponse: Amp Status is now {"volume":-51,"mute":false,"power":"on","source":"05","Powering":""} Dec 25 13:13:34 volumio volumio[755]: info: CoreStateMachine::pushState Dec 25 13:13:34 volumio volumio[755]: info: CorePlayQueue::getTrack 0 Dec 25 13:13:34 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 25 13:13:34 volumio volumio[755]: info: CoreCommandRouter::volumioPushState Dec 25 13:13:34 volumio volumio[755]: info: CoreStateMachine::pushState Dec 25 13:13:34 volumio volumio[755]: info: CorePlayQueue::getTrack 0 Dec 25 13:13:34 volumio volumio[755]: info: CoreCommandRouter::volumioPushState Dec 25 13:13:34 volumio volumio[755]: info: CoreStateMachine::pushState Dec 25 13:13:34 volumio volumio[755]: info: CorePlayQueue::getTrack 0 Dec 25 13:13:34 volumio volumio[755]: info: CoreCommandRouter::volumioPushState Dec 25 13:13:34 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 25 13:13:34 volumio volumio[755]: info: [SERIALAMPCONTROLLER] initVolumeSettings: getAlsaCards "2" Dec 25 13:13:34 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getAlsaCards Dec 25 13:13:34 volumio volumio[755]: info: [SERIALAMPCONTROLLER] initVolumeSettings: getAlsaCards [{"id":"0","alsacard":"b1","name":"HDMI"},{"id":"1","alsacard":"Headphones","name":"Headphones"},{"id":"2","alsacard":"sndrpihifiberry","name":"snd_rpi_hifiberry_digi"}] Dec 25 13:13:34 volumio volumio[755]: info: CoreCommandRouter::volumioUpdateVolumeSettings Dec 25 13:13:34 volumio volumio[755]: info: Updating Volume Controller Parameters: Device: 2 Name: snd_rpi_hifiberry_digi Mixer: Max Vol: -15 Vol Curve; Vol Steps: 1 Dec 25 13:13:34 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Dec 25 13:13:34 volumio volumio[755]: info: Enabling external Volume Control Dec 25 13:13:34 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: serialampcontroller , updateVolumeSettings Dec 25 13:13:34 volumio volumio[755]: info: [SERIALAMPCONTROLLER] updateVolumeSettings: received {"pluginType":"system_hardware","pluginName":"serialampcontroller","volumeOverride":true,"device":"2","name":"snd_rpi_hifiberry_digi","devicename":"Anthem - STR","mixer":"","mixertype":"None","maxvolume":-15,"volumecurve":"","volumesteps":1} Dec 25 13:13:34 volumio volumio[755]: info: [SERIALAMPCONTROLLER] retrieveVolume: Dec 25 13:13:34 volumio volumio[755]: info: [SERIALAMPCONTROLLER] getVolumeObject: {"mute":false,"currentDisableVolumeControl":false,"vol":55} Dec 25 13:13:34 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: serialampcontroller , retrievevolume Dec 25 13:13:34 volumio volumio[755]: info: [SERIALAMPCONTROLLER] retrieveVolume: Dec 25 13:13:34 volumio volumio[755]: info: [SERIALAMPCONTROLLER] getVolumeObject: {"mute":false,"currentDisableVolumeControl":false,"vol":55} Dec 25 13:13:34 volumio volumio[755]: info: CoreStateMachine::pushState Dec 25 13:13:34 volumio volumio[755]: info: CorePlayQueue::getTrack 0 Dec 25 13:13:34 volumio volumio[755]: info: CoreCommandRouter::volumioPushState Dec 25 13:13:34 volumio volumio[755]: info: CoreStateMachine::pushState Dec 25 13:13:34 volumio volumio[755]: info: CorePlayQueue::getTrack 0 Dec 25 13:13:34 volumio volumio[755]: info: CoreCommandRouter::volumioPushState Dec 25 13:13:34 volumio volumio[755]: info: [SERIALAMPCONTROLLER] [parser:data]: Listener received: Z1VOL-96.0 Dec 25 13:13:34 volumio volumio[755]: info: [SERIALAMPCONTROLLER] parser:data: call processResponse with: respVolume Dec 25 13:13:34 volumio volumio[755]: info: [SERIALAMPCONTROLLER] processResponse: Amp signaled volume is -96 Dec 25 13:13:34 volumio volumio[755]: info: [SERIALAMPCONTROLLER] getVolumeObject: {"mute":false,"currentDisableVolumeControl":false,"vol":0} Dec 25 13:13:34 volumio volumio[755]: info: CoreStateMachine::pushState Dec 25 13:13:34 volumio volumio[755]: info: CorePlayQueue::getTrack 0 Dec 25 13:13:34 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 25 13:13:34 volumio volumio[755]: info: CoreCommandRouter::volumioPushState Dec 25 13:13:34 volumio volumio[755]: info: [SERIALAMPCONTROLLER] processResponse: Amp Status is now {"volume":-96,"mute":false,"power":"on","source":"05","Powering":""} Dec 25 13:13:34 volumio volumio[755]: info: [SERIALAMPCONTROLLER] parser:data: call processResponse with: undefined Dec 25 13:13:34 volumio volumio[755]: info: [SERIALAMPCONTROLLER] processResponse: unhandled response "undefined" Dec 25 13:13:34 volumio volumio[755]: info: [SERIALAMPCONTROLLER] processResponse: Amp Status is now {"volume":-96,"mute":false,"power":"on","source":"05","Powering":""} Dec 25 13:13:34 volumio volumio[755]: info: CoreStateMachine::pushState Dec 25 13:13:34 volumio volumio[755]: info: CorePlayQueue::getTrack 0 Dec 25 13:13:34 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 25 13:13:34 volumio volumio[755]: info: CoreCommandRouter::volumioPushState Dec 25 13:13:34 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] on:pushState: previous state was "play" - next is play Dec 25 13:13:34 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] processResponse: Amp Status is now {"volume":-96,"mute":false,"power":"on","source":"05","Powering":""} Dec 25 13:13:34 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] on:pushState: previous state was "play" - next is play Dec 25 13:13:34 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] processResponse: Amp Status is now {"volume":-96,"mute":false,"power":"on","source":"05","Powering":""} Dec 25 13:13:34 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] on:pushState: previous state was "play" - next is play Dec 25 13:13:34 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] processResponse: Amp Status is now {"volume":-96,"mute":false,"power":"on","source":"05","Powering":""} Dec 25 13:13:34 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] on:pushState: previous state was "play" - next is play Dec 25 13:13:34 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] processResponse: Amp Status is now {"volume":-96,"mute":false,"power":"on","source":"05","Powering":""} Dec 25 13:13:34 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] on:pushState: previous state was "play" - next is play Dec 25 13:13:34 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] processResponse: Amp Status is now {"volume":-96,"mute":false,"power":"on","source":"05","Powering":""} Dec 25 13:13:34 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] on:pushState: previous state was "play" - next is play Dec 25 13:13:34 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] processResponse: Amp Status is now {"volume":-96,"mute":false,"power":"on","source":"05","Powering":""} Dec 25 13:13:34 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] on:pushState: previous state was "play" - next is play Dec 25 13:13:34 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] processResponse: Amp Status is now {"volume":-96,"mute":false,"power":"on","source":"05","Powering":""} Dec 25 13:13:34 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] on:pushState: previous state was "play" - next is play Dec 25 13:13:34 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] processResponse: Amp Status is now {"volume":-96,"mute":false,"power":"on","source":"05","Powering":""} Dec 25 13:13:34 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] on:pushState: previous state was "play" - next is play Dec 25 13:13:34 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] processResponse: Amp Status is now {"volume":-96,"mute":false,"power":"on","source":"05","Powering":""} Dec 25 13:13:35 volumio volumio[755]: info: CoreCommandRouter::volumioPlay Dec 25 13:13:35 volumio volumio[755]: info: CoreStateMachine::play index undefined Dec 25 13:13:35 volumio volumio[755]: info: CoreStateMachine::setConsumeUpdateService undefined Dec 25 13:13:35 volumio volumio[755]: info: CorePlayQueue::getTrack 0 Dec 25 13:13:39 volumio volumio[755]: info: [SERIALAMPCONTROLLER] onTcpClose: Port has closed, removing listeners. Dec 25 13:13:44 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Dec 25 13:13:44 volumio volumio[755]: info: [SERIALAMPCONTROLLER] initVolumeSettings: getAlsaCards "2" Dec 25 13:13:44 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getAlsaCards Dec 25 13:13:44 volumio volumio[755]: info: [SERIALAMPCONTROLLER] initVolumeSettings: getAlsaCards [{"id":"0","alsacard":"b1","name":"HDMI"},{"id":"1","alsacard":"Headphones","name":"Headphones"},{"id":"2","alsacard":"sndrpihifiberry","name":"snd_rpi_hifiberry_digi"}] Dec 25 13:13:44 volumio volumio[755]: info: CoreCommandRouter::volumioUpdateVolumeSettings Dec 25 13:13:44 volumio volumio[755]: info: Updating Volume Controller Parameters: Device: 2 Name: snd_rpi_hifiberry_digi Mixer: Max Vol: -15 Vol Curve; Vol Steps: 1 Dec 25 13:13:44 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Dec 25 13:13:44 volumio volumio[755]: info: Enabling external Volume Control Dec 25 13:13:44 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: serialampcontroller , updateVolumeSettings Dec 25 13:13:44 volumio volumio[755]: info: [SERIALAMPCONTROLLER] updateVolumeSettings: received {"pluginType":"system_hardware","pluginName":"serialampcontroller","volumeOverride":true,"device":"2","name":"snd_rpi_hifiberry_digi","devicename":"Anthem - STR","mixer":"","mixertype":"None","maxvolume":-15,"volumecurve":"","volumesteps":1} Dec 25 13:13:44 volumio volumio[755]: info: [SERIALAMPCONTROLLER] retrieveVolume: Dec 25 13:13:44 volumio volumio[755]: info: [SERIALAMPCONTROLLER] getVolumeObject: {"mute":false,"currentDisableVolumeControl":false,"vol":0} Dec 25 13:13:44 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: serialampcontroller , retrievevolume Dec 25 13:13:44 volumio volumio[755]: info: [SERIALAMPCONTROLLER] retrieveVolume: Dec 25 13:13:44 volumio volumio[755]: info: [SERIALAMPCONTROLLER] getVolumeObject: {"mute":false,"currentDisableVolumeControl":false,"vol":0} Dec 25 13:13:44 volumio volumio[755]: info: CoreStateMachine::pushState Dec 25 13:13:44 volumio volumio[755]: info: CorePlayQueue::getTrack 0 Dec 25 13:13:44 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 25 13:13:44 volumio volumio[755]: info: CoreCommandRouter::volumioPushState Dec 25 13:13:44 volumio volumio[755]: info: CoreStateMachine::pushState Dec 25 13:13:44 volumio volumio[755]: info: CorePlayQueue::getTrack 0 Dec 25 13:13:44 volumio volumio[755]: info: CoreCommandRouter::volumioPushState Dec 25 13:13:44 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] on:pushState: previous state was "play" - next is play Dec 25 13:13:44 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] processResponse: Amp Status is now {"volume":-96,"mute":false,"power":"on","source":"05","Powering":""} Dec 25 13:13:44 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] on:pushState: previous state was "play" - next is play Dec 25 13:13:44 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] processResponse: Amp Status is now {"volume":-96,"mute":false,"power":"on","source":"05","Powering":""} Dec 25 13:13:49 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 25 13:13:49 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 25 13:13:49 volumio volumio[755]: info: Discovery: Getting this device information Dec 25 13:13:49 volumio volumio[755]: info: CoreCommandRouter::volumioGetState Dec 25 13:13:49 volumio volumio[755]: info: CorePlayQueue::getTrack 0 Dec 25 13:13:49 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 25 13:13:49 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Dec 25 13:13:49 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: appearance , getAvailableLanguages Dec 25 13:13:49 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: system , getCurrentTimezone Dec 25 13:13:49 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: network , getInfoNetwork Dec 25 13:13:49 volumio sudo[2347]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ethtool eth0 Dec 25 13:13:49 volumio sudo[2347]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 25 13:13:49 volumio sudo[2347]: pam_unix(sudo:session): session closed for user root Dec 25 13:13:49 volumio sudo[2355]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Dec 25 13:13:49 volumio sudo[2355]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 25 13:13:49 volumio sudo[2355]: pam_unix(sudo:session): session closed for user root Dec 25 13:13:49 volumio sudo[2364]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Dec 25 13:13:49 volumio sudo[2364]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 25 13:13:49 volumio sudo[2364]: pam_unix(sudo:session): session closed for user root Dec 25 13:13:49 volumio sudo[2369]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Dec 25 13:13:49 volumio sudo[2369]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 25 13:13:49 volumio sudo[2369]: pam_unix(sudo:session): session closed for user root Dec 25 13:13:49 volumio sudo[2376]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 25 13:13:49 volumio sudo[2376]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 25 13:13:49 volumio sudo[2376]: pam_unix(sudo:session): session closed for user root Dec 25 13:13:49 volumio sudo[2378]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 25 13:13:49 volumio sudo[2378]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 25 13:13:49 volumio sudo[2378]: pam_unix(sudo:session): session closed for user root Dec 25 13:13:49 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Dec 25 13:13:49 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Dec 25 13:13:49 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 25 13:13:49 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 25 13:13:49 volumio volumio[755]: info: Discovery: Getting this device information Dec 25 13:13:49 volumio volumio[755]: info: CoreCommandRouter::volumioGetState Dec 25 13:13:49 volumio volumio[755]: info: CorePlayQueue::getTrack 0 Dec 25 13:13:49 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 25 13:13:49 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 25 13:13:49 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 25 13:13:49 volumio volumio[755]: info: Discovery: Getting this device information Dec 25 13:13:49 volumio volumio[755]: info: CoreCommandRouter::volumioGetState Dec 25 13:13:49 volumio volumio[755]: info: CorePlayQueue::getTrack 0 Dec 25 13:13:49 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 25 13:13:49 volumio volumio[755]: info: CoreCommandRouter::volumioGetState Dec 25 13:13:49 volumio volumio[755]: info: CorePlayQueue::getTrack 0 Dec 25 13:13:49 volumio volumio[755]: verbose: New Socket.io Connection to 192.168.1.73:3000 from 192.168.1.3 UA: Dart/3.10 (dart:io) Total Clients: 9 Dec 25 13:13:49 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Dec 25 13:13:49 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Dec 25 13:13:49 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Dec 25 13:13:49 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Dec 25 13:13:50 volumio sudo[2382]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 25 13:13:50 volumio sudo[2382]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 25 13:13:50 volumio sudo[2382]: pam_unix(sudo:session): session closed for user root Dec 25 13:13:50 volumio sudo[2384]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 25 13:13:50 volumio sudo[2384]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 25 13:13:50 volumio sudo[2384]: pam_unix(sudo:session): session closed for user root Dec 25 13:13:50 volumio volumio[755]: verbose: New Socket.io Connection to 192.168.1.73 from 192.168.1.3 UA: Mozilla/5.0 (Linux; Android 16; SM-S911B Build/BP2A.250605.031.A3; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/143.0.7499.34 Mobile Safari/537.36 Total Clients: 9 Dec 25 13:13:50 volumio sudo[2388]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Dec 25 13:13:50 volumio sudo[2388]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 25 13:13:50 volumio sudo[2388]: pam_unix(sudo:session): session closed for user root Dec 25 13:13:50 volumio sudo[2390]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Dec 25 13:13:50 volumio sudo[2390]: pam_unix(sudo:session): session opened for user root by (uid=0) Dec 25 13:13:50 volumio sudo[2390]: pam_unix(sudo:session): session closed for user root Dec 25 13:13:50 volumio volumio[755]: verbose: New Socket.io Connection to 192.168.1.73 from 192.168.1.3 UA: Mozilla/5.0 (Linux; Android 16; SM-S911B Build/BP2A.250605.031.A3; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/143.0.7499.34 Mobile Safari/537.36 Total Clients: 10 Dec 25 13:13:50 volumio volumio[755]: info: CoreCommandRouter::volumioGetState Dec 25 13:13:50 volumio volumio[755]: info: CorePlayQueue::getTrack 0 Dec 25 13:13:50 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Dec 25 13:13:50 volumio volumio[755]: info: Listing playlists Dec 25 13:13:50 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Dec 25 13:13:50 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Dec 25 13:13:50 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Dec 25 13:13:50 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Dec 25 13:13:51 volumio volumio[755]: info: CoreCommandRouter::volumioPause Dec 25 13:13:51 volumio volumio[755]: info: CoreStateMachine::pause Dec 25 13:13:51 volumio volumio[755]: info: CoreStateMachine::stPlaybackTimer Dec 25 13:13:51 volumio volumio[755]: info: CoreStateMachine::servicePause Dec 25 13:13:51 volumio volumio[755]: info: CorePlayQueue::getTrack 0 Dec 25 13:13:51 volumio volumio[755]: info: CoreCommandRouter::servicePause Dec 25 13:13:51 volumio volumio[755]: info: ControllerMpd::pause Dec 25 13:13:51 volumio volumio[755]: verbose: ControllerMpd::sendMpdCommand pause Dec 25 13:13:51 volumio volumio[755]: info: sendMpdCommand pause took 37 milliseconds Dec 25 13:13:51 volumio volumio[755]: info: Dec 25 13:13:51 volumio volumio[755]: ---------------------------- MPD announces state update: player Dec 25 13:13:51 volumio volumio[755]: info: ControllerMpd::getState Dec 25 13:13:51 volumio volumio[755]: verbose: ControllerMpd::sendMpdCommand status Dec 25 13:13:51 volumio volumio[755]: info: Dec 25 13:13:51 volumio volumio[755]: ---------------------------- MPD announces state update: player Dec 25 13:13:51 volumio volumio[755]: info: ControllerMpd::getState Dec 25 13:13:51 volumio volumio[755]: verbose: ControllerMpd::sendMpdCommand status Dec 25 13:13:51 volumio volumio[755]: info: sendMpdCommand status took 3 milliseconds Dec 25 13:13:51 volumio volumio[755]: info: sendMpdCommand status took 3 milliseconds Dec 25 13:13:51 volumio volumio[755]: verbose: ControllerMpd::parseState Dec 25 13:13:51 volumio volumio[755]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 25 13:13:51 volumio volumio[755]: verbose: ControllerMpd::parseState Dec 25 13:13:51 volumio volumio[755]: verbose: ControllerMpd::sendMpdCommand playlistinfo Dec 25 13:13:51 volumio volumio[755]: info: sendMpdCommand playlistinfo took 4 milliseconds Dec 25 13:13:51 volumio volumio[755]: info: sendMpdCommand playlistinfo took 3 milliseconds Dec 25 13:13:51 volumio volumio[755]: verbose: ControllerMpd::parseTrackInfo Dec 25 13:13:51 volumio volumio[755]: verbose: ControllerMpd::parseTrackInfo Dec 25 13:13:51 volumio volumio[755]: info: ControllerMpd::pushState Dec 25 13:13:51 volumio volumio[755]: info: CoreCommandRouter::servicePushState Dec 25 13:13:51 volumio volumio[755]: info: CorePlayQueue::getTrack 0 Dec 25 13:13:51 volumio volumio[755]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":86240,"duration":2792,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"823 Kbps","isStreaming":false,"title":"Green Bullfrog - The Green Bullfrog Sessions [NSP CD 503].flac","artist":"Green Bullfrog","album":"The Green Bullfrog Sessions [NSP CD 503]","uri":"NAS/DISKSTATION3/DEEP PURPLE/Rainbow - Blackmore/1971 The Green Bullfrog Sessions (1991 Connoisseur Collection)/Green Bullfrog - The Green Bullfrog Sessions [NSP CD 503].flac","trackType":"flac"} Dec 25 13:13:51 volumio volumio[755]: verbose: CURRENT POSITION 0 Dec 25 13:13:51 volumio volumio[755]: info: CoreStateMachine::syncState stateService pause Dec 25 13:13:51 volumio volumio[755]: info: CoreStateMachine::syncState currentStatus pause Dec 25 13:13:51 volumio volumio[755]: info: CoreStateMachine::pushState Dec 25 13:13:51 volumio volumio[755]: info: CorePlayQueue::getTrack 0 Dec 25 13:13:51 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Dec 25 13:13:51 volumio volumio[755]: info: CoreCommandRouter::volumioPushState Dec 25 13:13:51 volumio volumio[755]: info: CoreStateMachine::stPlaybackTimer Dec 25 13:13:51 volumio volumio[755]: info: ControllerMpd::pushState Dec 25 13:13:51 volumio volumio[755]: info: CoreCommandRouter::servicePushState Dec 25 13:13:51 volumio volumio[755]: info: CorePlayQueue::getTrack 0 Dec 25 13:13:51 volumio volumio[755]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":86240,"duration":2792,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"823 Kbps","isStreaming":false,"title":"Green Bullfrog - The Green Bullfrog Sessions [NSP CD 503].flac","artist":"Green Bullfrog","album":"The Green Bullfrog Sessions [NSP CD 503]","uri":"NAS/DISKSTATION3/DEEP PURPLE/Rainbow - Blackmore/1971 The Green Bullfrog Sessions (1991 Connoisseur Collection)/Green Bullfrog - The Green Bullfrog Sessions [NSP CD 503].flac","trackType":"flac"} Dec 25 13:13:51 volumio volumio[755]: verbose: CURRENT POSITION 0 Dec 25 13:13:51 volumio volumio[755]: info: CoreStateMachine::syncState stateService pause Dec 25 13:13:51 volumio volumio[755]: info: CoreStateMachine::syncState currentStatus pause Dec 25 13:13:51 volumio volumio[755]: info: CoreStateMachine::pushState Dec 25 13:13:51 volumio volumio[755]: info: CorePlayQueue::getTrack 0 Dec 25 13:13:51 volumio volumio[755]: info: CoreCommandRouter::volumioPushState Dec 25 13:13:51 volumio volumio[755]: info: CoreStateMachine::stPlaybackTimer Dec 25 13:13:51 volumio volumio[755]: info: ------------------------------ 59ms Dec 25 13:13:51 volumio volumio[755]: info: ------------------------------ 57ms Dec 25 13:13:51 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] on:pushState: previous state was "play" - next is pause Dec 25 13:13:51 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] processResponse: Amp Status is now {"volume":-96,"mute":false,"power":"on","source":"05","Powering":""} Dec 25 13:13:51 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] on:pushState: previous state was "pause" - next is pause Dec 25 13:13:51 volumio volumio[755]: info: [SERIALAMPCONTROLLER5] processResponse: Amp Status is now {"volume":-96,"mute":false,"power":"on","source":"05","Powering":""} Dec 25 13:13:52 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 25 13:13:52 volumio python3[524]: Terminated Dec 25 13:13:53 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 25 13:13:57 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Dec 25 13:13:57 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken Dec 25 13:14:08 volumio volumio[755]: error: Cannot download Available plugins list: Error: ESOCKETTIMEDOUT Dec 25 13:14:08 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Dec 25 13:14:08 volumio volumio[755]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Dec 25 13:14:08 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Dec 25 13:14:08 volumio volumio[755]: info: Received Get System Version Dec 25 13:14:08 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Dec 25 13:14:08 volumio volumio[755]: info: Received Get System Info Dec 25 13:14:08 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Dec 25 13:14:08 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Dec 25 13:14:08 volumio volumio[755]: info: Discovery: Getting this device information Dec 25 13:14:08 volumio volumio[755]: info: CoreCommandRouter::volumioGetState Dec 25 13:14:08 volumio volumio[755]: info: CorePlayQueue::getTrack 0 Dec 25 13:14:08 volumio volumio[755]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Dec 25 13:14:10 volumio volumio[755]: info: [SERIALAMPCONTROLLER] closePorts: closing TCP/IP Dec 25 13:14:10 volumio volumio[755]: info: [SERIALAMPCONTROLLER] resetVolumeSettings: Volume settings have been reset. Dec 25 13:14:10 volumio volumio[755]: error: Plugin serialampcontroller does not return adequate promise from onStop: please update! Dec 25 13:14:10 volumio volumio[755]: info: Disabling plugin serialampcontroller Dec 25 13:14:10 volumio volumio[755]: info: Done. Dec 25 13:14:19 volumio volumio[755]: info: [SERIALAMPCONTROLLER] closePorts: closed TCP/IP socket Dec 25 13:14:19 volumio volumio[755]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 25 13:14:19 volumio volumio[755]: Error: connect EHOSTUNREACH 192.168.1.101:14999 Dec 25 13:14:19 volumio volumio[755]: at TCPConnectWrap.afterConnect [as oncomplete] (net.js:1146:16) { Dec 25 13:14:19 volumio volumio[755]: errno: -113, Dec 25 13:14:19 volumio volumio[755]: code: 'EHOSTUNREACH', Dec 25 13:14:19 volumio volumio[755]: syscall: 'connect', Dec 25 13:14:19 volumio volumio[755]: address: '192.168.1.101', Dec 25 13:14:19 volumio volumio[755]: port: 14999 Dec 25 13:14:19 volumio volumio[755]: } Dec 25 13:14:19 volumio volumio[755]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Dec 25 13:14:20 volumio sudo[2592]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-12-25 13:13 Dec 25 13:14:20 volumio sudo[2592]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="b1c3cf61c2a0027c66bab1eb0a3795f80c1f2e95" VOLUMIO_FE_VERSION="614d7b13ffdcb0cc5a6072e7d06f59d52e323e71" VOLUMIO_FE3_VERSION="570aaed971c1346d45d1172dc445b086b258c6d1" VOLUMIO_BE_VERSION="e3eb3ee5b16063502f3a1735e11a28cfe54a0f46" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Sun 25 Jun 2023 07:20:58 PM CEST" VOLUMIO_VERSION="3.512" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="946a42b62509f37b5e7e2d86a2932a62"