-- Logs begin at Thu 2019-02-14 11:11:59 CET, end at Fri 2024-10-18 18:44:32 CEST. -- Oct 18 18:43:21 volumioga kernel: usb 1-1.3: USB disconnect, device number 3 Oct 18 18:43:21 volumioga volumio[885]: info: Oct 18 18:43:21 volumioga volumio[885]: ---------------------------- MPD announces state update: player Oct 18 18:43:21 volumioga volumio[885]: info: ControllerMpd::getState Oct 18 18:43:21 volumioga volumio[885]: verbose: ControllerMpd::sendMpdCommand status Oct 18 18:43:21 volumioga volumio[885]: info: Oct 18 18:43:21 volumioga volumio[885]: ---------------------------- MPD announces state update: player Oct 18 18:43:21 volumioga volumio[885]: info: ControllerMpd::getState Oct 18 18:43:21 volumioga volumio[885]: verbose: ControllerMpd::sendMpdCommand status Oct 18 18:43:21 volumioga volumio[885]: info: Oct 18 18:43:21 volumioga volumio[885]: ---------------------------- MPD announces state update: player Oct 18 18:43:21 volumioga volumio[885]: info: ControllerMpd::getState Oct 18 18:43:21 volumioga volumio[885]: verbose: ControllerMpd::sendMpdCommand status Oct 18 18:43:21 volumioga volumio[885]: verbose: ControllerMpd::sendMpdCommand clearerror Oct 18 18:43:21 volumioga volumio[885]: info: sendMpdCommand status took 13 milliseconds Oct 18 18:43:21 volumioga volumio[885]: verbose: ControllerMpd::parseState Oct 18 18:43:21 volumioga volumio[885]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 18 18:43:21 volumioga volumio[885]: verbose: ControllerMpd::sendMpdCommand clearerror Oct 18 18:43:21 volumioga volumio[885]: info: sendMpdCommand status took 20 milliseconds Oct 18 18:43:21 volumioga volumio[885]: verbose: ControllerMpd::sendMpdCommand clearerror Oct 18 18:43:21 volumioga volumio[885]: info: sendMpdCommand status took 21 milliseconds Oct 18 18:43:21 volumioga volumio[885]: info: sendMpdCommand clearerror took 11 milliseconds Oct 18 18:43:21 volumioga volumio[885]: info: sendMpdCommand playlistinfo took 9 milliseconds Oct 18 18:43:21 volumioga volumio[885]: verbose: ControllerMpd::parseState Oct 18 18:43:21 volumioga volumio[885]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 18 18:43:21 volumioga volumio[885]: verbose: ControllerMpd::parseState Oct 18 18:43:21 volumioga volumio[885]: verbose: ControllerMpd::sendMpdCommand playlistinfo Oct 18 18:43:21 volumioga volumio[885]: verbose: ControllerMpd::parseTrackInfo Oct 18 18:43:21 volumioga volumio[885]: info: ControllerMpd::pushState Oct 18 18:43:21 volumioga volumio[885]: info: CoreCommandRouter::servicePushState Oct 18 18:43:21 volumioga volumio[885]: verbose: In UPNP mode Oct 18 18:43:21 volumioga volumio[885]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":120187,"duration":262,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"945 Kbps","isStreaming":false,"title":"Beautiful Stranger","artist":"Madonna","album":"Austin Powers: The Spy Who Shagged Me Soundtrack","uri":"http://192.168.1.5:10401/tidal/10915899.flac","trackType":"tidal"} Oct 18 18:43:21 volumioga volumio[885]: verbose: CURRENT POSITION 0 Oct 18 18:43:21 volumioga volumio[885]: info: CoreStateMachine::syncState stateService pause Oct 18 18:43:21 volumioga volumio[885]: info: CoreStateMachine::syncState currentStatus play Oct 18 18:43:21 volumioga volumio[885]: info: CoreStateMachine::pushState Oct 18 18:43:21 volumioga volumio[885]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 18 18:43:21 volumioga volumio[885]: info: CoreCommandRouter::volumioPushState Oct 18 18:43:21 volumioga volumio[885]: info: CoreStateMachine::stPlaybackTimer Oct 18 18:43:21 volumioga volumio[885]: info: ------------------------------ 49ms Oct 18 18:43:21 volumioga volumio[885]: info: CoreCommandRouter::volumioGetQueue Oct 18 18:43:21 volumioga volumio[885]: info: CoreStateMachine::getQueue Oct 18 18:43:21 volumioga volumio[885]: info: CorePlayQueue::getQueue Oct 18 18:43:21 volumioga volumio[885]: info: sendMpdCommand clearerror took 46 milliseconds Oct 18 18:43:21 volumioga volumio[885]: info: sendMpdCommand clearerror took 44 milliseconds Oct 18 18:43:21 volumioga volumio[885]: info: sendMpdCommand playlistinfo took 38 milliseconds Oct 18 18:43:21 volumioga volumio[885]: info: sendMpdCommand playlistinfo took 37 milliseconds Oct 18 18:43:21 volumioga volumio[885]: verbose: ControllerMpd::parseTrackInfo Oct 18 18:43:21 volumioga volumio[885]: verbose: ControllerMpd::parseTrackInfo Oct 18 18:43:21 volumioga volumio[885]: info: ControllerMpd::pushState Oct 18 18:43:21 volumioga volumio[885]: info: CoreCommandRouter::servicePushState Oct 18 18:43:21 volumioga volumio[885]: verbose: In UPNP mode Oct 18 18:43:21 volumioga volumio[885]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":120187,"duration":262,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"945 Kbps","isStreaming":false,"title":"Beautiful Stranger","artist":"Madonna","album":"Austin Powers: The Spy Who Shagged Me Soundtrack","uri":"http://192.168.1.5:10401/tidal/10915899.flac","trackType":"tidal"} Oct 18 18:43:21 volumioga volumio[885]: verbose: CURRENT POSITION 0 Oct 18 18:43:21 volumioga volumio[885]: info: CoreStateMachine::syncState stateService pause Oct 18 18:43:21 volumioga volumio[885]: info: CoreStateMachine::syncState currentStatus play Oct 18 18:43:21 volumioga volumio[885]: info: CoreStateMachine::pushState Oct 18 18:43:21 volumioga volumio[885]: info: CoreCommandRouter::volumioPushState Oct 18 18:43:21 volumioga volumio[885]: info: CoreStateMachine::stPlaybackTimer Oct 18 18:43:21 volumioga volumio[885]: info: ControllerMpd::pushState Oct 18 18:43:21 volumioga volumio[885]: info: CoreCommandRouter::servicePushState Oct 18 18:43:21 volumioga volumio[885]: verbose: In UPNP mode Oct 18 18:43:21 volumioga volumio[885]: verbose: STATE SERVICE {"status":"pause","position":0,"seek":120187,"duration":262,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"945 Kbps","isStreaming":false,"title":"Beautiful Stranger","artist":"Madonna","album":"Austin Powers: The Spy Who Shagged Me Soundtrack","uri":"http://192.168.1.5:10401/tidal/10915899.flac","trackType":"tidal"} Oct 18 18:43:21 volumioga volumio[885]: verbose: CURRENT POSITION 0 Oct 18 18:43:21 volumioga volumio[885]: info: CoreStateMachine::syncState stateService pause Oct 18 18:43:21 volumioga volumio[885]: info: CoreStateMachine::syncState currentStatus play Oct 18 18:43:21 volumioga volumio[885]: info: CoreStateMachine::pushState Oct 18 18:43:21 volumioga volumio[885]: info: CoreCommandRouter::volumioPushState Oct 18 18:43:21 volumioga volumio[885]: info: CoreStateMachine::stPlaybackTimer Oct 18 18:43:21 volumioga volumio[885]: info: ------------------------------ 90ms Oct 18 18:43:21 volumioga volumio[885]: info: ------------------------------ 89ms Oct 18 18:43:21 volumioga volumio[885]: info: CoreCommandRouter::volumioGetQueue Oct 18 18:43:21 volumioga volumio[885]: info: CoreStateMachine::getQueue Oct 18 18:43:21 volumioga volumio[885]: info: CorePlayQueue::getQueue Oct 18 18:43:21 volumioga volumio[885]: info: CoreCommandRouter::volumioGetQueue Oct 18 18:43:21 volumioga volumio[885]: info: CoreStateMachine::getQueue Oct 18 18:43:21 volumioga volumio[885]: info: CorePlayQueue::getQueue Oct 18 18:43:21 volumioga volumio[885]: info: Oct 18 18:43:21 volumioga volumio[885]: ---------------------------- USB Audio Device Detached Oct 18 18:43:21 volumioga volumio[885]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , usbAudioDetach Oct 18 18:43:21 volumioga volumio[885]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Oct 18 18:43:21 volumioga volumio[885]: info: CoreCommandRouter::executeOnPlugin: raat , onStop Oct 18 18:43:21 volumioga volumio[885]: info: touch_display: Setting screensaver timeout to 120 seconds. Oct 18 18:43:21 volumioga kernel: usb 1-1.3: new high-speed USB device number 4 using xhci_hcd Oct 18 18:43:21 volumioga kernel: usb 1-1.3: New USB device found, idVendor=152a, idProduct=85dd, bcdDevice= 3.53 Oct 18 18:43:21 volumioga kernel: usb 1-1.3: New USB device strings: Mfr=1, Product=3, SerialNumber=2 Oct 18 18:43:21 volumioga kernel: usb 1-1.3: Product: SMSL USB AUDIO Oct 18 18:43:21 volumioga kernel: usb 1-1.3: Manufacturer: SMSL Oct 18 18:43:22 volumioga kernel: usb 1-1.3: 1:3 : unsupported format bits 0x100000000 Oct 18 18:43:22 volumioga kernel: hid-generic 0003:152A:85DD.0002: hiddev96,hidraw0: USB HID v1.10 Device [SMSL SMSL USB AUDIO] on usb-0000:01:00.0-1.3/input3 Oct 18 18:43:22 volumioga volumio[885]: info: Oct 18 18:43:22 volumioga volumio[885]: ---------------------------- USB Audio Device Attached Oct 18 18:43:22 volumioga volumio[885]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , usbAudioAttach Oct 18 18:43:22 volumioga volumio[885]: info: CoreCommandRouter::Close All Modals sent Oct 18 18:43:22 volumioga volumio[885]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Oct 18 18:43:22 volumioga volumio[885]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Oct 18 18:43:22 volumioga volumio[885]: info: Device 5 does not have any Mixer Control Available Oct 18 18:43:22 volumioga volumio[885]: info: CoreCommandRouter::volumioUpdateVolumeSettings Oct 18 18:43:22 volumioga volumio[885]: info: Updating Volume Controller Parameters: Device: 5 Name: SMSL USB AUDIO Mixer: Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 Oct 18 18:43:22 volumioga volumio[885]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Oct 18 18:43:22 volumioga volumio[885]: info: Disabling external Volume Control Oct 18 18:43:22 volumioga volumio[885]: info: CoreCommandRouter::getUIConfigOnPlugin Oct 18 18:43:22 volumioga volumio[885]: info: CoreStateMachine::pushState Oct 18 18:43:22 volumioga volumio[885]: info: CoreCommandRouter::volumioPushState Oct 18 18:43:22 volumioga volumio[885]: info: Preparing to generate the ALSA configuration file Oct 18 18:43:22 volumioga volumio[885]: info: CoreCommandRouter::volumioGetQueue Oct 18 18:43:22 volumioga volumio[885]: info: CoreStateMachine::getQueue Oct 18 18:43:22 volumioga volumio[885]: info: CorePlayQueue::getQueue Oct 18 18:43:22 volumioga volumio[885]: info: Asound.conf file unchanged, so no further update is needed Oct 18 18:43:22 volumioga volumio[885]: info: Output device has changed, restarting MPD Oct 18 18:43:22 volumioga sudo[3016]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/chmod 777 /etc/mpd.conf Oct 18 18:43:22 volumioga sudo[3016]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 18 18:43:22 volumioga volumio[885]: info: Output device has changed, restarting Shairport Sync Oct 18 18:43:22 volumioga volumio[885]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 18 18:43:22 volumioga sudo[3016]: pam_unix(sudo:session): session closed for user root Oct 18 18:43:22 volumioga volumio[885]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 18 18:43:22 volumioga sudo[3019]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart mpd.service Oct 18 18:43:22 volumioga sudo[3019]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 18 18:43:22 volumioga systemd[1]: Stopping Music Player Daemon... Oct 18 18:43:22 volumioga volumio[885]: info: Could not detect Primo: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0 Oct 18 18:43:22 volumioga volumio[885]: info: MPD Permissions set Oct 18 18:43:22 volumioga systemd[1]: mpd.service: Succeeded. Oct 18 18:43:22 volumioga systemd[1]: Stopped Music Player Daemon. Oct 18 18:43:22 volumioga systemd[1]: Starting Music Player Daemon... Oct 18 18:43:22 volumioga volumio[885]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sOptions Oct 18 18:43:22 volumioga volumio[885]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 18 18:43:22 volumioga volumio[885]: info: CoreCommandRouter::executeOnPlugin: i2s_dacs , getI2sStatus Oct 18 18:43:22 volumioga volumio[885]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 18 18:43:22 volumioga volumio[885]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 18 18:43:22 volumioga volumio[885]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 18 18:43:22 volumioga volumio[885]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 18 18:43:22 volumioga volumio[885]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 18 18:43:22 volumioga volumio[885]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 18 18:43:22 volumioga volumio[885]: info: CoreCommandRouter::executeOnPlugin: mpd , getConfigParam Oct 18 18:43:22 volumioga volumio[885]: info: CoreCommandRouter::executeOnPlugin: mpd , getPlaybackMode Oct 18 18:43:22 volumioga volumio[885]: info: CoreCommandRouter::executeOnPlugin: system , getAdvancedSettingsStatus Oct 18 18:43:22 volumioga volumio[885]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 18 18:43:22 volumioga volumio[885]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 18 18:43:22 volumioga volumio[885]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 18 18:43:22 volumioga volumio[885]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 18 18:43:22 volumioga volumio[885]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 18 18:43:22 volumioga volumio[885]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 18 18:43:22 volumioga volumio[885]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 18 18:43:22 volumioga volumio[885]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 18 18:43:22 volumioga volumio[885]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Oct 18 18:43:22 volumioga volumio[885]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Oct 18 18:43:22 volumioga volumio[885]: info: Starting Shairport Sync Oct 18 18:43:22 volumioga sudo[3035]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl restart shairport-sync Oct 18 18:43:22 volumioga sudo[3035]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 18 18:43:23 volumioga systemd[1]: Stopping Shairport Sync - AirPlay Audio Receiver... Oct 18 18:43:23 volumioga systemd[1]: shairport-sync.service: Succeeded. Oct 18 18:43:23 volumioga systemd[1]: Stopped Shairport Sync - AirPlay Audio Receiver. Oct 18 18:43:23 volumioga systemd[1]: Started Shairport Sync - AirPlay Audio Receiver. Oct 18 18:43:23 volumioga sudo[3035]: pam_unix(sudo:session): session closed for user root Oct 18 18:43:23 volumioga volumio[885]: info: Shairport-Sync Started Oct 18 18:43:23 volumioga volumio[885]: info: CoreCommandRouter::executeOnPlugin: raat , restartRaat Oct 18 18:43:23 volumioga mpd[3024]: Oct 18 18:43 : decoder: Decoder plugin 'wildmidi' is unavailable: configuration file does not exist: /etc/timidity/timidity.cfg Oct 18 18:43:23 volumioga systemd[1]: Started Music Player Daemon. Oct 18 18:43:23 volumioga sudo[3019]: pam_unix(sudo:session): session closed for user root Oct 18 18:43:23 volumioga volumio[885]: error: updateQueue error: null Oct 18 18:43:26 volumioga volumio[885]: info: CoreCommandRouter::volumioRetrieveVolumeLevels Oct 18 18:43:26 volumioga volumio[885]: info: CoreStateMachine::getcurrentVolume Oct 18 18:43:26 volumioga volumio[885]: info: CoreCommandRouter::volumioRetrievevolume Oct 18 18:43:26 volumioga volumio[885]: info: CoreStateMachine::pushState Oct 18 18:43:26 volumioga volumio[885]: info: CoreCommandRouter::volumioPushState Oct 18 18:43:26 volumioga volumio[885]: info: CoreCommandRouter::volumioGetQueue Oct 18 18:43:26 volumioga volumio[885]: info: CoreStateMachine::getQueue Oct 18 18:43:26 volumioga volumio[885]: info: CorePlayQueue::getQueue Oct 18 18:44:23 volumioga volumio[885]: info: CoreCommandRouter::volumioPlay Oct 18 18:44:23 volumioga volumio[885]: info: CoreStateMachine::play index undefined Oct 18 18:44:23 volumioga volumio[885]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 18 18:44:23 volumioga volumio[885]: info: CorePlayQueue::getTrack 0 Oct 18 18:44:32 volumioga volumio[885]: info: CoreCommandRouter::volumioPrevious Oct 18 18:44:32 volumioga volumio[885]: info: CoreStateMachine::previous Oct 18 18:44:32 volumioga volumio[885]: info: CorePlayQueue::getTrack 0 Oct 18 18:44:32 volumioga volumio[885]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 18 18:44:32 volumioga volumio[885]: TypeError: Cannot read property 'service' of undefined Oct 18 18:44:32 volumioga volumio[885]: at CoreStateMachine.previous (/volumio/app/statemachine.js:1315:97) Oct 18 18:44:32 volumioga volumio[885]: at CoreCommandRouter.volumioPrevious (/volumio/app/index.js:95:28) Oct 18 18:44:32 volumioga volumio[885]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:246:33) Oct 18 18:44:32 volumioga volumio[885]: at Socket.emit (events.js:315:20) Oct 18 18:44:32 volumioga volumio[885]: at /volumio/node_modules/socket.io/lib/socket.js:503:12 Oct 18 18:44:32 volumioga volumio[885]: at processTicksAndRejections (internal/process/task_queues.js:75:11) Oct 18 18:44:32 volumioga volumio[885]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 18 18:44:32 volumioga sudo[3228]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-10-18 18:43 Oct 18 18:44:32 volumioga sudo[3228]: 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="7f9f1bf001add7a8b19a4516e3c74ef598b2730d" VOLUMIO_FE_VERSION="614d7b13ffdcb0cc5a6072e7d06f59d52e323e71" VOLUMIO_FE3_VERSION="570aaed971c1346d45d1172dc445b086b258c6d1" VOLUMIO_BE_VERSION="512433c3e91cdaed7ecd2808b21adeffc2137d7f" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Wed 21 Feb 2024 09:37:22 PM CET" VOLUMIO_VERSION="3.631" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="fdd9dd1169c06c1ad0a30ddd24c91b6b"