-- 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"