Mar 03 21:27:00 volumiobookworm sudo[6935]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 03 21:27:00 volumiobookworm sudo[6935]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 03 21:27:00 volumiobookworm sudo[6937]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 03 21:27:00 volumiobookworm sudo[6937]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 03 21:27:00 volumiobookworm sudo[6935]: pam_unix(sudo:session): session closed for user root Mar 03 21:27:00 volumiobookworm volumio[6665]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan premium Mar 03 21:27:00 volumiobookworm volumio[6665]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan premium Mar 03 21:27:00 volumiobookworm volumio[6665]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan premium Mar 03 21:27:00 volumiobookworm volumio[6665]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan premium Mar 03 21:27:00 volumiobookworm volumio[6665]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan premium Mar 03 21:27:00 volumiobookworm volumio[6665]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan premium Mar 03 21:27:00 volumiobookworm volumio[6665]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan premium Mar 03 21:27:00 volumiobookworm volumio[6665]: info: [MyVolumio PluginManager] Adding plugin tidal to plan premium Mar 03 21:27:00 volumiobookworm volumio[6665]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan premium Mar 03 21:27:00 volumiobookworm volumio[6665]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan premium Mar 03 21:27:00 volumiobookworm volumio[6665]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan superstar Mar 03 21:27:00 volumiobookworm volumio[6665]: info: [MyVolumio PluginManager] Adding plugin multiroom to plan superstar Mar 03 21:27:00 volumiobookworm volumio[6665]: info: [MyVolumio PluginManager] Adding plugin metavolumio to plan superstar Mar 03 21:27:00 volumiobookworm volumio[6665]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan superstar Mar 03 21:27:00 volumiobookworm volumio[6665]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan superstar Mar 03 21:27:00 volumiobookworm volumio[6665]: info: [MyVolumio PluginManager] Adding plugin smart_inputs to plan superstar Mar 03 21:27:00 volumiobookworm volumio[6665]: info: [MyVolumio PluginManager] Adding plugin hi_res_audio to plan superstar Mar 03 21:27:00 volumiobookworm volumio[6665]: info: [MyVolumio PluginManager] Adding plugin tidal to plan superstar Mar 03 21:27:00 volumiobookworm volumio[6665]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan superstar Mar 03 21:27:00 volumiobookworm volumio[6665]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan superstar Mar 03 21:27:00 volumiobookworm volumio[6665]: info: [MyVolumio PluginManager] Adding plugin bluetooth to plan virtuoso Mar 03 21:27:00 volumiobookworm volumio[6665]: info: [MyVolumio PluginManager] Adding plugin manifestui to plan virtuoso Mar 03 21:27:00 volumiobookworm volumio[6665]: info: [MyVolumio PluginManager] Adding plugin cd_controller to plan virtuoso Mar 03 21:27:00 volumiobookworm volumio[6665]: info: [MyVolumio PluginManager] Adding plugin tidal to plan virtuoso Mar 03 21:27:00 volumiobookworm volumio[6665]: info: [MyVolumio PluginManager] Adding plugin qobuz to plan virtuoso Mar 03 21:27:00 volumiobookworm volumio[6665]: info: [MyVolumio PluginManager] Adding plugin tidalconnect to plan virtuoso Mar 03 21:27:00 volumiobookworm sudo[6937]: pam_unix(sudo:session): session closed for user root Mar 03 21:27:00 volumiobookworm volumio[6665]: info: Adding plugin metavolumio to MyMusic Plugins Mar 03 21:27:00 volumiobookworm volumio[6665]: info: Adding plugin cd_controller to MyMusic Plugins Mar 03 21:27:00 volumiobookworm volumio[6665]: info: Adding plugin smart_inputs to MyMusic Plugins Mar 03 21:27:00 volumiobookworm volumio[6665]: info: Adding plugin tidalconnect to MyMusic Plugins Mar 03 21:27:00 volumiobookworm volumio[6665]: info: [MyVolumio PluginManager] Loading plugin "my_volumio"... Mar 03 21:27:01 volumiobookworm volumio[6665]: info: [MyVolumio PluginManager] MyVolumio plugin successfully loaded Mar 03 21:27:01 volumiobookworm volumio[6665]: info: [MyVolumio PluginManager] Starting plugin system_controller.my_volumio Mar 03 21:27:01 volumiobookworm volumio[6665]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 03 21:27:01 volumiobookworm volumio[6665]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 03 21:27:01 volumiobookworm volumio[6665]: info: Starting MyVolumio Remote Streaming Endpoints Mar 03 21:27:01 volumiobookworm volumio[6665]: info: MyVolumio login type: Token Mar 03 21:27:01 volumiobookworm volumio[6665]: info: [MyVolumio PluginManager] MyVolumio plugin successfully started Mar 03 21:27:01 volumiobookworm volumio[6665]: info: [MyVolumio PluginManager] Loading plugin "streaming_services"... Mar 03 21:27:01 volumiobookworm volumio[6665]: info: Starting Streaming Service Transparent Proxy Mar 03 21:27:01 volumiobookworm volumio[6665]: info: [MyVolumio PluginManager] Streaming Services plugin successfully loaded Mar 03 21:27:01 volumiobookworm volumio[6665]: info: [MyVolumio PluginManager] Starting plugin music_service.streaming_services Mar 03 21:27:01 volumiobookworm volumio[6665]: info: Streaming services startup Mar 03 21:27:01 volumiobookworm volumio[6665]: info: Starting Streaming Daemon Mar 03 21:27:01 volumiobookworm sudo[6942]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 03 21:27:01 volumiobookworm sudo[6942]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 03 21:27:01 volumiobookworm volumio[6665]: info: [MyVolumio PluginManager] Streaming Services plugin successfully started Mar 03 21:27:01 volumiobookworm sudo[6942]: pam_unix(sudo:session): session closed for user root Mar 03 21:27:01 volumiobookworm volumio[6665]: error: Cannot start Volumio Streaming Daemon Mar 03 21:27:01 volumiobookworm volumio[6665]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Mar 03 21:27:01 volumiobookworm volumio[6665]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Mar 03 21:27:01 volumiobookworm sudo[6958]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Mar 03 21:27:01 volumiobookworm sudo[6958]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 03 21:27:01 volumiobookworm sudo[6958]: pam_unix(sudo:session): session closed for user root Mar 03 21:27:01 volumiobookworm volumio[6665]: info: Upmpdcli Daemon Started Mar 03 21:27:01 volumiobookworm volumio[6940]: STREAMING PROXY: Starting server on port 3245 Mar 03 21:27:01 volumiobookworm volumio[6940]: Node JS runtime: 20 Mar 03 21:27:01 volumiobookworm volumio[6665]: info: MYVOLUMIO SUCCESSFULLY LOGGED IN Mar 03 21:27:01 volumiobookworm volumio[6665]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 03 21:27:01 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] initVolumeSettings: getAlsaCards "0" Mar 03 21:27:01 volumiobookworm volumio[6665]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getAlsaCards Mar 03 21:27:01 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] initVolumeSettings: getAlsaCards [{"id":"0","alsacard":"sndrpihifiberry","name":"Hifiberry DAC"},{"id":"1","alsacard":"vc4hdmi0","name":"HDMI 0 Out"},{"id":"2","alsacard":"vc4hdmi1","name":"HDMI 1 Out"}] Mar 03 21:27:01 volumiobookworm volumio[6665]: info: CoreCommandRouter::volumioUpdateVolumeSettings Mar 03 21:27:01 volumiobookworm volumio[6665]: info: Updating Volume Controller Parameters: Device: 0 Name: Hifiberry DAC Mixer: Max Vol: 30 Vol Curve; Vol Steps: 1 Mar 03 21:27:01 volumiobookworm volumio[6665]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Mar 03 21:27:01 volumiobookworm volumio[6665]: info: Enabling external Volume Control Mar 03 21:27:01 volumiobookworm volumio[6665]: info: CoreCommandRouter::executeOnPlugin: serialampcontroller , updateVolumeSettings Mar 03 21:27:01 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] updateVolumeSettings: received {"pluginType":"system_hardware","pluginName":"serialampcontroller","volumeOverride":true,"device":"0","name":"Hifiberry DAC","alsacard":"sndrpihifiberry","devicename":"Rotel - RC-1592 >=V1.53","mixer":"","mixertype":"None","maxvolume":30,"volumecurve":"","volumesteps":1} Mar 03 21:27:01 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] retrieveVolume: Mar 03 21:27:01 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] getVolumeObject: {"mute":false,"disableVolumeControl":false,"vol":10} Mar 03 21:27:01 volumiobookworm volumio[6665]: info: CoreCommandRouter::executeOnPlugin: serialampcontroller , retrievevolume Mar 03 21:27:01 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] retrieveVolume: Mar 03 21:27:01 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] getVolumeObject: {"mute":false,"disableVolumeControl":false,"vol":10} Mar 03 21:27:01 volumiobookworm volumio[6665]: info: CoreStateMachine::pushState Mar 03 21:27:01 volumiobookworm volumio[6665]: info: CorePlayQueue::getTrack 0 Mar 03 21:27:01 volumiobookworm volumio[6665]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 03 21:27:01 volumiobookworm volumio[6665]: info: CoreCommandRouter::volumioPushState Mar 03 21:27:01 volumiobookworm volumio[6665]: info: CoreStateMachine::pushState Mar 03 21:27:01 volumiobookworm volumio[6665]: info: CorePlayQueue::getTrack 0 Mar 03 21:27:01 volumiobookworm volumio[6665]: info: CoreCommandRouter::volumioPushState Mar 03 21:27:02 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] on:pushState: undefined - stop Mar 03 21:27:02 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] on:pushState: undefined - stop Mar 03 21:27:02 volumiobookworm volumio[6665]: info: MyVolumio token set successfully Mar 03 21:27:02 volumiobookworm volumio[6665]: info: MYVOLUMIO: Adding device Mar 03 21:27:02 volumiobookworm volumio[6665]: info: MYVOLUMIO: Evaluating Server Mar 03 21:27:02 volumiobookworm volumio[6665]: info: MyVolumio status changed Mar 03 21:27:02 volumiobookworm volumio[6665]: info: Streaming services startup Mar 03 21:27:02 volumiobookworm volumio[6665]: info: Starting Streaming Daemon Mar 03 21:27:02 volumiobookworm volumio[6665]: info: Removing browser output: myVolumio user plan is not superstar Mar 03 21:27:02 volumiobookworm volumio[6665]: info: Removing audio output: Mar 03 21:27:02 volumiobookworm volumio[6665]: info: Stoppping Tunnel 1 Mar 03 21:27:02 volumiobookworm sudo[6983]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart volumio-streaming-daemon.service Mar 03 21:27:02 volumiobookworm sudo[6983]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 03 21:27:02 volumiobookworm sudo[6985]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop sshtunnel.service Mar 03 21:27:02 volumiobookworm sudo[6985]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) Mar 03 21:27:02 volumiobookworm systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 03 21:27:02 volumiobookworm systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 03 21:27:02 volumiobookworm volumio[6665]: error: Cannot start Volumio Streaming Daemon Mar 03 21:27:02 volumiobookworm volumio[6665]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Mar 03 21:27:02 volumiobookworm volumio[6665]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Mar 03 21:27:02 volumiobookworm sudo[6983]: pam_unix(sudo:session): session closed for user root Mar 03 21:27:02 volumiobookworm systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 03 21:27:02 volumiobookworm systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 03 21:27:02 volumiobookworm systemd[1]: /lib/systemd/system/sshtunnel.service:6: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 03 21:27:02 volumiobookworm systemd[1]: /lib/systemd/system/sshtunnel.service:7: Standard output type syslog is obsolete, automatically updating to journal. Please update your unit file, and consider removing the setting altogether. Mar 03 21:27:02 volumiobookworm sudo[6985]: pam_unix(sudo:session): session closed for user root Mar 03 21:27:02 volumiobookworm volumio[6665]: info: Remote SSH Stopped Mar 03 21:27:02 volumiobookworm volumio[6665]: info: Setting Geolocation for MyVolumio to eu4 Mar 03 21:27:02 volumiobookworm volumio[6665]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 03 21:27:02 volumiobookworm volumio[6665]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 03 21:27:02 volumiobookworm volumio[6665]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 03 21:27:03 volumiobookworm volumio[6665]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Mar 03 21:27:03 volumiobookworm volumio[6665]: info: Updating MyVolumio device info Mar 03 21:27:03 volumiobookworm volumio[6665]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 03 21:27:03 volumiobookworm volumio[6665]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 03 21:27:03 volumiobookworm volumio[6665]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 03 21:27:04 volumiobookworm volumio[6665]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Mar 03 21:27:07 volumiobookworm volumio[6665]: info: MYVOLUMIO: Adding device Mar 03 21:27:07 volumiobookworm volumio[6665]: info: MYVOLUMIO: Evaluating Server Mar 03 21:27:08 volumiobookworm volumio[6665]: info: Setting Geolocation for MyVolumio to eu4 Mar 03 21:27:08 volumiobookworm volumio[6665]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 03 21:27:08 volumiobookworm volumio[6665]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 03 21:27:08 volumiobookworm volumio[6665]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 03 21:27:08 volumiobookworm volumio[6665]: error: Failed to add MyVolumio device: {"message":"USER_NOT_FOUND"} Mar 03 21:27:09 volumiobookworm volumio[6665]: info: Updating MyVolumio device info Mar 03 21:27:09 volumiobookworm volumio[6665]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 03 21:27:09 volumiobookworm volumio[6665]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 03 21:27:09 volumiobookworm volumio[6665]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 03 21:27:09 volumiobookworm volumio[6665]: error: Failed to update MyVolumio device: {"message":"DEVICE_NOT_FOUND"} Mar 03 21:27:16 volumiobookworm volumio[6665]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Mar 03 21:27:16 volumiobookworm volumio[6665]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Mar 03 21:27:16 volumiobookworm volumio[6665]: info: CoreCommandRouter::volumioGetState Mar 03 21:27:16 volumiobookworm volumio[6665]: info: CorePlayQueue::getTrack 0 Mar 03 21:27:21 volumiobookworm volumio[6665]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 03 21:27:21 volumiobookworm volumio[6665]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 03 21:27:21 volumiobookworm volumio[6665]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Mar 03 21:27:21 volumiobookworm volumio[6665]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getConfigParam Mar 03 21:27:21 volumiobookworm volumio[6665]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Mar 03 21:27:21 volumiobookworm volumio[6665]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStatsObject Mar 03 21:27:21 volumiobookworm volumio[6665]: info: CoreCommandRouter::volumioGetBrowseSources Mar 03 21:27:21 volumiobookworm volumio[6665]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 03 21:27:21 volumiobookworm volumio[6665]: error: MyVolumio Plugin failed to authenticate in a timely fashion Mar 03 21:27:21 volumiobookworm volumio[6665]: info: Completed starting MyVolumio Plugin Mar 03 21:27:21 volumiobookworm volumio[6665]: info: BOOT COMPLETED Mar 03 21:27:21 volumiobookworm volumio[6665]: [Metrics] CommandRouter: 30s 814.25ms Mar 03 21:27:21 volumiobookworm volumio[6665]: info: CoreCommandRouter::volumiosetStartupVolume Mar 03 21:27:21 volumiobookworm volumio[6665]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 03 21:27:21 volumiobookworm volumio[6665]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 03 21:27:21 volumiobookworm volumio[6665]: info: CoreCommandRouter::Close All Modals sent Mar 03 21:27:21 volumiobookworm volumio[6665]: info: CoreCommandRouter::Close All Modals sent Mar 03 21:27:21 volumiobookworm volumio[6665]: info: Cannot play startup sound: Error: Command failed: /usr/bin/aplay -D volumio /volumio/app/startup.wav Mar 03 21:27:21 volumiobookworm volumio[6665]: aplay: main:831: audio open error: Invalid argument Mar 03 21:27:21 volumiobookworm volumio[6665]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 03 21:27:21 volumiobookworm volumio[6665]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Mar 03 21:27:21 volumiobookworm volumio[6665]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Mar 03 21:27:21 volumiobookworm volumio-remote-updater[893]: No test mode Mar 03 21:27:21 volumiobookworm volumio-remote-updater[893]: No alpha test mode Mar 03 21:27:21 volumiobookworm volumio[6665]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateEnabled Mar 03 21:27:21 volumiobookworm volumio[6665]: info: Update Ready: {"changeLogLink":"http://volumio.org","description":"

FIXES

 

NEW ADDITIONS

 

","title":"Update v3.785","updateavailable":true} Mar 03 21:27:21 volumiobookworm volumio[6665]: info: CoreCommandRouter::executeOnPlugin: updater_comm , setUpdateMessageCache Mar 03 21:27:22 volumiobookworm volumio[6665]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , checkAudioDeviceAvailable Mar 03 21:27:22 volumiobookworm volumio[6665]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Mar 03 21:27:22 volumiobookworm volumio[6665]: info: CoreCommandRouter::executeOnPlugin: system , versionChangeDetect Mar 03 21:27:48 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] closePorts: closing TCP/IP Mar 03 21:27:48 volumiobookworm volumio[6665]: error: Plugin serialampcontroller does not return adequate promise from onStop: please update! Mar 03 21:27:48 volumiobookworm volumio[6665]: info: Disabling plugin serialampcontroller Mar 03 21:27:48 volumiobookworm volumio[6665]: info: Done. Mar 03 21:27:48 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] closePorts: closed TCP/IP socket Mar 03 21:27:49 volumiobookworm volumio[6665]: info: Enabling plugin serialampcontroller Mar 03 21:27:49 volumiobookworm volumio[6665]: info: Loading plugin "serialampcontroller"... Mar 03 21:27:49 volumiobookworm volumio[6665]: info: Applying required configuration parameters for plugin serialampcontroller Mar 03 21:27:49 volumiobookworm volumio[6665]: info: Applying required configuration parameters for plugin serialampcontroller Mar 03 21:27:49 volumiobookworm volumio[6665]: info: PLUGIN START: serialampcontroller Mar 03 21:27:49 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] onStart: config: {"syncSave":true,"autosave":true,"autosaveDelay":1000,"saved":true,"atomicSave":false,"data":{"logging":{"type":"boolean","value":true},"serialInterfaceDev":{"type":"string","value":"usb-Prolific_Technology_Inc._USB-Serial_Controller_D-if00-port0"},"ampType":{"type":"string","value":"Rotel - RC-1592 >=V1.53"},"volumioInput":{"type":"string","value":"CD"},"minVolume":{"type":"number","value":0},"maxVolume":{"type":"number","value":30},"startupVolume":{"type":"number","value":10},"volumeSteps":{"type":"number","value":1},"mapTo100":{"type":"boolean","value":false},"pauseWhenMuted":{"type":"boolean","value":true},"pauseWhenInputChanged":{"type":"boolean","value":true},"switchInputAtPlay":{"type":"boolean","value":true},"startAtPowerup":{"type":"boolean","value":false},"tcpip":{"type":"boolean","value":true},"ipaddress":{"type":"string","value":"127.0.0.1"}},"callbacks":{"_":{}},"filePath":"/data/configuration/system_hardware/serialampcontroller/config.json"} Mar 03 21:27:49 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] loadI18nStrings: /data/plugins/system_hardware/serialampcontroller/i18n/strings_de.json Mar 03 21:27:49 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] loadAmpDefinitions: loaded AmpDefinitions for 10(serial) and 3 (TCP/IP) Amplifiers. Mar 03 21:27:49 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] listSerialDevices: found 1 devices.[{"path":"/dev/ttyUSB0","manufacturer":"Prolific Technology Inc. ","pnpId":"usb-Prolific_Technology_Inc._USB-Serial_Controller_D-if00-port0","vendorId":"067b","productId":"2303"}] Mar 03 21:27:49 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] setActiveAmp: {"vendor":"Rotel","model":"RC-1592 >=V1.53","interfaces":["RS232","TCP/IP"],"tcpport":9590,"baudRate":115200,"parity":"none","dataBits":8,"stopBits":1,"rtscts":false,"xon":false,"xoff":false,"xany":false,"sources":["CD","Coax1","Coax2","Coax3","Opt1","Opt2","Opt3","Aux","Tuner","Phono","USB","Bluetooth","Bal XLR","PC-USB"],"sourceCmd":["cd!","coax1!","coax2!","coax3!","opt1!","opt2!","opt3!","aux!","tuner!","phono!","usb!","bluetooth!","bal_xlr!","pcusb!"],"sourceRespPostfix":["cd","coax1","coax2","coax3","opt1","opt2","opt3","aux","tuner","phono","usb","bluetooth","bal_xlr","pc_usb"],"delimiter":"$","commands":{"powerOn":"power_on!","powerToggle":"power_toggle!","volUp":"vol_up!","volDown":"vol_dwn!","volValue":"vol_##!","mute":"mute!","muteOn":"mute_on!","muteOff":"mute_off!"},"responses":[{"rx":"power=on","cmd":["respPowerOn"]},{"rx":"power=standby","cmd":["respPowerOff"]},{"rx":"volume=([0-9]{2})","cmd":["respVolume"]},{"rx":"mute=on","cmd":["respMuteOn"]},{"rx":"mute=off","cmd":["respMuteOff"]},{"rx":"source=([a-z_123]*)","cmd":["respSource"]}],"statusRequests":{"reqPower":"get_current_power!","reqSource":"get_current_source!","reqVolume":"get_volume!","reqMute":"get_mute_status!","reqModel":""}} Mar 03 21:27:49 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] setActiveAmp: can send these responses: respPowerOn,respPowerOff,respVolume,respMuteOn,respMuteOff,respSource Mar 03 21:27:49 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] selectedInterfaceExists: TCP/IP selected. Expect network connection to exist. Mar 03 21:27:49 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] selectedAmpSupportsInterface: TCP/IP in ["RS232","TCP/IP"] Mar 03 21:27:49 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] openTcpIp: starting Mar 03 21:27:49 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] openTcpIp: connect to 127.0.0.1 on port: 9590 Mar 03 21:27:49 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] onStart: successfully started plugin Mar 03 21:27:49 volumiobookworm volumio[6665]: info: Done. Mar 03 21:27:49 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] openTcpIp: Connected to: 127.0.0.1:9590 Mar 03 21:27:49 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] attachParser: Port is now open. Connecting Parser with delimiter: $ Mar 03 21:27:49 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] getAmpStatus: sending status requests to Amp Mar 03 21:27:49 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] sendStatusRequest: Sent command for "reqPower": get_current_power! Mar 03 21:27:49 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] sendStatusRequest: Sent command for "reqVolume": get_volume! Mar 03 21:27:49 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] sendStatusRequest: Sent command for "reqMute": get_mute_status! Mar 03 21:27:49 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] sendStatusRequest: Sent command for "reqSource": get_current_source! Mar 03 21:27:49 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] [parser:data]: Listener received: power=on Mar 03 21:27:49 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] parser:data: call processResponse with: respPowerOn Mar 03 21:27:49 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] processResponse: Amp signaled PowerOn. Previous state is: off Mar 03 21:27:49 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] processResponse: Amp Status is now {"volume":10,"mute":false,"power":"off"} Mar 03 21:27:49 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] [parser:data]: Listener received: volume=10 Mar 03 21:27:49 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] parser:data: call processResponse with: respVolume Mar 03 21:27:49 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] processResponse: Amp signaled volume is 10 Mar 03 21:27:49 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] getVolumeObject: {"mute":false,"disableVolumeControl":false,"vol":10} Mar 03 21:27:49 volumiobookworm volumio[6665]: info: CoreStateMachine::pushState Mar 03 21:27:49 volumiobookworm volumio[6665]: info: CorePlayQueue::getTrack 0 Mar 03 21:27:49 volumiobookworm volumio[6665]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 03 21:27:49 volumiobookworm volumio[6665]: info: CoreCommandRouter::volumioPushState Mar 03 21:27:49 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] processResponse: Amp Status is now {"volume":10,"mute":false,"power":"off"} Mar 03 21:27:49 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] [parser:data]: Listener received: mute=off Mar 03 21:27:49 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] parser:data: call processResponse with: respMuteOff Mar 03 21:27:49 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] processResponse: Amp signaled MuteOff Mar 03 21:27:49 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] getVolumeObject: {"mute":false,"disableVolumeControl":false,"vol":10} Mar 03 21:27:49 volumiobookworm volumio[6665]: info: CoreStateMachine::pushState Mar 03 21:27:49 volumiobookworm volumio[6665]: info: CorePlayQueue::getTrack 0 Mar 03 21:27:49 volumiobookworm volumio[6665]: info: CoreCommandRouter::volumioPushState Mar 03 21:27:49 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] processResponse: Amp Status is now {"volume":10,"mute":false,"power":"off"} Mar 03 21:27:49 volumiobookworm volumio[6665]: info: CoreStateMachine::pushState Mar 03 21:27:49 volumiobookworm volumio[6665]: info: CorePlayQueue::getTrack 0 Mar 03 21:27:49 volumiobookworm volumio[6665]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 03 21:27:49 volumiobookworm volumio[6665]: info: CoreCommandRouter::volumioPushState Mar 03 21:27:49 volumiobookworm volumio[6665]: info: CoreStateMachine::pushState Mar 03 21:27:49 volumiobookworm volumio[6665]: info: CorePlayQueue::getTrack 0 Mar 03 21:27:49 volumiobookworm volumio[6665]: info: CoreCommandRouter::volumioPushState Mar 03 21:27:49 volumiobookworm volumio[6665]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Mar 03 21:27:49 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] [parser:data]: Listener received: source=cd Mar 03 21:27:49 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] parser:data: call processResponse with: respSource Mar 03 21:27:49 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] processResponse: Amp signaled source is cd Mar 03 21:27:49 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] processResponse: Amp Status is now {"volume":10,"mute":false,"power":"off","source":"cd"} Mar 03 21:27:50 volumiobookworm volumio[6665]: info: CoreCommandRouter::volumioGetState Mar 03 21:27:50 volumiobookworm volumio[6665]: info: CorePlayQueue::getTrack 0 Mar 03 21:27:50 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] on:pushState: undefined - stop Mar 03 21:27:50 volumiobookworm volumio[6665]: info: CoreCommandRouter::volumioPlay Mar 03 21:27:50 volumiobookworm volumio[6665]: info: CoreStateMachine::play index undefined Mar 03 21:27:50 volumiobookworm volumio[6665]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 03 21:27:50 volumiobookworm volumio[6665]: info: CoreCommandRouter::volumioPlay Mar 03 21:27:50 volumiobookworm volumio[6665]: info: CoreStateMachine::play index undefined Mar 03 21:27:50 volumiobookworm volumio[6665]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 03 21:27:50 volumiobookworm volumio[6665]: info: CorePlayQueue::getTrack 0 Mar 03 21:27:50 volumiobookworm volumio[6665]: info: CoreStateMachine::startPlaybackTimer Mar 03 21:27:50 volumiobookworm volumio[6665]: info: CorePlayQueue::getTrack 0 Mar 03 21:27:50 volumiobookworm volumio[6665]: verbose: ControllerMpd::clearAddPlayTracks INTERNAL/The Ataris - The Boys of Summer.mp3 Mar 03 21:27:50 volumiobookworm volumio[6665]: verbose: ControllerMpd::sendMpdCommand stop Mar 03 21:27:50 volumiobookworm volumio[6665]: info: CorePlayQueue::getTrack 0 Mar 03 21:27:50 volumiobookworm volumio[6665]: info: CoreStateMachine::startPlaybackTimer Mar 03 21:27:50 volumiobookworm volumio[6665]: info: CorePlayQueue::getTrack 0 Mar 03 21:27:50 volumiobookworm volumio[6665]: verbose: ControllerMpd::clearAddPlayTracks INTERNAL/The Ataris - The Boys of Summer.mp3 Mar 03 21:27:50 volumiobookworm volumio[6665]: verbose: ControllerMpd::sendMpdCommand stop Mar 03 21:27:50 volumiobookworm volumio[6665]: info: sendMpdCommand stop took 1 milliseconds Mar 03 21:27:50 volumiobookworm volumio[6665]: info: sendMpdCommand stop took 1 milliseconds Mar 03 21:27:50 volumiobookworm volumio[6665]: verbose: ControllerMpd::sendMpdCommand clear Mar 03 21:27:50 volumiobookworm volumio[6665]: verbose: ControllerMpd::sendMpdCommand clear Mar 03 21:27:50 volumiobookworm volumio[6665]: info: Mar 03 21:27:50 volumiobookworm volumio[6665]: ---------------------------- MPD announces system playlist update Mar 03 21:27:50 volumiobookworm volumio[6665]: info: Ignoring MPD Status Update Mar 03 21:27:50 volumiobookworm volumio[6665]: info: sendMpdCommand clear took 1 milliseconds Mar 03 21:27:50 volumiobookworm volumio[6665]: info: sendMpdCommand clear took 1 milliseconds Mar 03 21:27:50 volumiobookworm volumio[6665]: verbose: ControllerMpd::sendMpdCommand add "INTERNAL/The Ataris - The Boys of Summer.mp3" Mar 03 21:27:50 volumiobookworm volumio[6665]: verbose: ControllerMpd::sendMpdCommand add "INTERNAL/The Ataris - The Boys of Summer.mp3" Mar 03 21:27:50 volumiobookworm volumio[6665]: info: Mar 03 21:27:50 volumiobookworm volumio[6665]: ---------------------------- MPD announces system playlist update Mar 03 21:27:50 volumiobookworm volumio[6665]: info: Ignoring MPD Status Update Mar 03 21:27:50 volumiobookworm volumio[6665]: info: Mar 03 21:27:50 volumiobookworm volumio[6665]: ---------------------------- MPD announces system playlist update Mar 03 21:27:50 volumiobookworm volumio[6665]: info: Ignoring MPD Status Update Mar 03 21:27:50 volumiobookworm volumio[6665]: error: updateQueue error: null Mar 03 21:27:50 volumiobookworm volumio[6665]: info: Mar 03 21:27:50 volumiobookworm volumio[6665]: ---------------------------- MPD announces system playlist update Mar 03 21:27:50 volumiobookworm volumio[6665]: info: Ignoring MPD Status Update Mar 03 21:27:50 volumiobookworm volumio[6665]: info: ------------------------------ 1ms Mar 03 21:27:50 volumiobookworm volumio[6665]: info: sendMpdCommand add "INTERNAL/The Ataris - The Boys of Summer.mp3" took 1 milliseconds Mar 03 21:27:50 volumiobookworm volumio[6665]: info: sendMpdCommand add "INTERNAL/The Ataris - The Boys of Summer.mp3" took 1 milliseconds Mar 03 21:27:50 volumiobookworm volumio[6665]: info: ------------------------------ 2ms Mar 03 21:27:50 volumiobookworm volumio[6665]: info: ------------------------------ 1ms Mar 03 21:27:50 volumiobookworm volumio[6665]: verbose: ControllerMpd::sendMpdCommand play Mar 03 21:27:50 volumiobookworm volumio[6665]: verbose: ControllerMpd::sendMpdCommand play Mar 03 21:27:50 volumiobookworm volumio[6665]: info: Mar 03 21:27:50 volumiobookworm volumio[6665]: ---------------------------- MPD announces system playlist update Mar 03 21:27:50 volumiobookworm volumio[6665]: info: Ignoring MPD Status Update Mar 03 21:27:50 volumiobookworm volumio[6665]: info: Mar 03 21:27:50 volumiobookworm volumio[6665]: ---------------------------- MPD announces system playlist update Mar 03 21:27:50 volumiobookworm volumio[6665]: info: Ignoring MPD Status Update Mar 03 21:27:50 volumiobookworm volumio[6665]: info: ------------------------------ 2ms Mar 03 21:27:50 volumiobookworm volumio[6665]: info: sendMpdCommand play took 1 milliseconds Mar 03 21:27:50 volumiobookworm volumio[6665]: info: sendMpdCommand play took 1 milliseconds Mar 03 21:27:50 volumiobookworm volumio[6665]: info: ------------------------------ 1ms Mar 03 21:27:50 volumiobookworm volumio[6665]: info: ------------------------------ 2ms Mar 03 21:27:50 volumiobookworm volumio[6665]: info: Mar 03 21:27:50 volumiobookworm volumio[6665]: ---------------------------- MPD announces state update: player Mar 03 21:27:50 volumiobookworm volumio[6665]: info: ControllerMpd::getState Mar 03 21:27:50 volumiobookworm volumio[6665]: verbose: ControllerMpd::sendMpdCommand status Mar 03 21:27:50 volumiobookworm volumio[6665]: info: Mar 03 21:27:50 volumiobookworm volumio[6665]: ---------------------------- MPD announces state update: player Mar 03 21:27:50 volumiobookworm volumio[6665]: info: ControllerMpd::getState Mar 03 21:27:50 volumiobookworm volumio[6665]: verbose: ControllerMpd::sendMpdCommand status Mar 03 21:27:50 volumiobookworm volumio[6665]: info: Mar 03 21:27:50 volumiobookworm volumio[6665]: ---------------------------- MPD announces state update: player Mar 03 21:27:50 volumiobookworm volumio[6665]: info: ControllerMpd::getState Mar 03 21:27:50 volumiobookworm volumio[6665]: verbose: ControllerMpd::sendMpdCommand status Mar 03 21:27:50 volumiobookworm volumio[6665]: info: Mar 03 21:27:50 volumiobookworm volumio[6665]: ---------------------------- MPD announces state update: player Mar 03 21:27:50 volumiobookworm volumio[6665]: info: ControllerMpd::getState Mar 03 21:27:50 volumiobookworm volumio[6665]: verbose: ControllerMpd::sendMpdCommand status Mar 03 21:27:50 volumiobookworm volumio[6665]: verbose: ControllerMpd::sendMpdCommand clearerror Mar 03 21:27:50 volumiobookworm volumio[6665]: info: sendMpdCommand status took 3 milliseconds Mar 03 21:27:50 volumiobookworm volumio[6665]: verbose: ControllerMpd::sendMpdCommand clearerror Mar 03 21:27:50 volumiobookworm volumio[6665]: info: sendMpdCommand status took 2 milliseconds Mar 03 21:27:50 volumiobookworm volumio[6665]: verbose: ControllerMpd::sendMpdCommand clearerror Mar 03 21:27:50 volumiobookworm volumio[6665]: info: sendMpdCommand status took 3 milliseconds Mar 03 21:27:50 volumiobookworm volumio[6665]: verbose: ControllerMpd::parseState Mar 03 21:27:50 volumiobookworm volumio[6665]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 03 21:27:50 volumiobookworm volumio[6665]: verbose: ControllerMpd::parseState Mar 03 21:27:50 volumiobookworm volumio[6665]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 03 21:27:50 volumiobookworm volumio[6665]: verbose: ControllerMpd::parseState Mar 03 21:27:50 volumiobookworm volumio[6665]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 03 21:27:50 volumiobookworm volumio[6665]: info: Mar 03 21:27:50 volumiobookworm volumio[6665]: ---------------------------- MPD announces state update: player Mar 03 21:27:50 volumiobookworm volumio[6665]: info: ControllerMpd::getState Mar 03 21:27:50 volumiobookworm volumio[6665]: verbose: ControllerMpd::sendMpdCommand status Mar 03 21:27:50 volumiobookworm volumio[6665]: info: Mar 03 21:27:50 volumiobookworm volumio[6665]: ---------------------------- MPD announces state update: player Mar 03 21:27:50 volumiobookworm volumio[6665]: info: ControllerMpd::getState Mar 03 21:27:50 volumiobookworm volumio[6665]: verbose: ControllerMpd::sendMpdCommand status Mar 03 21:27:50 volumiobookworm volumio[6665]: verbose: ControllerMpd::sendMpdCommand clearerror Mar 03 21:27:50 volumiobookworm volumio[6665]: info: sendMpdCommand status took 7 milliseconds Mar 03 21:27:50 volumiobookworm volumio[6665]: info: sendMpdCommand clearerror took 5 milliseconds Mar 03 21:27:50 volumiobookworm volumio[6665]: info: sendMpdCommand clearerror took 6 milliseconds Mar 03 21:27:50 volumiobookworm volumio[6665]: info: sendMpdCommand clearerror took 5 milliseconds Mar 03 21:27:50 volumiobookworm volumio[6665]: info: sendMpdCommand playlistinfo took 3 milliseconds Mar 03 21:27:50 volumiobookworm volumio[6665]: info: sendMpdCommand playlistinfo took 3 milliseconds Mar 03 21:27:50 volumiobookworm volumio[6665]: info: sendMpdCommand playlistinfo took 3 milliseconds Mar 03 21:27:50 volumiobookworm volumio[6665]: info: sendMpdCommand status took 3 milliseconds Mar 03 21:27:50 volumiobookworm volumio[6665]: info: sendMpdCommand status took 2 milliseconds Mar 03 21:27:50 volumiobookworm volumio[6665]: verbose: ControllerMpd::parseState Mar 03 21:27:50 volumiobookworm volumio[6665]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 03 21:27:50 volumiobookworm volumio[6665]: verbose: ControllerMpd::parseTrackInfo Mar 03 21:27:50 volumiobookworm volumio[6665]: verbose: ControllerMpd::parseTrackInfo Mar 03 21:27:50 volumiobookworm volumio[6665]: verbose: ControllerMpd::parseTrackInfo Mar 03 21:27:50 volumiobookworm volumio[6665]: verbose: ControllerMpd::parseState Mar 03 21:27:50 volumiobookworm volumio[6665]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 03 21:27:50 volumiobookworm volumio[6665]: verbose: ControllerMpd::parseState Mar 03 21:27:50 volumiobookworm volumio[6665]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 03 21:27:50 volumiobookworm volumio[6665]: info: ControllerMpd::pushState Mar 03 21:27:50 volumiobookworm volumio[6665]: info: CoreCommandRouter::servicePushState Mar 03 21:27:50 volumiobookworm volumio[6665]: info: CorePlayQueue::getTrack 0 Mar 03 21:27:50 volumiobookworm volumio[6665]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":242,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"The Boys of Summer","artist":"The Ataris","album":null,"uri":"INTERNAL/The Ataris - The Boys of Summer.mp3","trackType":"mp3"} Mar 03 21:27:50 volumiobookworm volumio[6665]: verbose: CURRENT POSITION 0 Mar 03 21:27:50 volumiobookworm volumio[6665]: info: CoreStateMachine::syncState stateService pause Mar 03 21:27:50 volumiobookworm volumio[6665]: info: CoreStateMachine::syncState currentStatus stop Mar 03 21:27:50 volumiobookworm volumio[6665]: info: CoreStateMachine::pushState Mar 03 21:27:50 volumiobookworm volumio[6665]: info: CorePlayQueue::getTrack 0 Mar 03 21:27:50 volumiobookworm volumio[6665]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 03 21:27:50 volumiobookworm volumio[6665]: info: CoreCommandRouter::volumioPushState Mar 03 21:27:50 volumiobookworm volumio[6665]: info: ControllerMpd::pushState Mar 03 21:27:50 volumiobookworm volumio[6665]: info: CoreCommandRouter::servicePushState Mar 03 21:27:50 volumiobookworm volumio[6665]: info: CorePlayQueue::getTrack 0 Mar 03 21:27:50 volumiobookworm volumio[6665]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":242,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"The Boys of Summer","artist":"The Ataris","album":null,"uri":"INTERNAL/The Ataris - The Boys of Summer.mp3","trackType":"mp3"} Mar 03 21:27:50 volumiobookworm volumio[6665]: verbose: CURRENT POSITION 0 Mar 03 21:27:50 volumiobookworm volumio[6665]: info: CoreStateMachine::syncState stateService pause Mar 03 21:27:50 volumiobookworm volumio[6665]: info: CoreStateMachine::syncState currentStatus stop Mar 03 21:27:50 volumiobookworm volumio[6665]: info: CoreStateMachine::pushState Mar 03 21:27:50 volumiobookworm volumio[6665]: info: CorePlayQueue::getTrack 0 Mar 03 21:27:50 volumiobookworm volumio[6665]: info: CoreCommandRouter::volumioPushState Mar 03 21:27:50 volumiobookworm volumio[6665]: info: ControllerMpd::pushState Mar 03 21:27:50 volumiobookworm volumio[6665]: info: CoreCommandRouter::servicePushState Mar 03 21:27:50 volumiobookworm volumio[6665]: info: CorePlayQueue::getTrack 0 Mar 03 21:27:50 volumiobookworm volumio[6665]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":242,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"The Boys of Summer","artist":"The Ataris","album":null,"uri":"INTERNAL/The Ataris - The Boys of Summer.mp3","trackType":"mp3"} Mar 03 21:27:50 volumiobookworm volumio[6665]: verbose: CURRENT POSITION 0 Mar 03 21:27:50 volumiobookworm volumio[6665]: info: CoreStateMachine::syncState stateService pause Mar 03 21:27:50 volumiobookworm volumio[6665]: info: CoreStateMachine::syncState currentStatus stop Mar 03 21:27:50 volumiobookworm volumio[6665]: info: CoreStateMachine::pushState Mar 03 21:27:50 volumiobookworm volumio[6665]: info: CorePlayQueue::getTrack 0 Mar 03 21:27:50 volumiobookworm volumio[6665]: info: CoreCommandRouter::volumioPushState Mar 03 21:27:50 volumiobookworm volumio[6665]: info: ------------------------------ 18ms Mar 03 21:27:50 volumiobookworm volumio[6665]: info: ------------------------------ 17ms Mar 03 21:27:50 volumiobookworm volumio[6665]: info: ------------------------------ 18ms Mar 03 21:27:50 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] on:pushState: undefined - stop Mar 03 21:27:50 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] on:pushState: undefined - stop Mar 03 21:27:50 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] on:pushState: undefined - stop Mar 03 21:27:50 volumiobookworm volumio[6665]: info: sendMpdCommand clearerror took 16 milliseconds Mar 03 21:27:50 volumiobookworm volumio[6665]: info: sendMpdCommand playlistinfo took 15 milliseconds Mar 03 21:27:50 volumiobookworm volumio[6665]: info: sendMpdCommand playlistinfo took 14 milliseconds Mar 03 21:27:50 volumiobookworm volumio[6665]: info: sendMpdCommand playlistinfo took 13 milliseconds Mar 03 21:27:50 volumiobookworm volumio[6665]: verbose: ControllerMpd::parseTrackInfo Mar 03 21:27:50 volumiobookworm volumio[6665]: verbose: ControllerMpd::parseTrackInfo Mar 03 21:27:50 volumiobookworm volumio[6665]: verbose: ControllerMpd::parseTrackInfo Mar 03 21:27:50 volumiobookworm volumio[6665]: info: ControllerMpd::pushState Mar 03 21:27:50 volumiobookworm volumio[6665]: info: CoreCommandRouter::servicePushState Mar 03 21:27:50 volumiobookworm volumio[6665]: info: CorePlayQueue::getTrack 0 Mar 03 21:27:50 volumiobookworm volumio[6665]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":242,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"The Boys of Summer","artist":"The Ataris","album":null,"uri":"INTERNAL/The Ataris - The Boys of Summer.mp3","trackType":"mp3"} Mar 03 21:27:50 volumiobookworm volumio[6665]: verbose: CURRENT POSITION 0 Mar 03 21:27:50 volumiobookworm volumio[6665]: info: CoreStateMachine::syncState stateService pause Mar 03 21:27:50 volumiobookworm volumio[6665]: info: CoreStateMachine::syncState currentStatus stop Mar 03 21:27:50 volumiobookworm volumio[6665]: info: CoreStateMachine::pushState Mar 03 21:27:50 volumiobookworm volumio[6665]: info: CorePlayQueue::getTrack 0 Mar 03 21:27:50 volumiobookworm volumio[6665]: info: CoreCommandRouter::volumioPushState Mar 03 21:27:50 volumiobookworm volumio[6665]: info: ControllerMpd::pushState Mar 03 21:27:50 volumiobookworm volumio[6665]: info: CoreCommandRouter::servicePushState Mar 03 21:27:50 volumiobookworm volumio[6665]: info: CorePlayQueue::getTrack 0 Mar 03 21:27:50 volumiobookworm volumio[6665]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":242,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"The Boys of Summer","artist":"The Ataris","album":null,"uri":"INTERNAL/The Ataris - The Boys of Summer.mp3","trackType":"mp3"} Mar 03 21:27:50 volumiobookworm volumio[6665]: verbose: CURRENT POSITION 0 Mar 03 21:27:50 volumiobookworm volumio[6665]: info: CoreStateMachine::syncState stateService pause Mar 03 21:27:50 volumiobookworm volumio[6665]: info: CoreStateMachine::syncState currentStatus stop Mar 03 21:27:50 volumiobookworm volumio[6665]: info: CoreStateMachine::pushState Mar 03 21:27:50 volumiobookworm volumio[6665]: info: CorePlayQueue::getTrack 0 Mar 03 21:27:50 volumiobookworm volumio[6665]: info: CoreCommandRouter::volumioPushState Mar 03 21:27:50 volumiobookworm volumio[6665]: info: ControllerMpd::pushState Mar 03 21:27:50 volumiobookworm volumio[6665]: info: CoreCommandRouter::servicePushState Mar 03 21:27:50 volumiobookworm volumio[6665]: info: CorePlayQueue::getTrack 0 Mar 03 21:27:50 volumiobookworm volumio[6665]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":242,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"The Boys of Summer","artist":"The Ataris","album":null,"uri":"INTERNAL/The Ataris - The Boys of Summer.mp3","trackType":"mp3"} Mar 03 21:27:50 volumiobookworm volumio[6665]: verbose: CURRENT POSITION 0 Mar 03 21:27:50 volumiobookworm volumio[6665]: info: CoreStateMachine::syncState stateService pause Mar 03 21:27:50 volumiobookworm volumio[6665]: info: CoreStateMachine::syncState currentStatus stop Mar 03 21:27:50 volumiobookworm volumio[6665]: info: CoreStateMachine::pushState Mar 03 21:27:50 volumiobookworm volumio[6665]: info: CorePlayQueue::getTrack 0 Mar 03 21:27:50 volumiobookworm volumio[6665]: info: CoreCommandRouter::volumioPushState Mar 03 21:27:50 volumiobookworm volumio[6665]: info: ------------------------------ 30ms Mar 03 21:27:50 volumiobookworm volumio[6665]: info: ------------------------------ 25ms Mar 03 21:27:50 volumiobookworm volumio[6665]: info: ------------------------------ 25ms Mar 03 21:27:50 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] on:pushState: undefined - stop Mar 03 21:27:50 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] on:pushState: undefined - stop Mar 03 21:27:50 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] on:pushState: undefined - stop Mar 03 21:27:59 volumiobookworm volumio[6665]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 03 21:27:59 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] initVolumeSettings: getAlsaCards "0" Mar 03 21:27:59 volumiobookworm volumio[6665]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getAlsaCards Mar 03 21:27:59 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] initVolumeSettings: getAlsaCards [{"id":"0","alsacard":"sndrpihifiberry","name":"Hifiberry DAC"},{"id":"1","alsacard":"vc4hdmi0","name":"HDMI 0 Out"},{"id":"2","alsacard":"vc4hdmi1","name":"HDMI 1 Out"}] Mar 03 21:27:59 volumiobookworm volumio[6665]: info: CoreCommandRouter::volumioUpdateVolumeSettings Mar 03 21:27:59 volumiobookworm volumio[6665]: info: Updating Volume Controller Parameters: Device: 0 Name: Hifiberry DAC Mixer: Max Vol: 30 Vol Curve; Vol Steps: 1 Mar 03 21:27:59 volumiobookworm volumio[6665]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Mar 03 21:27:59 volumiobookworm volumio[6665]: info: Enabling external Volume Control Mar 03 21:27:59 volumiobookworm volumio[6665]: info: CoreCommandRouter::executeOnPlugin: serialampcontroller , updateVolumeSettings Mar 03 21:27:59 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] updateVolumeSettings: received {"pluginType":"system_hardware","pluginName":"serialampcontroller","volumeOverride":true,"device":"0","name":"Hifiberry DAC","alsacard":"sndrpihifiberry","devicename":"Rotel - RC-1592 >=V1.53","mixer":"","mixertype":"None","maxvolume":30,"volumecurve":"","volumesteps":1} Mar 03 21:27:59 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] retrieveVolume: Mar 03 21:27:59 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] getVolumeObject: {"mute":false,"disableVolumeControl":false,"vol":10} Mar 03 21:27:59 volumiobookworm volumio[6665]: info: CoreCommandRouter::executeOnPlugin: serialampcontroller , retrievevolume Mar 03 21:27:59 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] retrieveVolume: Mar 03 21:27:59 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] getVolumeObject: {"mute":false,"disableVolumeControl":false,"vol":10} Mar 03 21:28:00 volumiobookworm volumio[6665]: info: CoreStateMachine::pushState Mar 03 21:28:00 volumiobookworm volumio[6665]: info: CorePlayQueue::getTrack 0 Mar 03 21:28:00 volumiobookworm volumio[6665]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 03 21:28:00 volumiobookworm volumio[6665]: info: CoreCommandRouter::volumioPushState Mar 03 21:28:00 volumiobookworm volumio[6665]: info: CoreStateMachine::pushState Mar 03 21:28:00 volumiobookworm volumio[6665]: info: CorePlayQueue::getTrack 0 Mar 03 21:28:00 volumiobookworm volumio[6665]: info: CoreCommandRouter::volumioPushState Mar 03 21:28:00 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] on:pushState: undefined - stop Mar 03 21:28:00 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] on:pushState: undefined - stop Mar 03 21:28:00 volumiobookworm volumio[6665]: info: CoreCommandRouter::getUIConfigOnPlugin Mar 03 21:28:00 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] getUIConfig: interface: TCP/IP; amps: ["Rotel - RC-1592 >=V1.53","Rotel - RSP-1582 SW V5.xx","Rotel - RA-1592 SW >=V1.52"]selected: Rotel - RC-1592 >=V1.53 Mar 03 21:28:04 volumiobookworm volumio[6665]: info: CALLMETHOD: system_hardware serialampcontroller updateSerialSettings [object Object] Mar 03 21:28:04 volumiobookworm volumio[6665]: info: CoreCommandRouter::executeOnPlugin: serialampcontroller , updateSerialSettings Mar 03 21:28:04 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] updateSerialSettings: Saving Interface Settings:{"tcp_ip":false,"serial_interface_dev":{"value":1,"label":"usb-Prolific_Technology_Inc._USB-Serial_Controller_D-if00-port0"},"ip_address":"127.0.0.1"} Mar 03 21:28:04 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] closePorts: closing TCP/IP Mar 03 21:28:04 volumiobookworm volumio[6665]: info: CoreCommandRouter::getUIConfigOnPlugin Mar 03 21:28:04 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] closePorts: closed TCP/IP socket Mar 03 21:28:04 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] getUIConfig: interface: RS232; amps: ["Anthem - IDMSTR IA","Rotel - A12","Rotel - A14","Rotel - A11","Rotel - RC-1570","Rotel - RC-1592 >=V1.53","Rotel - RSP-1582 SW V5.xx","Rotel - RA-1592 SW >=V1.52","Meridian - DSP420","Cambridge - CXA61"]selected: ... Mar 03 21:28:04 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] getI18nString("TOAST_SAVE_SUCCESS"):Speichern erfolgreich Mar 03 21:28:04 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] getI18nString("TOAST_SERIAL_SAVE"):Einstellungen Serielle Schnittstelle Mar 03 21:28:09 volumiobookworm volumio[6665]: info: CALLMETHOD: system_hardware serialampcontroller updateAmpType [object Object] Mar 03 21:28:09 volumiobookworm volumio[6665]: info: CoreCommandRouter::executeOnPlugin: serialampcontroller , updateAmpType Mar 03 21:28:09 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] updateAmpType: Saving Amplifier Settings:{"amp_type":{"value":2,"label":"Rotel - A12"}} Mar 03 21:28:09 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] setActiveAmp: {"vendor":"Rotel","model":"A12","baudRate":115200,"parity":"none","dataBits":8,"stopBits":1,"rtscts":false,"xon":false,"xoff":false,"xany":false,"sources":["CD","Coax1","Coax2","Opt1","Opt2","Aux1","Aux2","Tuner","Phono","USB","Bluetooth","PC-USB"],"sourceCmd":["cd!","coax1!","coax2!","opt1!","opt2!","aux1!","aux2!","tuner!","phono!","usb!","bluetooth!","pcusb!"],"sourceRespPostfix":["cd","coax1","coax2","opt1","opt2","aux1","aux2","tuner","phono","usb","bluetooth","pc_usb"],"delimiter":"$","commands":{"powerOn":"power_on!","powerToggle":"power_toggle!","volUp":"vol_up!","volDown":"vol_dwn!","volValue":"vol_##!","mute":"mute!","muteOn":"mute_on!","muteOff":"mute_off!"},"responses":[{"rx":"power=on","cmd":["respPowerOn"]},{"rx":"power=standby","cmd":["respPowerOff"]},{"rx":"volume=([0-9]{2})","cmd":["respVolume"]},{"rx":"mute=on","cmd":["respMuteOn"]},{"rx":"mute=off","cmd":["respMuteOff"]},{"rx":"source=([a-z_12]*)","cmd":["respSource"]}],"statusRequests":{"reqPower":"power?","reqSource":"source?","reqVolume":"volume?","reqMute":"mute?","reqModel":"model?"}} Mar 03 21:28:09 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] setActiveAmp: can send these responses: respPowerOn,respPowerOff,respVolume,respMuteOn,respMuteOff,respSource Mar 03 21:28:09 volumiobookworm volumio[6665]: info: CoreCommandRouter::getUIConfigOnPlugin Mar 03 21:28:09 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] getUIConfig: interface: RS232; amps: ["Anthem - IDMSTR IA","Rotel - A12","Rotel - A14","Rotel - A11","Rotel - RC-1570","Rotel - RC-1592 >=V1.53","Rotel - RSP-1582 SW V5.xx","Rotel - RA-1592 SW >=V1.52","Meridian - DSP420","Cambridge - CXA61"]selected: Rotel - A12 Mar 03 21:28:09 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] closePorts: port is undefined Mar 03 21:28:09 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] selectedInterfaceExists: usb-Prolific_Technology_Inc._USB-Serial_Controller_D-if00-port0 in [{"path":"/dev/ttyUSB0","manufacturer":"Prolific Technology Inc. ","pnpId":"usb-Prolific_Technology_Inc._USB-Serial_Controller_D-if00-port0","vendorId":"067b","productId":"2303"}]?: true Mar 03 21:28:09 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] selectedAmpSupportsInterface: RS232 in [] Mar 03 21:28:09 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] openSerialPort: starting Mar 03 21:28:09 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] openSerialPort: check for usb-Prolific_Technology_Inc._USB-Serial_Controller_D-if00-port0 in [{"path":"/dev/ttyUSB0","manufacturer":"Prolific Technology Inc. ","pnpId":"usb-Prolific_Technology_Inc._USB-Serial_Controller_D-if00-port0","vendorId":"067b","productId":"2303"}] Mar 03 21:28:09 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] openSerialPort: connect to [{"path":"/dev/ttyUSB0","manufacturer":"Prolific Technology Inc. ","pnpId":"usb-Prolific_Technology_Inc._USB-Serial_Controller_D-if00-port0","vendorId":"067b","productId":"2303"}] configured with: {"autoOpen":false,"lock":false,"endOnClose":true,"baudRate":115200,"dataBits":8,"stopBits":1,"parity":"none","rtscts":false,"xon":false,"xoff":false,"xany":false} at /dev/ttyUSB0 Mar 03 21:28:09 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] openSerialPort: Now trying to open port Mar 03 21:28:09 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] getI18nString("TOAST_SAVE_SUCCESS"):Speichern erfolgreich Mar 03 21:28:09 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] getI18nString("TOAST_AMP_TYPE_SAVE"):Verstärker Typ Mar 03 21:28:09 volumiobookworm volumio[6665]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 Mar 03 21:28:09 volumiobookworm volumio[6665]: info: CoreCommandRouter::volumioGetState Mar 03 21:28:09 volumiobookworm volumio[6665]: info: CorePlayQueue::getTrack 0 Mar 03 21:28:09 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] on:pushState: undefined - stop Mar 03 21:28:09 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] attachParser: Port is now open. Connecting Parser with delimiter: $ Mar 03 21:28:09 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] getAmpStatus: sending status requests to Amp Mar 03 21:28:09 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] openSerialPort: Connection established. Mar 03 21:28:09 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] sendStatusRequest: Sent command for "reqModel": model? Mar 03 21:28:09 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] sendStatusRequest: Sent command for "reqPower": power? Mar 03 21:28:09 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] sendStatusRequest: Sent command for "reqVolume": volume? Mar 03 21:28:09 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] sendStatusRequest: Sent command for "reqMute": mute? Mar 03 21:28:09 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] sendStatusRequest: Sent command for "reqSource": source? Mar 03 21:28:09 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] [parser:data]: Listener received: model=a12 Mar 03 21:28:09 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] parser:data: no matching regex for: model=a12 Mar 03 21:28:09 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] [parser:data]: Listener received: power=on Mar 03 21:28:09 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] parser:data: call processResponse with: respPowerOn Mar 03 21:28:09 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] processResponse: Amp signaled PowerOn. Previous state is: on Mar 03 21:28:09 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] processResponse: Amp Status is now {"volume":10,"mute":false,"power":"on","source":"cd"} Mar 03 21:28:09 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] [parser:data]: Listener received: volume=25 Mar 03 21:28:09 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] parser:data: call processResponse with: respVolume Mar 03 21:28:09 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] processResponse: Amp signaled volume is 25 Mar 03 21:28:09 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] getVolumeObject: {"mute":false,"disableVolumeControl":false,"vol":25} Mar 03 21:28:09 volumiobookworm volumio[6665]: info: CoreStateMachine::pushState Mar 03 21:28:09 volumiobookworm volumio[6665]: info: CorePlayQueue::getTrack 0 Mar 03 21:28:09 volumiobookworm volumio[6665]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 03 21:28:09 volumiobookworm volumio[6665]: info: CoreCommandRouter::volumioPushState Mar 03 21:28:09 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] processResponse: Amp Status is now {"volume":25,"mute":false,"power":"on","source":"cd"} Mar 03 21:28:09 volumiobookworm volumio[6665]: info: CoreStateMachine::pushState Mar 03 21:28:09 volumiobookworm volumio[6665]: info: CorePlayQueue::getTrack 0 Mar 03 21:28:09 volumiobookworm volumio[6665]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 03 21:28:09 volumiobookworm volumio[6665]: info: CoreCommandRouter::volumioPushState Mar 03 21:28:09 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] [parser:data]: Listener received: mute=off Mar 03 21:28:09 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] parser:data: call processResponse with: respMuteOff Mar 03 21:28:09 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] processResponse: Amp signaled MuteOff Mar 03 21:28:09 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] getVolumeObject: {"mute":false,"disableVolumeControl":false,"vol":25} Mar 03 21:28:09 volumiobookworm volumio[6665]: info: CoreStateMachine::pushState Mar 03 21:28:09 volumiobookworm volumio[6665]: info: CorePlayQueue::getTrack 0 Mar 03 21:28:09 volumiobookworm volumio[6665]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 03 21:28:09 volumiobookworm volumio[6665]: info: CoreCommandRouter::volumioPushState Mar 03 21:28:09 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] processResponse: Amp Status is now {"volume":25,"mute":false,"power":"on","source":"cd"} Mar 03 21:28:09 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] [parser:data]: Listener received: source=bluetooth Mar 03 21:28:09 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] parser:data: call processResponse with: respSource Mar 03 21:28:09 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] processResponse: Amp signaled source is bluetooth Mar 03 21:28:09 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] processResponse: Amp Status is now {"volume":25,"mute":false,"power":"on","source":"bluetooth"} Mar 03 21:28:09 volumiobookworm volumio[6665]: info: CoreStateMachine::pushState Mar 03 21:28:09 volumiobookworm volumio[6665]: info: CorePlayQueue::getTrack 0 Mar 03 21:28:09 volumiobookworm volumio[6665]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 03 21:28:09 volumiobookworm volumio[6665]: info: CoreCommandRouter::volumioPushState Mar 03 21:28:09 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] on:pushState: undefined - stop Mar 03 21:28:09 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] on:pushState: undefined - stop Mar 03 21:28:09 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] on:pushState: undefined - stop Mar 03 21:28:09 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] on:pushState: undefined - stop Mar 03 21:28:09 volumiobookworm volumio[6665]: info: CoreCommandRouter::volumioPlay Mar 03 21:28:09 volumiobookworm volumio[6665]: info: CoreStateMachine::play index undefined Mar 03 21:28:09 volumiobookworm volumio[6665]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 03 21:28:09 volumiobookworm volumio[6665]: info: CoreCommandRouter::volumioPause Mar 03 21:28:09 volumiobookworm volumio[6665]: info: CoreStateMachine::pause Mar 03 21:28:09 volumiobookworm volumio[6665]: info: CorePlayQueue::getTrack 0 Mar 03 21:28:09 volumiobookworm volumio[6665]: info: CoreStateMachine::startPlaybackTimer Mar 03 21:28:09 volumiobookworm volumio[6665]: info: CorePlayQueue::getTrack 0 Mar 03 21:28:09 volumiobookworm volumio[6665]: verbose: ControllerMpd::clearAddPlayTracks INTERNAL/The Ataris - The Boys of Summer.mp3 Mar 03 21:28:09 volumiobookworm volumio[6665]: verbose: ControllerMpd::sendMpdCommand stop Mar 03 21:28:09 volumiobookworm volumio[6665]: info: Mar 03 21:28:09 volumiobookworm volumio[6665]: ---------------------------- MPD announces state update: player Mar 03 21:28:09 volumiobookworm volumio[6665]: info: sendMpdCommand stop took 1 milliseconds Mar 03 21:28:09 volumiobookworm volumio[6665]: info: ControllerMpd::getState Mar 03 21:28:09 volumiobookworm volumio[6665]: verbose: ControllerMpd::sendMpdCommand status Mar 03 21:28:09 volumiobookworm volumio[6665]: verbose: ControllerMpd::sendMpdCommand clear Mar 03 21:28:09 volumiobookworm volumio[6665]: info: Mar 03 21:28:09 volumiobookworm volumio[6665]: ---------------------------- MPD announces state update: player Mar 03 21:28:09 volumiobookworm volumio[6665]: info: ControllerMpd::getState Mar 03 21:28:09 volumiobookworm volumio[6665]: verbose: ControllerMpd::sendMpdCommand status Mar 03 21:28:09 volumiobookworm volumio[6665]: info: Mar 03 21:28:09 volumiobookworm volumio[6665]: ---------------------------- MPD announces state update: player Mar 03 21:28:09 volumiobookworm volumio[6665]: info: ControllerMpd::getState Mar 03 21:28:09 volumiobookworm volumio[6665]: verbose: ControllerMpd::sendMpdCommand status Mar 03 21:28:09 volumiobookworm volumio[6665]: info: Mar 03 21:28:09 volumiobookworm volumio[6665]: ---------------------------- MPD announces system playlist update Mar 03 21:28:09 volumiobookworm volumio[6665]: info: Ignoring MPD Status Update Mar 03 21:28:09 volumiobookworm volumio[6665]: info: sendMpdCommand status took 2 milliseconds Mar 03 21:28:09 volumiobookworm volumio[6665]: info: sendMpdCommand clear took 1 milliseconds Mar 03 21:28:09 volumiobookworm volumio[6665]: info: sendMpdCommand status took 1 milliseconds Mar 03 21:28:09 volumiobookworm volumio[6665]: info: sendMpdCommand status took 1 milliseconds Mar 03 21:28:09 volumiobookworm volumio[6665]: verbose: ControllerMpd::parseState Mar 03 21:28:09 volumiobookworm volumio[6665]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 03 21:28:09 volumiobookworm volumio[6665]: verbose: ControllerMpd::sendMpdCommand add "INTERNAL/The Ataris - The Boys of Summer.mp3" Mar 03 21:28:09 volumiobookworm volumio[6665]: verbose: ControllerMpd::parseState Mar 03 21:28:09 volumiobookworm volumio[6665]: verbose: ControllerMpd::parseState Mar 03 21:28:09 volumiobookworm volumio[6665]: info: ControllerMpd::pushState Mar 03 21:28:09 volumiobookworm volumio[6665]: info: CoreCommandRouter::servicePushState Mar 03 21:28:09 volumiobookworm volumio[6665]: info: CoreStateMachine::pushState Mar 03 21:28:09 volumiobookworm volumio[6665]: info: CorePlayQueue::getTrack 0 Mar 03 21:28:09 volumiobookworm volumio[6665]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 03 21:28:09 volumiobookworm volumio[6665]: info: CoreCommandRouter::volumioPushState Mar 03 21:28:09 volumiobookworm volumio[6665]: info: CorePlayQueue::getTrack 0 Mar 03 21:28:09 volumiobookworm volumio[6665]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Mar 03 21:28:09 volumiobookworm volumio[6665]: verbose: CURRENT POSITION 0 Mar 03 21:28:09 volumiobookworm volumio[6665]: info: CoreStateMachine::syncState stateService stop Mar 03 21:28:09 volumiobookworm volumio[6665]: info: CoreStateMachine::syncState currentStatus stop Mar 03 21:28:09 volumiobookworm volumio[6665]: info: CoreStateMachine::pushState Mar 03 21:28:09 volumiobookworm volumio[6665]: info: CorePlayQueue::getTrack 0 Mar 03 21:28:09 volumiobookworm volumio[6665]: info: CoreCommandRouter::volumioPushState Mar 03 21:28:09 volumiobookworm volumio[6665]: info: No code Mar 03 21:28:09 volumiobookworm volumio[6665]: info: CoreStateMachine::pushState Mar 03 21:28:09 volumiobookworm volumio[6665]: info: CorePlayQueue::getTrack 0 Mar 03 21:28:09 volumiobookworm volumio[6665]: info: CoreCommandRouter::volumioPushState Mar 03 21:28:09 volumiobookworm volumio[6665]: info: ControllerMpd::pushState Mar 03 21:28:09 volumiobookworm volumio[6665]: info: CoreCommandRouter::servicePushState Mar 03 21:28:09 volumiobookworm volumio[6665]: info: CoreStateMachine::pushState Mar 03 21:28:09 volumiobookworm volumio[6665]: info: CorePlayQueue::getTrack 0 Mar 03 21:28:09 volumiobookworm volumio[6665]: info: CoreCommandRouter::volumioPushState Mar 03 21:28:09 volumiobookworm volumio[6665]: info: CorePlayQueue::getTrack 0 Mar 03 21:28:09 volumiobookworm volumio[6665]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} Mar 03 21:28:09 volumiobookworm volumio[6665]: verbose: CURRENT POSITION 0 Mar 03 21:28:09 volumiobookworm volumio[6665]: info: CoreStateMachine::syncState stateService stop Mar 03 21:28:09 volumiobookworm volumio[6665]: info: CoreStateMachine::syncState currentStatus stop Mar 03 21:28:09 volumiobookworm volumio[6665]: info: CoreStateMachine::pushState Mar 03 21:28:09 volumiobookworm volumio[6665]: info: CorePlayQueue::getTrack 0 Mar 03 21:28:09 volumiobookworm volumio[6665]: info: CoreCommandRouter::volumioPushState Mar 03 21:28:09 volumiobookworm volumio[6665]: info: No code Mar 03 21:28:09 volumiobookworm volumio[6665]: info: CoreStateMachine::pushState Mar 03 21:28:09 volumiobookworm volumio[6665]: info: CorePlayQueue::getTrack 0 Mar 03 21:28:09 volumiobookworm volumio[6665]: info: CoreCommandRouter::volumioPushState Mar 03 21:28:09 volumiobookworm volumio[6665]: info: ------------------------------ 16ms Mar 03 21:28:09 volumiobookworm volumio[6665]: info: ------------------------------ 16ms Mar 03 21:28:09 volumiobookworm volumio[6665]: info: Mar 03 21:28:09 volumiobookworm volumio[6665]: ---------------------------- MPD announces system playlist update Mar 03 21:28:09 volumiobookworm volumio[6665]: info: Ignoring MPD Status Update Mar 03 21:28:09 volumiobookworm volumio[6665]: info: Mar 03 21:28:09 volumiobookworm volumio[6665]: ---------------------------- MPD announces system playlist update Mar 03 21:28:09 volumiobookworm volumio[6665]: info: Ignoring MPD Status Update Mar 03 21:28:09 volumiobookworm volumio[6665]: error: updateQueue error: null Mar 03 21:28:09 volumiobookworm volumio[6665]: info: Mar 03 21:28:09 volumiobookworm volumio[6665]: ---------------------------- MPD announces system playlist update Mar 03 21:28:09 volumiobookworm volumio[6665]: info: Ignoring MPD Status Update Mar 03 21:28:09 volumiobookworm volumio[6665]: info: ------------------------------ 16ms Mar 03 21:28:09 volumiobookworm volumio[6665]: info: sendMpdCommand playlistinfo took 16 milliseconds Mar 03 21:28:09 volumiobookworm volumio[6665]: info: sendMpdCommand add "INTERNAL/The Ataris - The Boys of Summer.mp3" took 16 milliseconds Mar 03 21:28:09 volumiobookworm volumio[6665]: info: ------------------------------ 2ms Mar 03 21:28:09 volumiobookworm volumio[6665]: info: ------------------------------ 1ms Mar 03 21:28:09 volumiobookworm volumio[6665]: verbose: ControllerMpd::parseTrackInfo Mar 03 21:28:09 volumiobookworm volumio[6665]: verbose: ControllerMpd::sendMpdCommand play Mar 03 21:28:09 volumiobookworm volumio[6665]: error: ControllerMpd::pushError: TypeError: Cannot read properties of undefined (reading 'split') Mar 03 21:28:09 volumiobookworm volumio[6665]: info: ------------------------------ 19ms Mar 03 21:28:09 volumiobookworm volumio[6665]: info: Mar 03 21:28:09 volumiobookworm volumio[6665]: ---------------------------- MPD announces system playlist update Mar 03 21:28:09 volumiobookworm volumio[6665]: info: Ignoring MPD Status Update Mar 03 21:28:09 volumiobookworm volumio[6665]: info: Mar 03 21:28:09 volumiobookworm volumio[6665]: ---------------------------- MPD announces system playlist update Mar 03 21:28:09 volumiobookworm volumio[6665]: info: Ignoring MPD Status Update Mar 03 21:28:09 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] on:pushState: undefined - stop Mar 03 21:28:09 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] on:pushState: undefined - stop Mar 03 21:28:09 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] on:pushState: undefined - stop Mar 03 21:28:09 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] on:pushState: undefined - stop Mar 03 21:28:09 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] on:pushState: undefined - stop Mar 03 21:28:09 volumiobookworm volumio[6665]: info: Mar 03 21:28:09 volumiobookworm volumio[6665]: ---------------------------- MPD announces state update: player Mar 03 21:28:09 volumiobookworm volumio[6665]: info: ------------------------------ 8ms Mar 03 21:28:09 volumiobookworm volumio[6665]: info: sendMpdCommand play took 7 milliseconds Mar 03 21:28:09 volumiobookworm volumio[6665]: info: ------------------------------ 7ms Mar 03 21:28:09 volumiobookworm volumio[6665]: info: ------------------------------ 6ms Mar 03 21:28:09 volumiobookworm volumio[6665]: info: ControllerMpd::getState Mar 03 21:28:09 volumiobookworm volumio[6665]: verbose: ControllerMpd::sendMpdCommand status Mar 03 21:28:09 volumiobookworm volumio[6665]: info: Mar 03 21:28:09 volumiobookworm volumio[6665]: ---------------------------- MPD announces state update: player Mar 03 21:28:09 volumiobookworm volumio[6665]: info: ControllerMpd::getState Mar 03 21:28:09 volumiobookworm volumio[6665]: verbose: ControllerMpd::sendMpdCommand status Mar 03 21:28:09 volumiobookworm volumio[6665]: info: Mar 03 21:28:09 volumiobookworm volumio[6665]: ---------------------------- MPD announces state update: player Mar 03 21:28:09 volumiobookworm volumio[6665]: info: ControllerMpd::getState Mar 03 21:28:09 volumiobookworm volumio[6665]: verbose: ControllerMpd::sendMpdCommand status Mar 03 21:28:09 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] on:pushState: undefined - stop Mar 03 21:28:09 volumiobookworm volumio[6665]: verbose: ControllerMpd::sendMpdCommand clearerror Mar 03 21:28:09 volumiobookworm volumio[6665]: info: sendMpdCommand status took 3 milliseconds Mar 03 21:28:09 volumiobookworm volumio[6665]: verbose: ControllerMpd::sendMpdCommand clearerror Mar 03 21:28:09 volumiobookworm volumio[6665]: info: sendMpdCommand status took 3 milliseconds Mar 03 21:28:09 volumiobookworm volumio[6665]: verbose: ControllerMpd::sendMpdCommand clearerror Mar 03 21:28:09 volumiobookworm volumio[6665]: info: sendMpdCommand status took 2 milliseconds Mar 03 21:28:09 volumiobookworm volumio[6665]: verbose: ControllerMpd::parseState Mar 03 21:28:09 volumiobookworm volumio[6665]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 03 21:28:09 volumiobookworm volumio[6665]: verbose: ControllerMpd::parseState Mar 03 21:28:09 volumiobookworm volumio[6665]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 03 21:28:09 volumiobookworm volumio[6665]: verbose: ControllerMpd::parseState Mar 03 21:28:09 volumiobookworm volumio[6665]: verbose: ControllerMpd::sendMpdCommand playlistinfo Mar 03 21:28:09 volumiobookworm volumio[6665]: info: sendMpdCommand clearerror took 3 milliseconds Mar 03 21:28:09 volumiobookworm volumio[6665]: info: sendMpdCommand clearerror took 3 milliseconds Mar 03 21:28:09 volumiobookworm volumio[6665]: info: sendMpdCommand clearerror took 3 milliseconds Mar 03 21:28:09 volumiobookworm volumio[6665]: info: sendMpdCommand playlistinfo took 1 milliseconds Mar 03 21:28:09 volumiobookworm volumio[6665]: info: sendMpdCommand playlistinfo took 0 milliseconds Mar 03 21:28:09 volumiobookworm volumio[6665]: info: sendMpdCommand playlistinfo took 0 milliseconds Mar 03 21:28:09 volumiobookworm volumio[6665]: verbose: ControllerMpd::parseTrackInfo Mar 03 21:28:09 volumiobookworm volumio[6665]: verbose: ControllerMpd::parseTrackInfo Mar 03 21:28:09 volumiobookworm volumio[6665]: verbose: ControllerMpd::parseTrackInfo Mar 03 21:28:09 volumiobookworm volumio[6665]: info: ControllerMpd::pushState Mar 03 21:28:09 volumiobookworm volumio[6665]: info: CoreCommandRouter::servicePushState Mar 03 21:28:09 volumiobookworm volumio[6665]: info: CorePlayQueue::getTrack 0 Mar 03 21:28:09 volumiobookworm volumio[6665]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":242,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"The Boys of Summer","artist":"The Ataris","album":null,"uri":"INTERNAL/The Ataris - The Boys of Summer.mp3","trackType":"mp3"} Mar 03 21:28:09 volumiobookworm volumio[6665]: verbose: CURRENT POSITION 0 Mar 03 21:28:09 volumiobookworm volumio[6665]: info: CoreStateMachine::syncState stateService pause Mar 03 21:28:09 volumiobookworm volumio[6665]: info: CoreStateMachine::syncState currentStatus stop Mar 03 21:28:09 volumiobookworm volumio[6665]: info: CoreStateMachine::pushState Mar 03 21:28:09 volumiobookworm volumio[6665]: info: CorePlayQueue::getTrack 0 Mar 03 21:28:09 volumiobookworm volumio[6665]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 03 21:28:09 volumiobookworm volumio[6665]: info: CoreCommandRouter::volumioPushState Mar 03 21:28:09 volumiobookworm volumio[6665]: info: ControllerMpd::pushState Mar 03 21:28:09 volumiobookworm volumio[6665]: info: CoreCommandRouter::servicePushState Mar 03 21:28:09 volumiobookworm volumio[6665]: info: CorePlayQueue::getTrack 0 Mar 03 21:28:09 volumiobookworm volumio[6665]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":242,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"The Boys of Summer","artist":"The Ataris","album":null,"uri":"INTERNAL/The Ataris - The Boys of Summer.mp3","trackType":"mp3"} Mar 03 21:28:09 volumiobookworm volumio[6665]: verbose: CURRENT POSITION 0 Mar 03 21:28:09 volumiobookworm volumio[6665]: info: CoreStateMachine::syncState stateService pause Mar 03 21:28:09 volumiobookworm volumio[6665]: info: CoreStateMachine::syncState currentStatus stop Mar 03 21:28:09 volumiobookworm volumio[6665]: info: CoreStateMachine::pushState Mar 03 21:28:09 volumiobookworm volumio[6665]: info: CorePlayQueue::getTrack 0 Mar 03 21:28:09 volumiobookworm volumio[6665]: info: CoreCommandRouter::volumioPushState Mar 03 21:28:09 volumiobookworm volumio[6665]: info: ControllerMpd::pushState Mar 03 21:28:09 volumiobookworm volumio[6665]: info: CoreCommandRouter::servicePushState Mar 03 21:28:09 volumiobookworm volumio[6665]: info: CorePlayQueue::getTrack 0 Mar 03 21:28:09 volumiobookworm volumio[6665]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":0,"duration":242,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"The Boys of Summer","artist":"The Ataris","album":null,"uri":"INTERNAL/The Ataris - The Boys of Summer.mp3","trackType":"mp3"} Mar 03 21:28:09 volumiobookworm volumio[6665]: verbose: CURRENT POSITION 0 Mar 03 21:28:09 volumiobookworm volumio[6665]: info: CoreStateMachine::syncState stateService pause Mar 03 21:28:09 volumiobookworm volumio[6665]: info: CoreStateMachine::syncState currentStatus stop Mar 03 21:28:09 volumiobookworm volumio[6665]: info: CoreStateMachine::pushState Mar 03 21:28:09 volumiobookworm volumio[6665]: info: CorePlayQueue::getTrack 0 Mar 03 21:28:09 volumiobookworm volumio[6665]: info: CoreCommandRouter::volumioPushState Mar 03 21:28:09 volumiobookworm volumio[6665]: info: ------------------------------ 13ms Mar 03 21:28:09 volumiobookworm volumio[6665]: info: ------------------------------ 13ms Mar 03 21:28:09 volumiobookworm volumio[6665]: info: ------------------------------ 12ms Mar 03 21:28:09 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] on:pushState: undefined - stop Mar 03 21:28:09 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] on:pushState: undefined - stop Mar 03 21:28:09 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] on:pushState: undefined - stop Mar 03 21:28:19 volumiobookworm volumio[6665]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Mar 03 21:28:19 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] initVolumeSettings: getAlsaCards "0" Mar 03 21:28:19 volumiobookworm volumio[6665]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getAlsaCards Mar 03 21:28:19 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] initVolumeSettings: getAlsaCards [{"id":"0","alsacard":"sndrpihifiberry","name":"Hifiberry DAC"},{"id":"1","alsacard":"vc4hdmi0","name":"HDMI 0 Out"},{"id":"2","alsacard":"vc4hdmi1","name":"HDMI 1 Out"}] Mar 03 21:28:19 volumiobookworm volumio[6665]: info: CoreCommandRouter::volumioUpdateVolumeSettings Mar 03 21:28:19 volumiobookworm volumio[6665]: info: Updating Volume Controller Parameters: Device: 0 Name: Hifiberry DAC Mixer: Max Vol: 30 Vol Curve; Vol Steps: 1 Mar 03 21:28:19 volumiobookworm volumio[6665]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Mar 03 21:28:19 volumiobookworm volumio[6665]: info: Enabling external Volume Control Mar 03 21:28:19 volumiobookworm volumio[6665]: info: CoreCommandRouter::executeOnPlugin: serialampcontroller , updateVolumeSettings Mar 03 21:28:19 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] updateVolumeSettings: received {"pluginType":"system_hardware","pluginName":"serialampcontroller","volumeOverride":true,"device":"0","name":"Hifiberry DAC","alsacard":"sndrpihifiberry","devicename":"Rotel - A12","mixer":"","mixertype":"None","maxvolume":30,"volumecurve":"","volumesteps":1} Mar 03 21:28:19 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] retrieveVolume: Mar 03 21:28:19 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] getVolumeObject: {"mute":false,"disableVolumeControl":false,"vol":25} Mar 03 21:28:19 volumiobookworm volumio[6665]: info: CoreCommandRouter::executeOnPlugin: serialampcontroller , retrievevolume Mar 03 21:28:19 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] retrieveVolume: Mar 03 21:28:19 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] getVolumeObject: {"mute":false,"disableVolumeControl":false,"vol":25} Mar 03 21:28:19 volumiobookworm volumio[6665]: info: CoreStateMachine::pushState Mar 03 21:28:19 volumiobookworm volumio[6665]: info: CorePlayQueue::getTrack 0 Mar 03 21:28:19 volumiobookworm volumio[6665]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 03 21:28:19 volumiobookworm volumio[6665]: info: CoreCommandRouter::volumioPushState Mar 03 21:28:19 volumiobookworm volumio[6665]: info: CoreStateMachine::pushState Mar 03 21:28:19 volumiobookworm volumio[6665]: info: CorePlayQueue::getTrack 0 Mar 03 21:28:19 volumiobookworm volumio[6665]: info: CoreCommandRouter::volumioPushState Mar 03 21:28:19 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] on:pushState: undefined - stop Mar 03 21:28:19 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] on:pushState: undefined - stop Mar 03 21:28:46 volumiobookworm volumio[6665]: info: CALLMETHOD: system_hardware serialampcontroller updateAmpType [object Object] Mar 03 21:28:46 volumiobookworm volumio[6665]: info: CoreCommandRouter::executeOnPlugin: serialampcontroller , updateAmpType Mar 03 21:28:46 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] updateAmpType: Saving Amplifier Settings:{"amp_type":{"value":2,"label":"Rotel - A12"}} Mar 03 21:28:46 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] setActiveAmp: {"vendor":"Rotel","model":"A12","baudRate":115200,"parity":"none","dataBits":8,"stopBits":1,"rtscts":false,"xon":false,"xoff":false,"xany":false,"sources":["CD","Coax1","Coax2","Opt1","Opt2","Aux1","Aux2","Tuner","Phono","USB","Bluetooth","PC-USB"],"sourceCmd":["cd!","coax1!","coax2!","opt1!","opt2!","aux1!","aux2!","tuner!","phono!","usb!","bluetooth!","pcusb!"],"sourceRespPostfix":["cd","coax1","coax2","opt1","opt2","aux1","aux2","tuner","phono","usb","bluetooth","pc_usb"],"delimiter":"$","commands":{"powerOn":"power_on!","powerToggle":"power_toggle!","volUp":"vol_up!","volDown":"vol_dwn!","volValue":"vol_##!","mute":"mute!","muteOn":"mute_on!","muteOff":"mute_off!"},"responses":[{"rx":"power=on","cmd":["respPowerOn"]},{"rx":"power=standby","cmd":["respPowerOff"]},{"rx":"volume=([0-9]{2})","cmd":["respVolume"]},{"rx":"mute=on","cmd":["respMuteOn"]},{"rx":"mute=off","cmd":["respMuteOff"]},{"rx":"source=([a-z_12]*)","cmd":["respSource"]}],"statusRequests":{"reqPower":"power?","reqSource":"source?","reqVolume":"volume?","reqMute":"mute?","reqModel":"model?"}} Mar 03 21:28:46 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] setActiveAmp: can send these responses: respPowerOn,respPowerOff,respVolume,respMuteOn,respMuteOff,respSource Mar 03 21:28:46 volumiobookworm volumio[6665]: info: CoreCommandRouter::getUIConfigOnPlugin Mar 03 21:28:46 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] getUIConfig: interface: RS232; amps: ["Anthem - IDMSTR IA","Rotel - A12","Rotel - A14","Rotel - A11","Rotel - RC-1570","Rotel - RC-1592 >=V1.53","Rotel - RSP-1582 SW V5.xx","Rotel - RA-1592 SW >=V1.52","Meridian - DSP420","Cambridge - CXA61"]selected: Rotel - A12 Mar 03 21:28:46 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] closePorts: closing RS232 Mar 03 21:28:46 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] selectedInterfaceExists: usb-Prolific_Technology_Inc._USB-Serial_Controller_D-if00-port0 in [{"path":"/dev/ttyUSB0","manufacturer":"Prolific Technology Inc. ","pnpId":"usb-Prolific_Technology_Inc._USB-Serial_Controller_D-if00-port0","vendorId":"067b","productId":"2303"}]?: true Mar 03 21:28:46 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] selectedAmpSupportsInterface: RS232 in [] Mar 03 21:28:46 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] openSerialPort: starting Mar 03 21:28:46 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] openSerialPort: check for usb-Prolific_Technology_Inc._USB-Serial_Controller_D-if00-port0 in [{"path":"/dev/ttyUSB0","manufacturer":"Prolific Technology Inc. ","pnpId":"usb-Prolific_Technology_Inc._USB-Serial_Controller_D-if00-port0","vendorId":"067b","productId":"2303"}] Mar 03 21:28:46 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] openSerialPort: connect to [{"path":"/dev/ttyUSB0","manufacturer":"Prolific Technology Inc. ","pnpId":"usb-Prolific_Technology_Inc._USB-Serial_Controller_D-if00-port0","vendorId":"067b","productId":"2303"}] configured with: {"autoOpen":false,"lock":false,"endOnClose":true,"baudRate":115200,"dataBits":8,"stopBits":1,"parity":"none","rtscts":false,"xon":false,"xoff":false,"xany":false} at /dev/ttyUSB0 Mar 03 21:28:46 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] openSerialPort: Now trying to open port Mar 03 21:28:46 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] getI18nString("TOAST_SAVE_SUCCESS"):Speichern erfolgreich Mar 03 21:28:46 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] getI18nString("TOAST_AMP_TYPE_SAVE"):Verstärker Typ Mar 03 21:28:46 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] closePorts: closed serial port Mar 03 21:28:46 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] closePorts: remaining config: {"_readableState":{"objectMode":false,"highWaterMark":65536,"buffer":{"head":null,"tail":null,"length":0},"length":0,"pipes":[],"flowing":null,"ended":false,"endEmitted":false,"reading":false,"constructed":true,"sync":true,"needReadable":false,"emittedReadable":false,"readableListening":false,"resumeScheduled":false,"errorEmitted":false,"emitClose":true,"autoDestroy":true,"destroyed":false,"errored":null,"closed":false,"closeEmitted":false,"defaultEncoding":"utf8","awaitDrainWriters":null,"multiAwaitDrain":false,"readingMore":false,"dataEmitted":false,"decoder":null,"encoding":null},"_events":{},"_eventsCount":3,"_writableState":{"objectMode":false,"highWaterMark":65536,"finalCalled":false,"needDrain":false,"ending":false,"ended":false,"finished":false,"destroyed":false,"decodeStrings":true,"defaultEncoding":"utf8","length":0,"writing":false,"corked":0,"sync":true,"bufferProcessing":false,"writecb":null,"writelen":0,"afterWriteTickInfo":null,"buffered":[],"bufferedIndex":0,"allBuffers":true,"allNoop":true,"pendingcb":0,"constructed":true,"prefinished":false,"errorEmitted":false,"emitClose":true,"autoDestroy":true,"errored":null,"closed":false,"closeEmitted":false},"allowHalfOpen":true,"_kMinPoolSpace":128,"opening":true,"closing":false,"settings":{"autoOpen":false,"endOnClose":true,"highWaterMark":65536,"binding":{"fd":27},"lock":false,"baudRate":115200,"dataBits":8,"stopBits":1,"parity":"none","rtscts":false,"xon":false,"xoff":false,"xany":false,"path":"/dev/ttyUSB0"}} Mar 03 21:28:46 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] serial port [event:close]: Port is now closed. Mar 03 21:28:46 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] attachParser: Port is now open. Connecting Parser with delimiter: $ Mar 03 21:28:46 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] getAmpStatus: sending status requests to Amp Mar 03 21:28:46 volumiobookworm volumio[6665]: info: [SERIALAMPCONTROLLER] openSerialPort: Connection established. Mar 03 21:28:46 volumiobookworm volumio[6665]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 03 21:28:46 volumiobookworm volumio[6665]: ReferenceError: error is not defined Mar 03 21:28:46 volumiobookworm volumio[6665]: at /data/plugins/system_hardware/serialampcontroller/index.js:1048:117 Mar 03 21:28:46 volumiobookworm volumio[6665]: at process.processTicksAndRejections (node:internal/process/task_queues:81:21) Mar 03 21:28:46 volumiobookworm volumio[6665]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 03 21:28:46 volumiobookworm sudo[7189]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2025-03-03 21:27' Mar 03 21:28:46 volumiobookworm sudo[7189]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000) PRETTY_NAME="Raspbian GNU/Linux 12 (bookworm)" NAME="Raspbian GNU/Linux" VERSION_ID="12" VERSION="12 (bookworm)" VERSION_CODENAME=bookworm ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="6a71b1b8f832c66e3bde56982bbc4fb0dcc139a1" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="572bccfe6facd2cbc0b66d419c4ed66a3b0126c1" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Sat Oct 19 20:30:59 UTC 2024" VOLUMIO_VERSION="0.012" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="68e75b944cee4d40104b64931fbc3e36"