Mar 29 13:58:24 volumio systemd[1]: Starting setdatetime-helper.service - Time Synchronization Helper Service...
Mar 29 13:58:24 volumio systemd[1]: setdatetime-helper.service: Deactivated successfully.
Mar 29 13:58:24 volumio systemd[1]: Finished setdatetime-helper.service - Time Synchronization Helper Service.
Mar 29 13:58:39 volumio volumio[1318]: info: CorePlayQueue::getTrack 0
Mar 29 13:58:39 volumio volumio[1318]: info: CorePlayQueue::getTrack 1
Mar 29 13:58:39 volumio volumio[1318]: info: Prefetching next song
Mar 29 13:58:39 volumio volumio[1318]: info: DOING PREFETCH IN MPD
Mar 29 13:58:39 volumio volumio[1318]: verbose: ControllerMpd::sendMpdCommand add "NAS/Music/Movie-Soundtracks/Film-Music-Hans-Zimmer-Prague-CD1/02 Hans Zimmer & Lisa Gerrard - Gladiator: Now We Are Free (vocal version).flac"
Mar 29 13:58:39 volumio volumio[1318]: info:
Mar 29 13:58:39 volumio volumio[1318]: ---------------------------- MPD announces system playlist update
Mar 29 13:58:39 volumio volumio[1318]: info: Ignoring MPD Status Update
Mar 29 13:58:39 volumio volumio[1318]: info: sendMpdCommand add "NAS/Music/Movie-Soundtracks/Film-Music-Hans-Zimmer-Prague-CD1/02 Hans Zimmer & Lisa Gerrard - Gladiator: Now We Are Free (vocal version).flac" took 1 milliseconds
Mar 29 13:58:39 volumio volumio[1318]: verbose: ControllerMpd::sendMpdCommand consume 1
Mar 29 13:58:39 volumio volumio[1318]: info:
Mar 29 13:58:39 volumio volumio[1318]: ---------------------------- MPD announces state update: options
Mar 29 13:58:39 volumio volumio[1318]: info: ------------------------------ 1ms
Mar 29 13:58:39 volumio volumio[1318]: info: sendMpdCommand consume 1 took 1 milliseconds
Mar 29 13:58:39 volumio volumio[1318]: info: ControllerMpd::getState
Mar 29 13:58:39 volumio volumio[1318]: verbose: ControllerMpd::sendMpdCommand status
Mar 29 13:58:39 volumio volumio[1318]: info: sendMpdCommand status took 0 milliseconds
Mar 29 13:58:39 volumio volumio[1318]: verbose: ControllerMpd::parseState
Mar 29 13:58:39 volumio volumio[1318]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Mar 29 13:58:39 volumio volumio[1318]: info: sendMpdCommand playlistinfo took 1 milliseconds
Mar 29 13:58:39 volumio volumio[1318]: verbose: ControllerMpd::parseTrackInfo
Mar 29 13:58:39 volumio volumio[1318]: info: ControllerMpd::pushState
Mar 29 13:58:39 volumio volumio[1318]: info: CoreCommandRouter::servicePushState
Mar 29 13:58:39 volumio volumio[1318]: info: CorePlayQueue::getTrack 0
Mar 29 13:58:39 volumio volumio[1318]: verbose: STATE SERVICE {"status":"play","position":0,"seek":433013,"duration":438,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1414 Kbps","isStreaming":false,"title":"Gladiator: Symphonic Suite","artist":"Hans Zimmer","album":"Film Music of Hans Zimmer","uri":"NAS/Music/Movie-Soundtracks/Film-Music-Hans-Zimmer-Prague-CD1/01 Hans Zimmer - Gladiator: Symphonic Suite.flac","trackType":"flac"}
Mar 29 13:58:39 volumio volumio[1318]: verbose: CURRENT POSITION 0
Mar 29 13:58:39 volumio volumio[1318]: info: CoreStateMachine::syncState stateService play
Mar 29 13:58:39 volumio volumio[1318]: info: CoreStateMachine::syncState currentStatus play
Mar 29 13:58:39 volumio volumio[1318]: info: Received an update from plugin. extracting info from payload
Mar 29 13:58:39 volumio volumio[1318]: info: CoreStateMachine::pushState
Mar 29 13:58:39 volumio volumio[1318]: info: CorePlayQueue::getTrack 0
Mar 29 13:58:39 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Mar 29 13:58:39 volumio volumio[1318]: info: CoreCommandRouter::volumioPushState
Mar 29 13:58:39 volumio volumio[1318]: info: CoreStateMachine::pushState
Mar 29 13:58:39 volumio volumio[1318]: info: CorePlayQueue::getTrack 0
Mar 29 13:58:39 volumio volumio[1318]: info: CoreCommandRouter::volumioPushState
Mar 29 13:58:39 volumio volumio[1318]: info: ------------------------------ 10ms
Mar 29 13:58:40 volumio ntpd[1144]: PROTO: 172.233.155.39 unlink local addr 192.168.0.132 ->
Mar 29 13:58:43 volumio volumio[1318]: info: CoreStateMachine::startPlaybackTimer
Mar 29 13:58:43 volumio volumio[1318]: info: CorePlayQueue::getTrack 1
Mar 29 13:58:44 volumio volumio[1318]: info: CoreStateMachine::pushState
Mar 29 13:58:44 volumio volumio[1318]: info: CorePlayQueue::getTrack 1
Mar 29 13:58:44 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Mar 29 13:58:44 volumio volumio[1318]: info: CoreCommandRouter::volumioPushState
Mar 29 13:58:44 volumio volumio[1318]: info:
Mar 29 13:58:44 volumio volumio[1318]: ---------------------------- MPD announces system playlist update
Mar 29 13:58:44 volumio volumio[1318]: info: Ignoring MPD Status Update
Mar 29 13:58:44 volumio volumio[1318]: info:
Mar 29 13:58:44 volumio volumio[1318]: ---------------------------- MPD announces state update: player
Mar 29 13:58:44 volumio volumio[1318]: info: ControllerMpd::getState
Mar 29 13:58:44 volumio volumio[1318]: verbose: ControllerMpd::sendMpdCommand status
Mar 29 13:58:44 volumio volumio[1318]: info: ------------------------------ 1ms
Mar 29 13:58:44 volumio volumio[1318]: info: sendMpdCommand status took 0 milliseconds
Mar 29 13:58:44 volumio volumio[1318]: verbose: ControllerMpd::parseState
Mar 29 13:58:44 volumio volumio[1318]: verbose: ControllerMpd::sendMpdCommand playlistinfo
Mar 29 13:58:44 volumio volumio[1318]: info: sendMpdCommand playlistinfo took 1 milliseconds
Mar 29 13:58:44 volumio volumio[1318]: verbose: ControllerMpd::parseTrackInfo
Mar 29 13:58:44 volumio volumio[1318]: info: ControllerMpd::pushState
Mar 29 13:58:44 volumio volumio[1318]: info: CoreCommandRouter::servicePushState
Mar 29 13:58:44 volumio volumio[1318]: info: CorePlayQueue::getTrack 1
Mar 29 13:58:44 volumio volumio[1318]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":262,"samplerate":"44.1 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":"1414 Kbps","isStreaming":false,"title":"Gladiator: Now We Are Free (vocal version)","artist":"Hans Zimmer & Lisa Gerrard","album":"Film Music of Hans Zimmer","uri":"NAS/Music/Movie-Soundtracks/Film-Music-Hans-Zimmer-Prague-CD1/02 Hans Zimmer & Lisa Gerrard - Gladiator: Now We Are Free (vocal version).flac","trackType":"flac"}
Mar 29 13:58:44 volumio volumio[1318]: verbose: CURRENT POSITION 1
Mar 29 13:58:44 volumio volumio[1318]: info: CoreStateMachine::syncState stateService play
Mar 29 13:58:44 volumio volumio[1318]: info: CoreStateMachine::syncState currentStatus play
Mar 29 13:58:44 volumio volumio[1318]: info: Received an update from plugin. extracting info from payload
Mar 29 13:58:44 volumio volumio[1318]: info: CoreStateMachine::pushState
Mar 29 13:58:44 volumio volumio[1318]: info: CorePlayQueue::getTrack 1
Mar 29 13:58:44 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
Mar 29 13:58:44 volumio volumio[1318]: info: CoreCommandRouter::volumioPushState
Mar 29 13:58:44 volumio volumio[1318]: info: CoreStateMachine::pushState
Mar 29 13:58:44 volumio volumio[1318]: info: CorePlayQueue::getTrack 1
Mar 29 13:58:44 volumio volumio[1318]: info: CoreCommandRouter::volumioPushState
Mar 29 13:58:44 volumio volumio[1318]: info: ------------------------------ 9ms
Mar 29 13:58:48 volumio ntpd[1144]: PROTO: 66.118.229.14 unlink local addr 192.168.0.132 ->
Mar 29 13:58:56 volumio volumio[1318]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 9
Mar 29 13:58:56 volumio volumio[1318]: info: Downloading plugin at http://127.0.0.1:3000/plugin-serve/stylish_player.zip
Mar 29 13:58:56 volumio volumio5-onboarding[2365]: time=2026-03-29T13:58:56.989-05:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Mar 29 13:58:56 volumio volumio[1318]: info: END DOWNLOAD: http://127.0.0.1:3000/plugin-serve/stylish_player.zip
Mar 29 13:58:56 volumio volumio5-onboarding[2365]: time=2026-03-29T13:58:56.997-05:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Mar 29 13:58:57 volumio volumio5-onboarding[2365]: time=2026-03-29T13:58:56.999-05:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Mar 29 13:58:57 volumio volumio5-onboarding[2365]: time=2026-03-29T13:58:57.193-05:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Mar 29 13:58:57 volumio volumio[1318]: info: Check plugin dependencies
Mar 29 13:58:57 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion
Mar 29 13:58:57 volumio volumio5-onboarding[2365]: time=2026-03-29T13:58:57.207-05:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Mar 29 13:58:57 volumio volumio[1318]: info: Rename folder
Mar 29 13:58:57 volumio volumio5-onboarding[2365]: time=2026-03-29T13:58:57.215-05:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Mar 29 13:58:57 volumio volumio[1318]: info: Move to category
Mar 29 13:58:57 volumio volumio[1318]: info: Folder /tmp/downloaded_plugin.zip removed
Mar 29 13:58:57 volumio volumio5-onboarding[2365]: time=2026-03-29T13:58:57.404-05:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Mar 29 13:58:57 volumio volumio[1318]: info: Checking if install.sh is present
Mar 29 13:58:57 volumio volumio[1318]: info: Executing install.sh
Mar 29 13:58:57 volumio sudo[4550]: volumio : PWD=/ ; USER=root ; COMMAND=/usr/bin/sh /data/plugins/user_interface/stylish_player/install.sh
Mar 29 13:58:57 volumio sudo[4550]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 29 13:58:57 volumio sudo[4550]: pam_unix(sudo:session): session closed for user root
Mar 29 13:58:57 volumio volumio[1318]: info: Installing Stylish Player Dependencies
Mar 29 13:58:57 volumio volumio5-onboarding[2365]: time=2026-03-29T13:58:57.428-05:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Mar 29 13:58:57 volumio volumio[1318]: Plugin install end detected on script
Mar 29 13:58:57 volumio volumio[1318]: info: Install script completed
Mar 29 13:58:57 volumio volumio5-onboarding[2365]: time=2026-03-29T13:58:57.432-05:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Mar 29 13:58:57 volumio volumio5-onboarding[2365]: time=2026-03-29T13:58:57.435-05:00 level=WARN msg="received plugin install progress but no plugin is being installed" component=state
Mar 29 13:58:57 volumio volumio[1318]: info: Done installing plugin.
Mar 29 13:58:57 volumio volumio[1318]: info: Enabling plugin stylish_player
Mar 29 13:58:57 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Mar 29 13:58:57 volumio volumio[1318]: info: [{"prettyName":"YouTube2","name":"youtube2","category":"music_service","version":"2.5.1","icon":"fa-youtube-play","isManuallyInstalled":false,"enabled":true,"active":true},{"prettyName":"Backup & Restore Data","name":"backup_restore","category":"system_controller","version":"1.7.4","icon":"fa-floppy-o","isManuallyInstalled":false,"enabled":true,"active":true},{"prettyName":"Music Services Shield","name":"music_services_shield","category":"system_hardware","version":"2.3.1","icon":"fa-shield","isManuallyInstalled":false,"enabled":true,"active":true},{"prettyName":"Now Playing","name":"now_playing","category":"user_interface","version":"1.0.7","icon":"fa-play-circle","isManuallyInstalled":false,"enabled":true,"active":true},{"prettyName":"PeppyMeter Screensaver","name":"peppy_screensaver","category":"user_interface","version":"3.3.1","icon":"fa-lightbulb-o","isManuallyInstalled":true,"enabled":false,"active":false},{"prettyName":"Stylish Player","name":"stylish_player","category":"user_interface","version":"1.0.40","icon":"fa-music","isManuallyInstalled":false,"enabled":true,"active":true}]
Mar 29 13:58:57 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken
Mar 29 13:58:57 volumio volumio[1318]: info: Folder /tmp/downloaded_plugin.zip removed
Mar 29 13:58:57 volumio volumio[1318]: info: Folder /tmp/plugins removed
Mar 29 13:58:57 volumio volumio[1318]: info: Folder /data/temp removed
Mar 29 13:58:59 volumio volumio[1318]: info: Stylish Player: Server stopped
Mar 29 13:58:59 volumio volumio[1318]: info: Disabling plugin stylish_player
Mar 29 13:58:59 volumio volumio[1318]: info: Done.
Mar 29 13:59:01 volumio sudo[4567]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0
Mar 29 13:59:01 volumio sudo[4567]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 29 13:59:01 volumio sudo[4569]: volumio : PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0
Mar 29 13:59:01 volumio sudo[4569]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
Mar 29 13:59:01 volumio sudo[4567]: pam_unix(sudo:session): session closed for user root
Mar 29 13:59:01 volumio sudo[4569]: pam_unix(sudo:session): session closed for user root
Mar 29 13:59:01 volumio volumio[1318]: verbose: New Socket.io Connection to 192.168.0.132 from 192.168.0.236 UA: Mozilla/5.0 (Macintosh; Intel Mac OS X 10_15_7) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/146.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 8
Mar 29 13:59:01 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Mar 29 13:59:01 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom
Mar 29 13:59:01 volumio volumio[1318]: info: CoreCommandRouter::volumioGetState
Mar 29 13:59:01 volumio volumio[1318]: info: CorePlayQueue::getTrack 1
Mar 29 13:59:01 volumio volumio[1318]: info: CoreCommandRouter::volumioGetVisibleSources
Mar 29 13:59:01 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
Mar 29 13:59:01 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings
Mar 29 13:59:01 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard
Mar 29 13:59:01 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard
Mar 29 13:59:01 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings
Mar 29 13:59:01 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken
Mar 29 13:59:03 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Mar 29 13:59:03 volumio volumio[1318]: info: Received Get System Info
Mar 29 13:59:03 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Mar 29 13:59:03 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Mar 29 13:59:03 volumio volumio[1318]: info: Discovery: Getting this device information
Mar 29 13:59:03 volumio volumio[1318]: info: CoreCommandRouter::volumioGetState
Mar 29 13:59:03 volumio volumio[1318]: info: CorePlayQueue::getTrack 1
Mar 29 13:59:03 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Mar 29 13:59:03 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus
Mar 29 13:59:03 volumio volumio[1318]: info: Received Get System Info
Mar 29 13:59:03 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo
Mar 29 13:59:03 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice
Mar 29 13:59:03 volumio volumio[1318]: info: Discovery: Getting this device information
Mar 29 13:59:03 volumio volumio[1318]: info: CoreCommandRouter::volumioGetState
Mar 29 13:59:03 volumio volumio[1318]: info: CorePlayQueue::getTrack 1
Mar 29 13:59:03 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses
Mar 29 13:59:07 volumio volumio[1318]: info: Enabling plugin stylish_player
Mar 29 13:59:07 volumio volumio[1318]: info: Loading plugin "stylish_player"...
Mar 29 13:59:07 volumio volumio[1318]: info: PLUGIN START: stylish_player
Mar 29 13:59:07 volumio volumio[1318]: info: CoreCommandRouter::executeOnPlugin: alsa_controller , updateALSAConfigFile
Mar 29 13:59:07 volumio volumio[1318]: /usr/bin/mkfifo: cannot create fifo '/tmp/stream.mp3': File exists
Mar 29 13:59:07 volumio volumio[1318]: error: ----failed to create fifo :Error: Command failed: /usr/bin/mkfifo -m 646 /tmp/stream.mp3
Mar 29 13:59:07 volumio volumio[1318]: /usr/bin/mkfifo: cannot create fifo '/tmp/stream.mp3': File exists
Mar 29 13:59:07 volumio volumio[1318]: info: Preparing to generate the ALSA configuration file
Mar 29 13:59:07 volumio volumio[1318]: |||||||||||||||||||||||| WARNING: FATAL ERROR |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Mar 29 13:59:07 volumio volumio[1318]: Error: listen EADDRINUSE: address already in use :::9993
Mar 29 13:59:07 volumio volumio[1318]: at Server.setupListenHandle [as _listen2] (node:net:1872:16)
Mar 29 13:59:07 volumio volumio[1318]: at listenInCluster (node:net:1920:12)
Mar 29 13:59:07 volumio volumio[1318]: at Server.listen (node:net:2008:7)
Mar 29 13:59:07 volumio volumio[1318]: at ControllerStylishPlayer.streamOutViz (/data/plugins/user_interface/stylish_player/index.js:176:20)
Mar 29 13:59:07 volumio volumio[1318]: at ControllerStylishPlayer.onStart (/data/plugins/user_interface/stylish_player/index.js:60:8)
Mar 29 13:59:07 volumio volumio[1318]: at PluginManager.startPlugin (/volumio/app/pluginmanager.js:431:30)
Mar 29 13:59:07 volumio volumio[1318]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28)
Mar 29 13:59:07 volumio volumio[1318]: at process.processTicksAndRejections (node:internal/process/task_queues:77:11) {
Mar 29 13:59:07 volumio volumio[1318]: code: 'EADDRINUSE',
Mar 29 13:59:07 volumio volumio[1318]: errno: -98,
Mar 29 13:59:07 volumio volumio[1318]: syscall: 'listen',
Mar 29 13:59:07 volumio volumio[1318]: address: '::',
Mar 29 13:59:07 volumio volumio[1318]: port: 9993
Mar 29 13:59:07 volumio volumio[1318]: }
Mar 29 13:59:07 volumio volumio[1318]: |||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||
Mar 29 13:59:08 volumio sudo[4609]: volumio : PWD=/ ; USER=root ; COMMAND=/bin/journalctl '--since=2026-03-29 13:58'
Mar 29 13:59:08 volumio sudo[4609]: pam_unix(sudo:session): session opened for user root(uid=0) by (uid=1000)
PRETTY_NAME="Debian GNU/Linux 12 (bookworm)"
NAME="Debian GNU/Linux"
VERSION_ID="12"
VERSION="12 (bookworm)"
VERSION_CODENAME=bookworm
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="dc61260dec5515dafd2b634881860b4c46c919ff"
VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd"
VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2"
VOLUMIO_BE_VERSION="0e58f1861fa88e02087981b8d91f7511f0e7011b"
VOLUMIO_ARCH="x64"
VOLUMIO_VARIANT="volumio"
VOLUMIO_TEST="FALSE"
VOLUMIO_BUILD_DATE="Fri Mar 6 17:11:42 UTC 2026"
VOLUMIO_VERSION="4.103"
VOLUMIO_HARDWARE="x86_amd64"
VOLUMIO_DEVICENAME="x86_64"
VOLUMIO_HASH="21a5161aef4cb85a1f93b140ccadc4f1"