-- Logs begin at Thu 2019-02-14 11:11:59 CET, end at Sun 2024-11-24 02:55:44 CET. -- Nov 24 02:54:00 volumio70 volumio[1019]: info: getStreamUrl took 641 milliseconds Nov 24 02:54:00 volumio70 volumio[1019]: STREAMING PROXY: Got real url: http://streaming-qobuz-std.akamaized.net:80/file?uid=1139355&eid=195085173&fmt=7&profile=raw&app_id=539451548&cid=1457119&etsp=1732416840&hmac=PAG6Wz_QJ-CZCCEVdF09rQ7PvKE Nov 24 02:54:00 volumio70 volumio[1019]: STREAMING PROXY: Response: 200, length: 38622507 Nov 24 02:54:03 volumio70 volumio[1019]: info: CoreStateMachine::startPlaybackTimer Nov 24 02:54:03 volumio70 volumio[1019]: info: CorePlayQueue::getTrack 26 Nov 24 02:54:04 volumio70 volumio[1019]: info: CoreStateMachine::pushState Nov 24 02:54:04 volumio70 volumio[1019]: info: CorePlayQueue::getTrack 26 Nov 24 02:54:04 volumio70 volumio[1019]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 24 02:54:04 volumio70 volumio[1019]: info: CoreCommandRouter::volumioPushState Nov 24 02:54:04 volumio70 volumio[1019]: info: MRS: Pushing multiroomSync output update for this device Nov 24 02:54:04 volumio70 volumio[1019]: info: MRS: Pushing multiroomSync output Nov 24 02:54:04 volumio70 volumio[1019]: info: Nov 24 02:54:04 volumio70 volumio[1019]: ---------------------------- MPD announces system playlist update Nov 24 02:54:04 volumio70 volumio[1019]: info: Ignoring MPD Status Update Nov 24 02:54:04 volumio70 volumio[1019]: info: Nov 24 02:54:04 volumio70 volumio[1019]: ---------------------------- MPD announces state update: player Nov 24 02:54:04 volumio70 volumio[1019]: info: ControllerMpd::getState Nov 24 02:54:04 volumio70 volumio[1019]: verbose: ControllerMpd::sendMpdCommand status Nov 24 02:54:04 volumio70 volumio[1019]: info: ------------------------------ 2ms Nov 24 02:54:04 volumio70 volumio[1019]: info: sendMpdCommand status took 1 milliseconds Nov 24 02:54:04 volumio70 volumio[1019]: verbose: ControllerMpd::parseState Nov 24 02:54:04 volumio70 volumio[1019]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 24 02:54:04 volumio70 volumio[1019]: info: sendMpdCommand playlistinfo took 0 milliseconds Nov 24 02:54:04 volumio70 volumio[1019]: verbose: ControllerMpd::parseTrackInfo Nov 24 02:54:04 volumio70 volumio[1019]: info: ControllerMpd::pushState Nov 24 02:54:04 volumio70 volumio[1019]: info: CoreCommandRouter::servicePushState Nov 24 02:54:04 volumio70 volumio[1019]: info: CorePlayQueue::getTrack 26 Nov 24 02:54:04 volumio70 volumio[1019]: verbose: STATE SERVICE {"status":"play","position":0,"seek":34,"duration":225,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1128 Kbps","isStreaming":false,"title":"195085173","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/195085173","trackType":"qobuz"} Nov 24 02:54:04 volumio70 volumio[1019]: verbose: CURRENT POSITION 26 Nov 24 02:54:04 volumio70 volumio[1019]: info: CoreStateMachine::syncState stateService play Nov 24 02:54:04 volumio70 volumio[1019]: info: CoreStateMachine::syncState currentStatus play Nov 24 02:54:04 volumio70 volumio[1019]: info: Received an update from plugin. extracting info from payload Nov 24 02:54:04 volumio70 volumio[1019]: info: CoreStateMachine::pushState Nov 24 02:54:04 volumio70 volumio[1019]: info: CorePlayQueue::getTrack 26 Nov 24 02:54:04 volumio70 volumio[1019]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 24 02:54:04 volumio70 volumio[1019]: info: CoreCommandRouter::volumioPushState Nov 24 02:54:04 volumio70 volumio[1019]: info: MRS: Pushing multiroomSync output update for this device Nov 24 02:54:04 volumio70 volumio[1019]: info: MRS: Pushing multiroomSync output Nov 24 02:54:04 volumio70 volumio[1019]: info: CoreStateMachine::pushState Nov 24 02:54:04 volumio70 volumio[1019]: info: CorePlayQueue::getTrack 26 Nov 24 02:54:04 volumio70 volumio[1019]: info: CoreCommandRouter::volumioPushState Nov 24 02:54:04 volumio70 volumio[1019]: info: MRS: Pushing multiroomSync output update for this device Nov 24 02:54:04 volumio70 volumio[1019]: info: MRS: Pushing multiroomSync output Nov 24 02:54:04 volumio70 volumio[1019]: info: ------------------------------ 15ms Nov 24 02:54:15 volumio70 volumio[1019]: STREAMING PROXY: Client dropped request, destroying Nov 24 02:54:38 volumio70 volumio[1019]: info: Tunnel connection is inactive, restarting it Nov 24 02:54:38 volumio70 volumio[1019]: info: Starting Tunnel 1 Nov 24 02:54:38 volumio70 volumio[1019]: info: Starting Tunnel Connection Checker Nov 24 02:54:39 volumio70 sudo[2643]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart sshtunnel.service Nov 24 02:54:39 volumio70 sudo[2643]: pam_unix(sudo:session): session opened for user root by (uid=0) Nov 24 02:54:39 volumio70 autossh[2187]: received signal to exit (15) Nov 24 02:54:39 volumio70 systemd[1]: Stopping MyVolumio SSH Tunnel... Nov 24 02:54:39 volumio70 systemd[1]: sshtunnel.service: Main process exited, code=killed, status=15/TERM Nov 24 02:54:39 volumio70 volumio[1019]: ------------------------------------ BT MESSAGE: BT STATUS: running Nov 24 02:54:39 volumio70 systemd[1]: sshtunnel.service: Succeeded. Nov 24 02:54:39 volumio70 systemd[1]: Stopped MyVolumio SSH Tunnel. Nov 24 02:54:39 volumio70 volumio[1019]: ------------------------------------ BT MESSAGE: BT STATUS: waiting Nov 24 02:54:39 volumio70 systemd[1]: Started MyVolumio SSH Tunnel. Nov 24 02:54:39 volumio70 sudo[2643]: pam_unix(sudo:session): session closed for user root Nov 24 02:54:39 volumio70 volumio[1019]: info: Remote SSH Started Nov 24 02:54:39 volumio70 autossh[2647]: port set to 0, monitoring disabled Nov 24 02:54:39 volumio70 autossh[2647]: starting ssh (count 1) Nov 24 02:54:39 volumio70 autossh[2647]: ssh child pid is 2650 Nov 24 02:54:39 volumio70 volumio[1019]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 Nov 24 02:54:39 volumio70 volumio[1019]: info: CoreCommandRouter::volumioGetState Nov 24 02:54:39 volumio70 volumio[1019]: info: CorePlayQueue::getTrack 26 Nov 24 02:55:10 volumio70 volumiossh-tunnel[2645]: Warning: Permanently added '[eu4.myvolumio.org]:2222,[167.172.103.77]:2222' (RSA) to the list of known hosts. Nov 24 02:55:25 volumio70 volumio[1019]: info: CoreCommandRouter::volumioPause Nov 24 02:55:25 volumio70 volumio[1019]: info: CoreStateMachine::pause Nov 24 02:55:25 volumio70 volumio[1019]: info: CoreStateMachine::stPlaybackTimer Nov 24 02:55:25 volumio70 volumio[1019]: info: CoreStateMachine::servicePause Nov 24 02:55:25 volumio70 volumio[1019]: info: CorePlayQueue::getTrack 26 Nov 24 02:55:25 volumio70 volumio[1019]: info: CoreCommandRouter::servicePause Nov 24 02:55:25 volumio70 volumio[1019]: info: [1732413325614] ControllerQobuz::pause Nov 24 02:55:25 volumio70 volumio[1019]: info: CoreStateMachine::setConsumeUpdateService mpd Nov 24 02:55:25 volumio70 volumio[1019]: info: ControllerMpd::pause Nov 24 02:55:25 volumio70 volumio[1019]: verbose: ControllerMpd::sendMpdCommand pause Nov 24 02:55:25 volumio70 volumio[1019]: info: Nov 24 02:55:25 volumio70 volumio[1019]: ---------------------------- MPD announces state update: player Nov 24 02:55:25 volumio70 volumio[1019]: info: sendMpdCommand pause took 1 milliseconds Nov 24 02:55:25 volumio70 volumio[1019]: info: ControllerMpd::getState Nov 24 02:55:25 volumio70 volumio[1019]: verbose: ControllerMpd::sendMpdCommand status Nov 24 02:55:25 volumio70 volumio[1019]: info: sendMpdCommand status took 0 milliseconds Nov 24 02:55:25 volumio70 volumio[1019]: verbose: ControllerMpd::parseState Nov 24 02:55:25 volumio70 volumio[1019]: verbose: ControllerMpd::sendMpdCommand playlistinfo Nov 24 02:55:25 volumio70 volumio[1019]: info: sendMpdCommand playlistinfo took 0 milliseconds Nov 24 02:55:25 volumio70 volumio[1019]: verbose: ControllerMpd::parseTrackInfo Nov 24 02:55:25 volumio70 volumio[1019]: info: ControllerMpd::pushState Nov 24 02:55:25 volumio70 volumio[1019]: info: CoreCommandRouter::servicePushState Nov 24 02:55:25 volumio70 volumio[1019]: info: CorePlayQueue::getTrack 26 Nov 24 02:55:25 volumio70 volumio[1019]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":80777,"duration":225,"samplerate":"44.1 kHz","bitdepth":"24 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1472 Kbps","isStreaming":false,"title":"195085173","artist":null,"album":null,"uri":"http://127.0.0.1:3245?data=qobuz://song/195085173","trackType":"qobuz"} Nov 24 02:55:25 volumio70 volumio[1019]: verbose: CURRENT POSITION 26 Nov 24 02:55:25 volumio70 volumio[1019]: info: CoreStateMachine::syncState stateService pause Nov 24 02:55:25 volumio70 volumio[1019]: info: CoreStateMachine::syncState currentStatus pause Nov 24 02:55:25 volumio70 volumio[1019]: info: CoreStateMachine::pushState Nov 24 02:55:25 volumio70 volumio[1019]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Nov 24 02:55:25 volumio70 volumio[1019]: info: CoreCommandRouter::volumioPushState Nov 24 02:55:25 volumio70 volumio[1019]: info: MRS: Pushing multiroomSync output update for this device Nov 24 02:55:25 volumio70 volumio[1019]: info: MRS: Pushing multiroomSync output Nov 24 02:55:25 volumio70 volumio[1019]: info: CoreStateMachine::stPlaybackTimer Nov 24 02:55:25 volumio70 volumio[1019]: info: ------------------------------ 14ms Nov 24 02:55:25 volumio70 volumio[1019]: info: touch_display: Setting screensaver timeout to 120 seconds. Nov 24 02:55:32 volumio70 volumio[1019]: info: CoreCommandRouter::getUIConfigOnPlugin Nov 24 02:55:32 volumio70 volumio[1019]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Nov 24 02:55:32 volumio70 volumio[1019]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Nov 24 02:55:32 volumio70 volumio[1019]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Nov 24 02:55:32 volumio70 volumio[1019]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 24 02:55:32 volumio70 volumio[1019]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 24 02:55:32 volumio70 volumio[1019]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 24 02:55:32 volumio70 volumio[1019]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 24 02:55:32 volumio70 volumio[1019]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 24 02:55:32 volumio70 volumio[1019]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 24 02:55:32 volumio70 volumio[1019]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Nov 24 02:55:32 volumio70 volumio[1019]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Nov 24 02:55:32 volumio70 volumio[1019]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Nov 24 02:55:44 volumio70 volumio[1019]: info: ___________ PLUGINS: Run Shutdown Tasks ___________ Nov 24 02:55:44 volumio70 volumio[1019]: info: PLUGIN onShutdown : networkfs Nov 24 02:55:44 volumio70 volumio[1019]: info: PLUGIN onShutdown : audiophonicsonoff Nov 24 02:55:44 volumio70 volumio[1019]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 24 02:55:44 volumio70 volumio[1019]: TypeError: Cannot read property 'writeSync' of undefined Nov 24 02:55:44 volumio70 volumio[1019]: at ControllerAudiophonicsOnOff.onVolumioShutdown (/data/plugins/system_controller/audiophonicsonoff/index.js:43:25) Nov 24 02:55:44 volumio70 volumio[1019]: at PluginManager.onVolumioShutdownPlugin (/volumio/app/pluginmanager.js:638:30) Nov 24 02:55:44 volumio70 volumio[1019]: at HashMap. (/volumio/app/pluginmanager.js:621:31) Nov 24 02:55:44 volumio70 volumio[1019]: at HashMap.forEach (/volumio/node_modules/hashmap/hashmap.js:171:10) Nov 24 02:55:44 volumio70 volumio[1019]: at HashMap.proto. [as forEach] (/volumio/node_modules/hashmap/hashmap.js:201:7) Nov 24 02:55:44 volumio70 volumio[1019]: at PluginManager.onVolumioShutdown (/volumio/app/pluginmanager.js:619:20) Nov 24 02:55:44 volumio70 volumio[1019]: at CoreCommandRouter.shutdown (/volumio/app/index.js:1333:24) Nov 24 02:55:44 volumio70 volumio[1019]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:859:33) Nov 24 02:55:44 volumio70 volumio[1019]: at Socket.emit (events.js:315:20) Nov 24 02:55:44 volumio70 volumio[1019]: at /volumio/node_modules/socket.io/lib/socket.js:528:12 Nov 24 02:55:44 volumio70 volumio[1019]: at processTicksAndRejections (internal/process/task_queues.js:75:11) Nov 24 02:55:44 volumio70 volumio[1019]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Nov 24 02:55:44 volumio70 sudo[2833]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-11-24 02:54 Nov 24 02:55:44 volumio70 sudo[2833]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="70bcab5180cf11352f5a5197ade215ea8ee93db0" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="678d37490b3eb2102ce7c6d7a6dc3cf042ff2347" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Fri 08 Nov 2024 06:51:56 PM CET" VOLUMIO_VERSION="3.779" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="b9009e0280f50389e80a537357ff3961"