-- Logs begin at Sat 2024-10-19 08:26:52 CST, end at Sat 2024-10-19 09:46:18 CST. -- Oct 19 09:45:01 volumio volumio[1149]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: python-requests/2.21.0 Engine version: 3 Transport: polling Total Clients: 7 Oct 19 09:45:01 volumio volumio[1149]: info: CoreCommandRouter::volumioGetState Oct 19 09:45:06 volumio volumio[1149]: error: MyVolumio got a network error: A network error (such as timeout, interrupted connection or unreachable host) has occurred. Oct 19 09:45:06 volumio volumio[1149]: info: Retrying Login Due to Network Error Oct 19 09:45:16 volumio volumio[1149]: info: MyVolumio login type: Token Oct 19 09:45:46 volumio volumio[1149]: error: MyVolumio got a network error: A network error (such as timeout, interrupted connection or unreachable host) has occurred. Oct 19 09:45:46 volumio volumio[1149]: info: Retrying Login Due to Network Error Oct 19 09:45:56 volumio volumio[1149]: info: MyVolumio login type: Token Oct 19 09:46:15 volumio kernel: usb 1-4: USB disconnect, device number 2 Oct 19 09:46:15 volumio thd[678]: Error reading device '/dev/input/event2' Oct 19 09:46:15 volumio volumio[1149]: info: No valid Plugin REST Endpoint Oct 19 09:46:15 volumio volumio[1149]: info: Oct 19 09:46:15 volumio volumio[1149]: ---------------------------- USB Audio Device Detached Oct 19 09:46:15 volumio volumio[1149]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , usbAudioDetach Oct 19 09:46:15 volumio volumio[1149]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Oct 19 09:46:15 volumio volumio[1149]: info: CoreCommandRouter::executeOnPlugin: raat , onStop Oct 19 09:46:16 volumio kernel: usb 1-4: new full-speed USB device number 3 using ohci-pci Oct 19 09:46:16 volumio kernel: usb 1-4: New USB device found, idVendor=0d8c, idProduct=013c, bcdDevice= 1.00 Oct 19 09:46:16 volumio kernel: usb 1-4: New USB device strings: Mfr=1, Product=2, SerialNumber=0 Oct 19 09:46:16 volumio kernel: usb 1-4: Product: USB PnP Sound Device Oct 19 09:46:16 volumio kernel: usb 1-4: Manufacturer: C-Media Electronics Inc. Oct 19 09:46:16 volumio kernel: input: C-Media Electronics Inc. USB PnP Sound Device as /devices/pci0000:00/0000:00:12.0/usb1/1-4/1-4:1.3/0003:0D8C:013C.0007/input/input31 Oct 19 09:46:16 volumio kernel: hid-generic 0003:0D8C:013C.0007: input,hidraw0: USB HID v1.00 Device [C-Media Electronics Inc. USB PnP Sound Device] on usb-0000:00:12.0-4/input3 Oct 19 09:46:16 volumio volumio[1149]: info: Oct 19 09:46:16 volumio volumio[1149]: ---------------------------- USB Audio Device Attached Oct 19 09:46:16 volumio volumio[1149]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , usbAudioAttach Oct 19 09:46:16 volumio systemd-udevd[10291]: Process '/usr/sbin/th-cmd --socket /var/run/thd.socket --passfd --udev' failed with exit code 1. Oct 19 09:46:16 volumio volumio[1149]: info: CoreCommandRouter::Close All Modals sent Oct 19 09:46:16 volumio volumio[1149]: info: Preparing to save Alsa Options, stopping services first Oct 19 09:46:16 volumio volumio[1149]: info: CoreCommandRouter::volumioGetState Oct 19 09:46:16 volumio volumio[1149]: info: CoreCommandRouter::volumioPause Oct 19 09:46:16 volumio volumio[1149]: info: CoreStateMachine::pause Oct 19 09:46:16 volumio volumio[1149]: info: CoreStateMachine::stPlaybackTimer Oct 19 09:46:16 volumio volumio[1149]: info: CoreStateMachine::servicePause Oct 19 09:46:16 volumio volumio[1149]: info: CorePlayQueue::getTrack 3 Oct 19 09:46:16 volumio volumio[1149]: info: CoreCommandRouter::servicePause Oct 19 09:46:16 volumio volumio[1149]: info: [1729302376869] ControllerUPNPBrowser::pause Oct 19 09:46:16 volumio volumio[1149]: verbose: ControllerMpd::sendMpdCommand pause Oct 19 09:46:16 volumio volumio[1149]: info: Saving Audio Output to: {"disallowPush":true,"output_device":{"value":"5","label":"USB PnP Sound Device","alsacard":"Device"},"i2s":false} Oct 19 09:46:16 volumio volumio[1149]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Oct 19 09:46:17 volumio volumio[1149]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Oct 19 09:46:17 volumio volumio[1149]: info: Setting default mixerSoftMaster for Softvolume device Oct 19 09:46:17 volumio volumio[1149]: info: CoreCommandRouter::volumioUpdateVolumeSettings Oct 19 09:46:17 volumio volumio[1149]: info: Updating Volume Controller Parameters: Device: 5 Name: softvolume Mixer: SoftMaster Max Vol: 10 Vol Curve; logarithmic Vol Steps: 1 Oct 19 09:46:17 volumio volumio[1149]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Oct 19 09:46:17 volumio volumio[1149]: info: Disabling external Volume Control Oct 19 09:46:17 volumio volumio[1149]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 19 09:46:17 volumio volumio[1149]: info: Enable softmixer device for audio device undefined Oct 19 09:46:17 volumio volumio[1149]: info: Oct 19 09:46:17 volumio volumio[1149]: ---------------------------- MPD announces state update: player Oct 19 09:46:17 volumio volumio[1149]: info: sendMpdCommand pause took 733 milliseconds Oct 19 09:46:17 volumio volumio[1149]: info: ControllerMpd::getState Oct 19 09:46:17 volumio volumio[1149]: verbose: ControllerMpd::sendMpdCommand status Oct 19 09:46:17 volumio volumio[1149]: info: Oct 19 09:46:17 volumio volumio[1149]: ---------------------------- MPD announces state update: player Oct 19 09:46:17 volumio volumio[1149]: info: ControllerMpd::getState Oct 19 09:46:17 volumio volumio[1149]: verbose: ControllerMpd::sendMpdCommand status Oct 19 09:46:17 volumio volumio[1149]: info: Oct 19 09:46:17 volumio volumio[1149]: ---------------------------- MPD announces state update: player Oct 19 09:46:17 volumio volumio[1149]: info: ControllerMpd::getState Oct 19 09:46:17 volumio volumio[1149]: verbose: ControllerMpd::sendMpdCommand status Oct 19 09:46:17 volumio volumio[1149]: info: Oct 19 09:46:17 volumio volumio[1149]: ---------------------------- MPD announces state update: player Oct 19 09:46:17 volumio volumio[1149]: info: ControllerMpd::getState Oct 19 09:46:17 volumio volumio[1149]: verbose: ControllerMpd::sendMpdCommand status Oct 19 09:46:17 volumio volumio[1149]: info: sendMpdCommand status took 32 milliseconds Oct 19 09:46:17 volumio volumio[1149]: info: sendMpdCommand status took 21 milliseconds Oct 19 09:46:17 volumio volumio[1149]: info: sendMpdCommand status took 19 milliseconds Oct 19 09:46:17 volumio volumio[1149]: info: sendMpdCommand status took 17 milliseconds Oct 19 09:46:17 volumio volumio[1149]: verbose: ControllerMpd::parseState Oct 19 09:46:17 volumio volumio[1149]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 19 09:46:17 volumio volumio[1149]: verbose: ControllerMpd::parseState Oct 19 09:46:17 volumio volumio[1149]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 19 09:46:17 volumio volumio[1149]: verbose: ControllerMpd::parseState Oct 19 09:46:17 volumio volumio[1149]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 19 09:46:17 volumio volumio[1149]: verbose: ControllerMpd::parseState Oct 19 09:46:17 volumio volumio[1149]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 19 09:46:17 volumio volumio[1149]: info: Software Volume ALSA configuration written Oct 19 09:46:17 volumio volumio[1149]: info: Preparing to generate the ALSA configuration file Oct 19 09:46:17 volumio volumio[1149]: info: No valid Plugin REST Endpoint Oct 19 09:46:17 volumio volumio[1149]: info: sendMpdCommand playlistinfo took 95 milliseconds Oct 19 09:46:17 volumio volumio[1149]: verbose: ControllerMpd::parseTrackInfo Oct 19 09:46:17 volumio volumio[1149]: info: ControllerMpd::pushState Oct 19 09:46:17 volumio volumio[1149]: info: CoreCommandRouter::servicePushState Oct 19 09:46:17 volumio volumio[1149]: info: CorePlayQueue::getTrack 3 Oct 19 09:46:17 volumio volumio[1149]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":95657,"duration":199,"samplerate":"96 kHz","bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"499.wav","artist":null,"album":null,"uri":"http://192.168.3.75:8200/MediaItems/499.wav","trackType":"wav"} Oct 19 09:46:17 volumio volumio[1149]: verbose: CURRENT POSITION 3 Oct 19 09:46:17 volumio volumio[1149]: info: CoreStateMachine::syncState stateService pause Oct 19 09:46:17 volumio volumio[1149]: info: CoreStateMachine::syncState currentStatus pause Oct 19 09:46:17 volumio volumio[1149]: info: CoreStateMachine::pushState Oct 19 09:46:17 volumio volumio[1149]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 19 09:46:17 volumio volumio[1149]: info: CoreCommandRouter::volumioPushState Oct 19 09:46:17 volumio volumio[1149]: info: CoreStateMachine::stPlaybackTimer Oct 19 09:46:17 volumio volumio[1149]: info: ControllerMpd::pushState Oct 19 09:46:17 volumio volumio[1149]: info: CoreCommandRouter::servicePushState Oct 19 09:46:17 volumio volumio[1149]: info: CorePlayQueue::getTrack 3 Oct 19 09:46:17 volumio volumio[1149]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":95657,"duration":199,"samplerate":"96 kHz","bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"499.wav","artist":null,"album":null,"uri":"http://192.168.3.75:8200/MediaItems/499.wav","trackType":"wav"} Oct 19 09:46:17 volumio volumio[1149]: verbose: CURRENT POSITION 3 Oct 19 09:46:17 volumio volumio[1149]: info: CoreStateMachine::syncState stateService pause Oct 19 09:46:17 volumio volumio[1149]: info: CoreStateMachine::syncState currentStatus pause Oct 19 09:46:17 volumio volumio[1149]: info: CoreStateMachine::pushState Oct 19 09:46:17 volumio volumio[1149]: info: CoreCommandRouter::volumioPushState Oct 19 09:46:17 volumio volumio[1149]: info: CoreStateMachine::stPlaybackTimer Oct 19 09:46:17 volumio volumio[1149]: info: ControllerMpd::pushState Oct 19 09:46:17 volumio volumio[1149]: info: CoreCommandRouter::servicePushState Oct 19 09:46:17 volumio volumio[1149]: info: CorePlayQueue::getTrack 3 Oct 19 09:46:17 volumio volumio[1149]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":95657,"duration":199,"samplerate":"96 kHz","bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"499.wav","artist":null,"album":null,"uri":"http://192.168.3.75:8200/MediaItems/499.wav","trackType":"wav"} Oct 19 09:46:17 volumio volumio[1149]: verbose: CURRENT POSITION 3 Oct 19 09:46:17 volumio volumio[1149]: info: CoreStateMachine::syncState stateService pause Oct 19 09:46:17 volumio volumio[1149]: info: CoreStateMachine::syncState currentStatus pause Oct 19 09:46:17 volumio volumio[1149]: info: CoreStateMachine::pushState Oct 19 09:46:17 volumio volumio[1149]: info: CoreCommandRouter::volumioPushState Oct 19 09:46:17 volumio volumio[1149]: info: CoreStateMachine::stPlaybackTimer Oct 19 09:46:17 volumio volumio[1149]: info: ControllerMpd::pushState Oct 19 09:46:17 volumio volumio[1149]: info: CoreCommandRouter::servicePushState Oct 19 09:46:17 volumio volumio[1149]: info: CorePlayQueue::getTrack 3 Oct 19 09:46:17 volumio volumio[1149]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":95657,"duration":199,"samplerate":"96 kHz","bitdepth":"32 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"499.wav","artist":null,"album":null,"uri":"http://192.168.3.75:8200/MediaItems/499.wav","trackType":"wav"} Oct 19 09:46:17 volumio volumio[1149]: verbose: CURRENT POSITION 3 Oct 19 09:46:17 volumio volumio[1149]: info: CoreStateMachine::syncState stateService pause Oct 19 09:46:17 volumio volumio[1149]: info: CoreStateMachine::syncState currentStatus pause Oct 19 09:46:17 volumio volumio[1149]: info: CoreStateMachine::pushState Oct 19 09:46:17 volumio volumio[1149]: info: CoreCommandRouter::volumioPushState Oct 19 09:46:17 volumio volumio[1149]: info: CoreStateMachine::stPlaybackTimer Oct 19 09:46:17 volumio volumio[1149]: info: ------------------------------ 269ms Oct 19 09:46:17 volumio volumio[1149]: info: ------------------------------ 267ms Oct 19 09:46:17 volumio volumio[1149]: info: ------------------------------ 262ms Oct 19 09:46:17 volumio volumio[1149]: info: ------------------------------ 262ms Oct 19 09:46:17 volumio volumio[1149]: info: CoreStateMachine::pushState Oct 19 09:46:17 volumio volumio[1149]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 19 09:46:17 volumio volumio[1149]: info: CoreCommandRouter::volumioPushState Oct 19 09:46:18 volumio volumio[1149]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Oct 19 09:46:18 volumio volumio[1149]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 19 09:46:18 volumio volumio[1149]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Oct 19 09:46:18 volumio volumio[1149]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 19 09:46:18 volumio volumio[1149]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 19 09:46:18 volumio volumio[1149]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 19 09:46:18 volumio volumio[1149]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 19 09:46:18 volumio volumio[1149]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 19 09:46:18 volumio volumio[1149]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 19 09:46:18 volumio volumio[1149]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 19 09:46:18 volumio volumio[1149]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Oct 19 09:46:18 volumio volumio[1149]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Oct 19 09:46:18 volumio volumio[1149]: info: The plugin alsa_controller has an ALSA contribution file softvolume.postVolume.conf Oct 19 09:46:18 volumio volumio[1149]: info: The plugin peppy_screensaver has an ALSA contribution file Peppyalsa.postPeppyalsa.5.conf Oct 19 09:46:18 volumio volumio[1149]: info: Reading ALSA contributions from plugins. Oct 19 09:46:18 volumio volumio[1149]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 19 09:46:18 volumio volumio[1149]: Error: ENOTDIR: not a directory, scandir '/tmp/peppyrunning' Oct 19 09:46:18 volumio volumio[1149]: at Object.readdirSync (fs.js:1048:3) Oct 19 09:46:18 volumio volumio[1149]: at rmkidsSync (/data/plugins/user_interface/peppy_screensaver/node_modules/rimraf/rimraf.js:349:11) Oct 19 09:46:18 volumio volumio[1149]: at rmdirSync (/data/plugins/user_interface/peppy_screensaver/node_modules/rimraf/rimraf.js:342:7) Oct 19 09:46:18 volumio volumio[1149]: at Function.rimrafSync [as sync] (/data/plugins/user_interface/peppy_screensaver/node_modules/rimraf/rimraf.js:319:62) Oct 19 09:46:18 volumio volumio[1149]: at Object.removeSync (/data/plugins/user_interface/peppy_screensaver/node_modules/fs-extra/lib/remove/index.js:4:17) Oct 19 09:46:18 volumio volumio[1149]: at Socket. (/data/plugins/user_interface/peppy_screensaver/index.js:225:48) Oct 19 09:46:18 volumio volumio[1149]: at Socket.Emitter.emit (/data/plugins/user_interface/peppy_screensaver/node_modules/component-emitter/index.js:145:20) Oct 19 09:46:18 volumio volumio[1149]: at Socket.onevent (/data/plugins/user_interface/peppy_screensaver/node_modules/socket.io-client/lib/socket.js:278:10) Oct 19 09:46:18 volumio volumio[1149]: at Socket.onpacket (/data/plugins/user_interface/peppy_screensaver/node_modules/socket.io-client/lib/socket.js:236:12) Oct 19 09:46:18 volumio volumio[1149]: at Manager. (/data/plugins/user_interface/peppy_screensaver/node_modules/component-bind/index.js:21:15) Oct 19 09:46:18 volumio volumio[1149]: at Manager.Emitter.emit (/data/plugins/user_interface/peppy_screensaver/node_modules/component-emitter/index.js:145:20) Oct 19 09:46:18 volumio volumio[1149]: at Manager.ondecoded (/data/plugins/user_interface/peppy_screensaver/node_modules/socket.io-client/lib/manager.js:349:8) Oct 19 09:46:18 volumio volumio[1149]: at Decoder. (/data/plugins/user_interface/peppy_screensaver/node_modules/component-bind/index.js:21:15) Oct 19 09:46:18 volumio volumio[1149]: at Decoder.Emitter.emit (/data/plugins/user_interface/peppy_screensaver/node_modules/component-emitter/index.js:145:20) Oct 19 09:46:18 volumio volumio[1149]: at Decoder.add (/data/plugins/user_interface/peppy_screensaver/node_modules/socket.io-parser/index.js:251:12) Oct 19 09:46:18 volumio volumio[1149]: at Manager.ondata (/data/plugins/user_interface/peppy_screensaver/node_modules/socket.io-client/lib/manager.js:339:16) { Oct 19 09:46:18 volumio volumio[1149]: errno: -20, Oct 19 09:46:18 volumio volumio[1149]: syscall: 'scandir', Oct 19 09:46:18 volumio volumio[1149]: code: 'ENOTDIR', Oct 19 09:46:18 volumio volumio[1149]: path: '/tmp/peppyrunning' Oct 19 09:46:18 volumio volumio[1149]: } Oct 19 09:46:18 volumio volumio[1149]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 19 09:46:18 volumio sudo[10367]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-10-19 09:45 Oct 19 09:46:18 volumio sudo[10367]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Debian GNU/Linux 10 (buster)" NAME="Debian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="5fd3886148e72a9cecd88a772d1f6079fb64d11a" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="8bb23b009e91ae4c7ecd678f193e7d3b281fca0c" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Mon 22 Jul 2024 07:48:50 PM CEST" VOLUMIO_VERSION="3.742" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="1049be5fd382035818795b7f5c38e10d"