-- Logs begin at Fri 2024-04-12 00:35:54 UTC, end at Wed 2024-04-17 11:37:05 UTC. -- Apr 17 11:36:01 primo-1 volumio[27989]: (node:27989) [DEP0005] DeprecationWarning: Buffer() is deprecated due to security and usability issues. Please use the Buffer.alloc(), Buffer.allocUnsafe(), or Buffer.from() methods instead. Apr 17 11:36:01 primo-1 volumio[27989]: (Use `node --trace-deprecation ...` to show where the warning was created) Apr 17 11:36:01 primo-1 volumio[27989]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback Apr 17 11:36:01 primo-1 volumio[27989]: [SpotifyConnect] Creating VLS config file Apr 17 11:36:01 primo-1 volumio[27989]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 17 11:36:01 primo-1 volumio[27989]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 17 11:36:01 primo-1 volumio[27989]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 17 11:36:02 primo-1 volumio[27989]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 17 11:36:02 primo-1 volumio[27989]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 17 11:36:02 primo-1 volumio[27989]: [SpotifyConnect] Starting metadata listener Apr 17 11:36:02 primo-1 volumio[27989]: info: Preparing to generate the ALSA configuration file Apr 17 11:36:03 primo-1 sudo[28548]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volspotconnect.service Apr 17 11:36:03 primo-1 sudo[28548]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 17 11:36:03 primo-1 volumio[27989]: info: Stopping AccessToken refresher cron Apr 17 11:36:04 primo-1 sudo[28548]: pam_unix(sudo:session): session closed for user root Apr 17 11:36:05 primo-1 volumio[27989]: info: AccessToken refresher cron started Apr 17 11:36:05 primo-1 volumio[27989]: info: Adding TIDAL REST API Endpoints Apr 17 11:36:05 primo-1 volumio[27989]: info: Adding getStreamUrltidal REST Endpoint for plugin: music_service/tidal Apr 17 11:36:20 primo-1 volumio[27989]: info: MRS: Getting audio outputs on start Apr 17 11:36:21 primo-1 volumio[27989]: info: MRS: Requesting all other devices output Apr 17 11:36:24 primo-1 volumio[27989]: info: Initializing I2S Bus Apr 17 11:36:24 primo-1 sudo[28555]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volumiobt.service Apr 17 11:36:24 primo-1 sudo[28555]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 17 11:36:25 primo-1 sudo[28555]: pam_unix(sudo:session): session closed for user root Apr 17 11:36:25 primo-1 volumio[27989]: /usr/bin/mkfifo: cannot create fifo '/tmp/fusiondspfifo': File exists Apr 17 11:36:26 primo-1 volumio[27989]: error: FusionDsp - ----failed to create fusiondspfifo :Error: Command failed: /bin/touch /tmp/sr.log && /bin/chmod 666 /tmp/sr.log && /bin/touch /tmp/camilladsp.log && /bin/chmod 666 /tmp/camilladsp.log && /usr/bin/mkfifo -m 646 /tmp/fusiondspfifo Apr 17 11:36:26 primo-1 volumio[27989]: /usr/bin/mkfifo: cannot create fifo '/tmp/fusiondspfifo': File exists Apr 17 11:36:27 primo-1 volumio[27989]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 17 11:36:30 primo-1 kernel: aml_tdm_open Apr 17 11:36:30 primo-1 kernel: Not init audio effects Apr 17 11:36:30 primo-1 kernel: audio_ddr_mngr: frddrs[0] registered by device ff660000.audiobus:tdm@1 Apr 17 11:36:30 primo-1 kernel: tdm playback mute: 1, lane_cnt = 8 Apr 17 11:36:30 primo-1 kernel: audio_ddr_mngr: frddrs[0] released by device ff660000.audiobus:tdm@1 Apr 17 11:36:32 primo-1 volumio[27989]: No protocol specified Apr 17 11:36:32 primo-1 volumio[27989]: xcb_connection_has_error() returned true Apr 17 11:36:32 primo-1 volumio[27989]: info: FusionDsp - AAAAAAAAAAAAAA-> 44100 48000 88200 96000 176400 192000 <-AAAAAAAAAAAAA Apr 17 11:36:34 primo-1 volumio[27989]: info: FusionDsp loaded Apr 17 11:36:34 primo-1 volumio[27989]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Apr 17 11:36:35 primo-1 sudo[28568]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start fusiondsp.service Apr 17 11:36:35 primo-1 sudo[28568]: pam_unix(sudo:session): session opened for user root by (uid=0) Apr 17 11:36:36 primo-1 sudo[28568]: pam_unix(sudo:session): session closed for user root Apr 17 11:36:37 primo-1 volumio[27989]: info: FusionDsp - Reporting Fusion DSP Enabled Apr 17 11:36:37 primo-1 volumio[27989]: info: Adding Signal Path Element [object Object] Apr 17 11:36:37 primo-1 volumio[27989]: info: Adding fusiondspeq DSP Signal Path Element Apr 17 11:36:37 primo-1 volumio[27989]: info: Additional DSP elements updated Apr 17 11:36:37 primo-1 volumio[27989]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 17 11:36:37 primo-1 volumio[27989]: info: Updating RAAT Signal Path Apr 17 11:36:38 primo-1 volumio[27989]: error: Cannot write to RAAT Client: TypeError: Cannot read property 'write' of undefined Apr 17 11:36:39 primo-1 volumio[27989]: info: FusionDsp - If filter freq >samplerate/2 then disable it Apr 17 11:36:42 primo-1 volumio[27989]: info: Discovery: adding ac8d7a39-706e-4de7-b574-edb89ca95674 Apr 17 11:36:42 primo-1 volumio[27989]: info: Discovery: Found device Primo 1 Apr 17 11:36:42 primo-1 volumio[27989]: info: CoreCommandRouter::volumioGetState Apr 17 11:36:42 primo-1 volumio[27989]: info: CorePlayQueue::getTrack 0 Apr 17 11:36:42 primo-1 volumio[27989]: info: MRS: Pushing multiroomSync output for this device Apr 17 11:36:43 primo-1 volumio[27989]: info: MRS: Pushing multiroomSync output Apr 17 11:36:43 primo-1 volumio[27989]: info: Adding audio output: Apr 17 11:36:43 primo-1 volumio[27989]: info: Adding audio output: Apr 17 11:36:44 primo-1 volumio[27989]: info: Discovery: this is already registered, ac8d7a39-706e-4de7-b574-edb89ca95674 Apr 17 11:36:44 primo-1 volumio[27989]: info: Discovery: Found device Primo 1 Apr 17 11:36:44 primo-1 volumio[27989]: info: CoreCommandRouter::volumioGetState Apr 17 11:36:44 primo-1 volumio[27989]: info: CorePlayQueue::getTrack 0 Apr 17 11:36:44 primo-1 volumio-remote-updater[4477]: [2024-04-17 11:36:44] [disconnect] Disconnect close local:[1006,The closing handshake timed out] remote:[1000] Apr 17 11:36:48 primo-1 volumio[27989]: info: Serial port opened successfully Apr 17 11:36:48 primo-1 volumio[27989]: info: Sending serial start messages Apr 17 11:36:49 primo-1 systemd[1]: mpd.service: Start operation timed out. Terminating. Apr 17 11:36:49 primo-1 systemd[1]: mpd.service: Main process exited, code=killed, status=15/TERM Apr 17 11:36:49 primo-1 systemd[1]: mpd.service: Failed with result 'timeout'. Apr 17 11:36:49 primo-1 systemd[1]: Failed to start Music Player Daemon. Apr 17 11:36:49 primo-1 volumio-remote-updater[4477]: [2024-04-17 11:36:49] [connect] Successful connection Apr 17 11:36:50 primo-1 sudo[28355]: pam_unix(sudo:session): session closed for user root Apr 17 11:36:50 primo-1 sudo[28411]: pam_unix(sudo:session): session closed for user root Apr 17 11:36:50 primo-1 volumio[27989]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 17 11:36:51 primo-1 volumio[27989]: info: The plugin multiroom has an ALSA contribution file volumioMultiRoomServer.postMultiRoom.1000.conf Apr 17 11:36:51 primo-1 volumio[27989]: info: The plugin fusiondsp has an ALSA contribution file volumioDsp.postDsp.10.conf Apr 17 11:36:51 primo-1 volumio[27989]: info: Reading ALSA contributions from plugins. Apr 17 11:36:51 primo-1 volumio[27989]: info: Checking for updated MCU Firmware Apr 17 11:36:51 primo-1 volumio[27989]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 17 11:36:51 primo-1 volumio[27989]: error: Failed to retrieve informations for FW Update Apr 17 11:36:51 primo-1 volumio[27989]: info: Volumio BT Module successfully started Apr 17 11:36:51 primo-1 volumio[27989]: [SpotifyConnect] Vollibrespot Daemon service started! Apr 17 11:36:51 primo-1 volumio[27989]: [Metrics] SpotifyConnect: 49s 780.57ms Apr 17 11:36:51 primo-1 volumio[27989]: info: TidalConnect service stoped! Apr 17 11:36:51 primo-1 volumio[27989]: error: Cannot start Volumio Streaming Daemon Apr 17 11:36:51 primo-1 volumio[27989]: error: Failed initialization of streaming services: Error: Error: Command failed: /usr/bin/sudo systemctl restart volumio-streaming-daemon.service Apr 17 11:36:51 primo-1 volumio[27989]: Failed to restart volumio-streaming-daemon.service: Unit volumio-streaming-daemon.service not found. Apr 17 11:36:51 primo-1 volumio[27989]: info: Bluetooth name changed to Primo 1 Apr 17 11:36:51 primo-1 volumio[27989]: info: MPD Permissions set Apr 17 11:36:51 primo-1 volumio[27989]: info: MPD Permissions set Apr 17 11:36:52 primo-1 volumio[27989]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Apr 17 11:36:52 primo-1 volumio[27989]: info: CoreCommandRouter::executeOnPlugin: system , getConfigParam Apr 17 11:36:52 primo-1 volumio[27989]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Apr 17 11:36:52 primo-1 volumio[27989]: error: Plugin music_service mpd failed to complete 'onStart' in a timely fashion Apr 17 11:36:52 primo-1 volumio[27989]: error: Plugin music_service tidalconnect failed to complete 'onStart' in a timely fashion Apr 17 11:36:52 primo-1 volumio[27989]: error: Plugin audio_interface multiroom failed to complete 'onStart' in a timely fashion Apr 17 11:36:52 primo-1 volumio[27989]: error: Plugin music_service qobuz failed to complete 'onStart' in a timely fashion Apr 17 11:36:52 primo-1 volumio[27989]: info: ------------------------------------------- Apr 17 11:36:52 primo-1 volumio[27989]: info: ----- MyVolumio plugins startup ---- Apr 17 11:36:52 primo-1 volumio[27989]: info: ------------------------------------------- Apr 17 11:36:52 primo-1 volumio[27989]: info: [MyVolumio PluginManager] Fetching plans data.... Apr 17 11:36:52 primo-1 volumio[27989]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setDeviceVolumeOverride Apr 17 11:36:52 primo-1 volumio[27989]: info: Setting Device Volume Override Apr 17 11:36:53 primo-1 dbus-daemon[4481]: [system] Connection has not authenticated soon enough, closing it (auth_timeout=30000ms, elapsed: 30001ms) Apr 17 11:36:53 primo-1 volumiologrotate[4544]: ls: cannot access '/var/log/samba/log.wb-PRIMO': No such file or directory Apr 17 11:36:53 primo-1 dbus-daemon[4481]: [system] Connection has not authenticated soon enough, closing it (auth_timeout=30000ms, elapsed: 30006ms) Apr 17 11:36:53 primo-1 volumiologrotate[4544]: ls: cannot access '1': No such file or directory Apr 17 11:36:54 primo-1 volumio[27989]: No protocol specified Apr 17 11:36:54 primo-1 volumio[27989]: xcb_connection_has_error() returned true Apr 17 11:36:54 primo-1 volumio[27989]: info: Applying Volume Override Apr 17 11:36:54 primo-1 volumio[27989]: info: CoreCommandRouter::volumioUpdateVolumeSettings Apr 17 11:36:54 primo-1 volumio[27989]: info: Updating Volume Controller Parameters: Device: 0,0 Name: Analog Outputs Mixer: Audio hdmi-out mute Max Vol: 100 Vol Curve; logarithmic Vol Steps: 1 Apr 17 11:36:54 primo-1 volumio[27989]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , setExternalVolume Apr 17 11:36:54 primo-1 volumio[27989]: info: Enabling external Volume Control Apr 17 11:36:54 primo-1 volumio[27989]: info: CoreCommandRouter::executeOnPlugin: inputs , updateVolumeSettings Apr 17 11:36:54 primo-1 volumio[27989]: info: CoreCommandRouter::executeOnPlugin: inputs , retrievevolume Apr 17 11:36:54 primo-1 volumio[27989]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 17 11:36:54 primo-1 volumio[27989]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam Apr 17 11:36:54 primo-1 volumio[27989]: info: CoreStateMachine::pushState Apr 17 11:36:54 primo-1 volumio[27989]: info: CorePlayQueue::getTrack 0 Apr 17 11:36:54 primo-1 volumio[27989]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 17 11:36:54 primo-1 volumio[27989]: info: CoreCommandRouter::volumioPushState Apr 17 11:36:54 primo-1 volumio[27989]: info: MRS: Pushing multiroomSync output update for this device Apr 17 11:36:54 primo-1 volumio[27989]: info: MRS: Pushing multiroomSync output Apr 17 11:36:54 primo-1 volumio[27989]: info: CoreStateMachine::pushState Apr 17 11:36:54 primo-1 volumio[27989]: info: CorePlayQueue::getTrack 0 Apr 17 11:36:54 primo-1 volumio[27989]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Apr 17 11:36:55 primo-1 volumio[27989]: info: CoreCommandRouter::volumioPushState Apr 17 11:36:55 primo-1 volumio[27989]: info: MRS: Pushing multiroomSync output update for this device Apr 17 11:36:55 primo-1 volumio[27989]: info: MRS: Pushing multiroomSync output Apr 17 11:36:55 primo-1 volumio[27989]: info: CoreStateMachine::pushState Apr 17 11:36:55 primo-1 volumio[27989]: info: CorePlayQueue::getTrack 0 Apr 17 11:36:55 primo-1 volumio[27989]: info: CoreCommandRouter::volumioPushState Apr 17 11:36:55 primo-1 volumio[27989]: info: MRS: Pushing multiroomSync output update for this device Apr 17 11:36:55 primo-1 volumio[27989]: info: MRS: Pushing multiroomSync output Apr 17 11:36:56 primo-1 volumio[27989]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 17 11:36:56 primo-1 volumio[27989]: Error: write EPIPE Apr 17 11:36:56 primo-1 volumio[27989]: at afterWriteDispatched (internal/stream_base_commons.js:156:25) Apr 17 11:36:56 primo-1 volumio[27989]: at writeGeneric (internal/stream_base_commons.js:147:3) Apr 17 11:36:56 primo-1 volumio[27989]: at Socket._writeGeneric (net.js:798:11) Apr 17 11:36:56 primo-1 volumio[27989]: at Socket._write (net.js:810:8) Apr 17 11:36:56 primo-1 volumio[27989]: at writeOrBuffer (internal/streams/writable.js:358:12) Apr 17 11:36:56 primo-1 volumio[27989]: at Socket.Writable.write (internal/streams/writable.js:303:10) Apr 17 11:36:56 primo-1 volumio[27989]: at /volumio/app/plugins/audio_interface/bluetooth/node_modules/dbus-native/lib/handshake.js:82:16 Apr 17 11:36:56 primo-1 volumio[27989]: at Socket.readable (/volumio/app/plugins/audio_interface/bluetooth/node_modules/dbus-native/lib/readline.js:12:11) Apr 17 11:36:56 primo-1 volumio[27989]: at Socket.emit (events.js:400:28) Apr 17 11:36:56 primo-1 volumio[27989]: at emitReadable_ (internal/streams/readable.js:555:12) Apr 17 11:36:56 primo-1 volumio[27989]: at processTicksAndRejections (internal/process/task_queues.js:81:21) { Apr 17 11:36:56 primo-1 volumio[27989]: errno: -32, Apr 17 11:36:56 primo-1 volumio[27989]: code: 'EPIPE', Apr 17 11:36:56 primo-1 volumio[27989]: syscall: 'write' Apr 17 11:36:56 primo-1 volumio[27989]: } Apr 17 11:36:56 primo-1 volumio[27989]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Apr 17 11:37:02 primo-1 volumio-remote-updater[4477]: [2024-04-17 11:37:02] [connect] Successful connection Apr 17 11:37:05 primo-1 sudo[28659]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-04-17 11:36 Apr 17 11:37:05 primo-1 sudo[28659]: 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="7f9f1bf001add7a8b19a4516e3c74ef598b2730d" VOLUMIO_FE_VERSION="614d7b13ffdcb0cc5a6072e7d06f59d52e323e71" VOLUMIO_FE3_VERSION="570aaed971c1346d45d1172dc445b086b258c6d1" VOLUMIO_BE_VERSION="e831866afe2db61aee9333a8f5ba9d9fd36609c7" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="primo2rev2" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Sun 18 Feb 2024 12:01:04 PM CET" VOLUMIO_VERSION="3.629" VOLUMIO_HARDWARE="mp1" VOLUMIO_DEVICENAME="Volumio MP1" VOLUMIO_VENDOR_MODEL="Volumio Primo" VOLUMIO_VENDOR="Volumio" VOLUMIO_MODEL="Primo" VOLUMIO_HASH="728189e850980f21ef569472434ec23d"