-- Logs begin at Mon 2025-05-19 20:56:45 CST, end at Wed 2025-05-21 08:28:30 CST. -- May 21 08:27:00 volumio-zw ntpd[5191]: receive: Unexpected origin timestamp 0xebd79c54.4cab6070 does not match aorg 0000000000.00000000 from server@162.159.200.1 xmt 0xebd79c54.70bdd83c May 21 08:27:01 volumio-zw volumio[950]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats May 21 08:27:02 volumio-zw ntpd[5191]: receive: Unexpected origin timestamp 0xebd79c56.4cad490e does not match aorg 0000000000.00000000 from server@162.159.200.1 xmt 0xebd79c56.70776c4a May 21 08:27:05 volumio-zw volumio[950]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats May 21 08:27:09 volumio-zw volumio[950]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats May 21 08:27:14 volumio-zw volumio[950]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats May 21 08:27:18 volumio-zw volumio[950]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats May 21 08:27:19 volumio-zw nmbd[20512]: [2025/05/21 08:27:19.033655, 0] ../source3/libsmb/nmblib.c:917(send_udp) May 21 08:27:19 volumio-zw nmbd[20512]: Packet send failed to 192.168.211.255(138) ERRNO=Network is unreachable May 21 08:27:22 volumio-zw volumio[950]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats May 21 08:27:26 volumio-zw volumio[950]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats May 21 08:27:29 volumio-zw volumio[950]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats May 21 08:27:33 volumio-zw volumio[950]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats May 21 08:27:33 volumio-zw volumio[950]: info: CoreCommandRouter::executeOnPlugin: networkfs , addShare May 21 08:27:33 volumio-zw volumio[950]: info: Adding a new share May 21 08:27:33 volumio-zw volumio[950]: info: No correspondence found in configuration for share music1 on IP 192.168.31.250 May 21 08:27:33 volumio-zw sudo[11585]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t nfs -o ro,soft,noauto 192.168.31.250:/volume1/music /mnt/NAS/music1 May 21 08:27:33 volumio-zw sudo[11585]: pam_unix(sudo:session): session opened for user root by (uid=0) May 21 08:27:33 volumio-zw kernel: FS-Cache: Loaded May 21 08:27:33 volumio-zw kernel: Key type dns_resolver registered May 21 08:27:33 volumio-zw kernel: NFS: Registering the id_resolver key type May 21 08:27:33 volumio-zw kernel: Key type id_resolver registered May 21 08:27:33 volumio-zw kernel: Key type id_legacy registered May 21 08:27:34 volumio-zw systemd[1]: /lib/systemd/system/rpc-statd.service:13: PIDFile= references path below legacy directory /var/run/, updating /var/run/rpc.statd.pid → /run/rpc.statd.pid; please update the unit file accordingly. May 21 08:27:34 volumio-zw systemd[1]: Starting Preprocess NFS configuration... May 21 08:27:34 volumio-zw systemd[1]: nfs-config.service: Succeeded. May 21 08:27:34 volumio-zw systemd[1]: Started Preprocess NFS configuration. May 21 08:27:34 volumio-zw systemd[1]: Starting NFS status monitor for NFSv2/3 locking.... May 21 08:27:34 volumio-zw systemd[1]: Starting Notify NFS peers of a restart... May 21 08:27:34 volumio-zw sm-notify[11605]: Version 1.3.3 starting May 21 08:27:34 volumio-zw systemd[1]: rpc-statd-notify.service: Succeeded. May 21 08:27:34 volumio-zw systemd[1]: Started Notify NFS peers of a restart. May 21 08:27:34 volumio-zw rpc.statd[11606]: Version 1.3.3 starting May 21 08:27:34 volumio-zw rpc.statd[11606]: Flags: TI-RPC May 21 08:27:34 volumio-zw rpc.statd[11606]: Failed to read /var/lib/nfs/state: Success May 21 08:27:34 volumio-zw rpc.statd[11606]: Initializing NSM state May 21 08:27:34 volumio-zw systemd[1]: Started NFS status monitor for NFSv2/3 locking.. May 21 08:27:34 volumio-zw sudo[11585]: pam_unix(sudo:session): session closed for user root May 21 08:27:34 volumio-zw volumio[950]: verbose: ControllerMpd::sendMpdCommand status May 21 08:27:34 volumio-zw volumio[950]: info: May 21 08:27:34 volumio-zw volumio[950]: ---------------------------- MPD announces state update: update May 21 08:27:34 volumio-zw volumio[950]: info: ControllerMpd::getState May 21 08:27:34 volumio-zw volumio[950]: verbose: ControllerMpd::sendMpdCommand status May 21 08:27:34 volumio-zw volumio[950]: info: sendMpdCommand status took 4 milliseconds May 21 08:27:34 volumio-zw volumio[950]: info: sendMpdCommand status took 3 milliseconds May 21 08:27:34 volumio-zw volumio[950]: verbose: ControllerMpd::parseState May 21 08:27:34 volumio-zw volumio[950]: info: Command Router : Notfying DB Updatetrue May 21 08:27:34 volumio-zw volumio[950]: verbose: ControllerMpd::parseState May 21 08:27:34 volumio-zw volumio[950]: info: ControllerMpd::pushState May 21 08:27:34 volumio-zw volumio[950]: info: CoreCommandRouter::servicePushState May 21 08:27:34 volumio-zw volumio[950]: info: CoreStateMachine::pushState May 21 08:27:34 volumio-zw volumio[950]: info: CorePlayQueue::getTrack 0 May 21 08:27:34 volumio-zw volumio[950]: info: CoreCommandRouter::volumioPushState May 21 08:27:34 volumio-zw volumio[950]: info: CorePlayQueue::getTrack 0 May 21 08:27:34 volumio-zw volumio[950]: verbose: STATE SERVICE {"status":"stop","position":null,"seek":null,"duration":null,"samplerate":null,"bitdepth":null,"channels":null,"random":false,"updatedb":true,"repeat":false,"bitrate":null,"isStreaming":false,"title":null,"artist":null,"album":null,"uri":null} May 21 08:27:34 volumio-zw volumio[950]: verbose: CURRENT POSITION 0 May 21 08:27:34 volumio-zw volumio[950]: info: CoreStateMachine::syncState stateService stop May 21 08:27:34 volumio-zw volumio[950]: info: CoreStateMachine::syncState currentStatus stop May 21 08:27:34 volumio-zw volumio[950]: info: CoreStateMachine::pushState May 21 08:27:34 volumio-zw volumio[950]: info: CorePlayQueue::getTrack 0 May 21 08:27:34 volumio-zw volumio[950]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 21 08:27:34 volumio-zw volumio[950]: info: CoreCommandRouter::volumioPushState May 21 08:27:34 volumio-zw volumio[950]: info: No code May 21 08:27:34 volumio-zw volumio[950]: info: CoreStateMachine::pushState May 21 08:27:34 volumio-zw volumio[950]: info: CorePlayQueue::getTrack 0 May 21 08:27:34 volumio-zw volumio[950]: info: CoreCommandRouter::volumioPushState May 21 08:27:34 volumio-zw volumio[950]: info: ------------------------------ 145ms May 21 08:27:34 volumio-zw volumio[950]: info: [1747787254454] Database update started May 21 08:27:35 volumio-zw volumio[950]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares May 21 08:27:36 volumio-zw volumio[950]: info: CoreCommandRouter::Close All Modals sent May 21 08:27:37 volumio-zw volumio[950]: info: CoreCommandRouter::executeOnPlugin: networkfs , discoverShares May 21 08:27:37 volumio-zw volumio[950]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , browseForService May 21 08:27:37 volumio-zw volumio[950]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats May 21 08:27:38 volumio-zw volumio[950]: info: Executing SMB command: smbclient --no-pass --debuglevel=0 -L iStoreOS-2.local. May 21 08:27:38 volumio-zw volumio[950]: info: Executing SMB command: smbclient --no-pass --debuglevel=0 -L MYHQ.local. May 21 08:27:38 volumio-zw volumio[950]: info: Executing SMB command: smbclient --no-pass --debuglevel=0 -L volumio.local. May 21 08:27:38 volumio-zw volumio[950]: info: Executing SMB command: smbclient --no-pass --debuglevel=0 -L iStoreOS.local. May 21 08:27:38 volumio-zw volumio[950]: info: Executing SMB command: smbclient --no-pass --debuglevel=0 -L iStoreOS-3.local. May 21 08:27:38 volumio-zw volumio[950]: info: Error browsing device MYHQ for shares: Command failed: smbclient --no-pass --debuglevel=0 -L MYHQ.local. May 21 08:27:38 volumio-zw volumio[950]: Unable to initialize messaging context May 21 08:27:41 volumio-zw volumio[950]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats May 21 08:27:42 volumio-zw ntpd[5191]: receive: Unexpected origin timestamp 0xebd79c7e.4cac1c4a does not match aorg 0000000000.00000000 from server@162.159.200.1 xmt 0xebd79c7e.70127f04 May 21 08:27:45 volumio-zw volumio[950]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats May 21 08:27:49 volumio-zw volumio[950]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats May 21 08:27:53 volumio-zw volumio[950]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats May 21 08:27:57 volumio-zw volumio[950]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats May 21 08:27:59 volumio-zw nmbd[20512]: [2025/05/21 08:27:59.082706, 0] ../source3/nmbd/nmbd_namequery.c:109(query_name_response) May 21 08:27:59 volumio-zw nmbd[20512]: query_name_response: Multiple (2) responses received for a query on subnet 192.168.31.48 for name WORKGROUP<1d>. May 21 08:27:59 volumio-zw nmbd[20512]: This response was from IP 192.168.31.188, reporting an IP address of 192.168.31.188. May 21 08:28:02 volumio-zw volumio[950]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats May 21 08:28:04 volumio-zw nmbd[20512]: [2025/05/21 08:28:04.089675, 0] ../source3/libsmb/nmblib.c:917(send_udp) May 21 08:28:04 volumio-zw nmbd[20512]: Packet send failed to 192.168.211.255(138) ERRNO=Network is unreachable May 21 08:28:06 volumio-zw volumio[950]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats May 21 08:28:09 volumio-zw volumio[950]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats May 21 08:28:11 volumio-zw volumio[950]: info: CoreCommandRouter::executeOnPlugin: networkfs , addShare May 21 08:28:11 volumio-zw volumio[950]: info: Adding a new share May 21 08:28:11 volumio-zw volumio[950]: info: Checking key NasMounts.4199d075-e898-41b0-be7d-19da0a22fb0c May 21 08:28:11 volumio-zw volumio[950]: info: No correspondence found in configuration for share music2 on IP 192.168.31.250 May 21 08:28:11 volumio-zw sudo[11741]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/mount -t nfs -o ro,soft,noauto 192.168.31.250:/volume2/music2 /mnt/NAS/music2 May 21 08:28:11 volumio-zw sudo[11741]: pam_unix(sudo:session): session opened for user root by (uid=0) May 21 08:28:11 volumio-zw sudo[11741]: pam_unix(sudo:session): session closed for user root May 21 08:28:11 volumio-zw volumio[950]: info: [1747787291348] Database update started May 21 08:28:12 volumio-zw volumio[950]: info: CoreCommandRouter::executeOnPlugin: networkfs , listShares May 21 08:28:13 volumio-zw volumio[950]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats May 21 08:28:17 volumio-zw volumio[950]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats May 21 08:28:21 volumio-zw volumio[950]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats May 21 08:28:23 volumio-zw volumio[950]: info: CALLMETHOD: miscellanea my_music updateMusicLibraryBrowseSourcesVisibility [object Object] May 21 08:28:23 volumio-zw volumio[950]: info: CoreCommandRouter::executeOnPlugin: my_music , updateMusicLibraryBrowseSourcesVisibility May 21 08:28:23 volumio-zw volumio[950]: info: CoreCommandRouter::volumioUpdateToBrowseSources May 21 08:28:23 volumio-zw volumio[950]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 21 08:28:23 volumio-zw volumio[950]: Cannot find translation for source Volusonic May 21 08:28:25 volumio-zw volumio[950]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats May 21 08:28:25 volumio-zw volumio[950]: info: CALLMETHOD: miscellanea my_music updateMusicLibrarySupersearchSources [object Object] May 21 08:28:25 volumio-zw volumio[950]: info: CoreCommandRouter::executeOnPlugin: my_music , updateMusicLibrarySupersearchSources May 21 08:28:26 volumio-zw volumio[950]: info: CoreCommandRouter::volumioGetBrowseSources May 21 08:28:26 volumio-zw volumio[950]: info: CoreCommandRouter::updateGlobalSearchableBrowseSources May 21 08:28:29 volumio-zw volumio[950]: info: CoreCommandRouter::executeOnPlugin: mpd , getMyCollectionStats May 21 08:28:29 volumio-zw volumio[950]: info: Disabling MyMusic plugin upnp May 21 08:28:29 volumio-zw sudo[11791]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop upmpdcli.service May 21 08:28:29 volumio-zw sudo[11791]: pam_unix(sudo:session): session opened for user root by (uid=0) May 21 08:28:29 volumio-zw systemd[1]: Stopping UPnP Renderer front-end to MPD... May 21 08:28:29 volumio-zw volumio[950]: error: Upnp client error: Error: This socket has been ended by the other party May 21 08:28:30 volumio-zw volumio[950]: info: Enabling MyMusic plugin upnp May 21 08:28:30 volumio-zw volumio[950]: info: Enabling plugin upnp May 21 08:28:30 volumio-zw volumio[950]: info: Loading plugin "upnp"... May 21 08:28:30 volumio-zw volumio[950]: info: [1747787310536] Starting Upmpd Daemon May 21 08:28:30 volumio-zw volumio[950]: info: CoreCommandRouter::executeOnPlugin: system , registerCallback May 21 08:28:30 volumio-zw volumio[950]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 21 08:28:30 volumio-zw volumio[950]: Error: listen EADDRINUSE: address already in use :::6599 May 21 08:28:30 volumio-zw volumio[950]: at Server.setupListenHandle [as _listen2] (net.js:1331:16) May 21 08:28:30 volumio-zw volumio[950]: at listenInCluster (net.js:1379:12) May 21 08:28:30 volumio-zw volumio[950]: at Server.listen (net.js:1465:7) May 21 08:28:30 volumio-zw volumio[950]: at UpnpInterface.onVolumioStart (/volumio/app/plugins/audio_interface/upnp/index.js:78:17) May 21 08:28:30 volumio-zw volumio[950]: at PluginManager.loadCorePlugin (/volumio/app/pluginmanager.js:255:38) May 21 08:28:30 volumio-zw volumio[950]: at Promise._successFn (/volumio/app/pluginmanager.js:1855:19) May 21 08:28:30 volumio-zw volumio[950]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) May 21 08:28:30 volumio-zw volumio[950]: at processTicksAndRejections (internal/process/task_queues.js:77:11) { May 21 08:28:30 volumio-zw volumio[950]: code: 'EADDRINUSE', May 21 08:28:30 volumio-zw volumio[950]: errno: -98, May 21 08:28:30 volumio-zw volumio[950]: syscall: 'listen', May 21 08:28:30 volumio-zw volumio[950]: address: '::', May 21 08:28:30 volumio-zw volumio[950]: port: 6599 May 21 08:28:30 volumio-zw volumio[950]: } May 21 08:28:30 volumio-zw volumio[950]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 21 08:28:30 volumio-zw sudo[11802]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-05-21 08:27 May 21 08:28:30 volumio-zw sudo[11802]: 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="570c5791513f5bac7da274aba6690c1a961705de" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="35e4a13c94df42ebab19fd6178d6be47190c244d" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 13 May 2025 05:50:12 PM CEST" VOLUMIO_VERSION="3.812" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="39b0f8c200b2dcadf117e189b4b3632d"