-- Logs begin at Sat 2025-05-24 09:35:28 +07, end at Sat 2025-05-24 09:49:32 +07. -- May 24 09:48:36 volumio volumio[1602]: 100 May 24 09:48:36 volumio volumio[1602]: % Total % Received % Xferd Average Speed Time Time Time Current May 24 09:48:36 volumio volumio[1602]: Dload Upload Total Spent Left Speed May 24 09:48:36 volumio volumio[945]: info: May 24 09:48:36 volumio volumio[945]: ---------------------------- Client requests Volume 100 May 24 09:48:36 volumio volumio[945]: info: VolumeController::SetAlsaVolume100 May 24 09:48:36 volumio volumio[945]: info: CoreCommandRouter::volumioGetState May 24 09:48:36 volumio volumio[945]: info: CorePlayQueue::getTrack 0 May 24 09:48:36 volumio volumio[945]: info: CoreStateMachine::pushState May 24 09:48:36 volumio volumio[945]: info: CorePlayQueue::getTrack 0 May 24 09:48:36 volumio volumio[1602]: [158B blob data] May 24 09:48:36 volumio volumio[1602]: {"time":1748054916927,"response":"volume Success"}100 May 24 09:48:36 volumio volumio[945]: (node:945) UnhandledPromiseRejectionWarning: TypeError: Cannot read property 'name' of undefined May 24 09:48:36 volumio volumio[945]: at CoreStateMachine.getState (/volumio/app/statemachine.js:126:48) May 24 09:48:36 volumio volumio[945]: at CoreCommandRouter.volumioGetState (/volumio/app/index.js:109:28) May 24 09:48:36 volumio volumio[945]: at ControllerYTCR.isCurrentService (/data/plugins/music_service/ytcr/dist/index.js:486:95) May 24 09:48:36 volumio volumio[945]: at /data/plugins/music_service/ytcr/dist/index.js:283:22 May 24 09:48:36 volumio volumio[945]: at CoreCommandRouter.callCallback (/volumio/app/index.js:214:9) May 24 09:48:36 volumio volumio[945]: at CoreCommandRouter.volumioupdatevolume (/volumio/app/index.js:143:8) May 24 09:48:36 volumio volumio[945]: at Promise._successFn (/volumio/app/index.js:137:16) May 24 09:48:36 volumio volumio[945]: at nextTickCallback (/volumio/node_modules/kew/kew.js:47:28) May 24 09:48:36 volumio volumio[945]: at processTicksAndRejections (internal/process/task_queues.js:77:11) May 24 09:48:36 volumio volumio[945]: (Use `node --trace-warnings ...` to show where the warning was created) May 24 09:48:36 volumio volumio[945]: (node:945) UnhandledPromiseRejectionWarning: Unhandled promise rejection. This error originated either by throwing inside of an async function without a catch block, or by rejecting a promise which was not handled with .catch(). To terminate the node process on unhandled promise rejection, use the CLI flag `--unhandled-rejections=strict` (see https://nodejs.org/api/cli.html#cli_unhandled_rejections_mode). (rejection id: 1) May 24 09:48:36 volumio volumio[945]: (node:945) [DEP0018] DeprecationWarning: Unhandled promise rejections are deprecated. In the future, promise rejections that are not handled will terminate the Node.js process with a non-zero exit code. May 24 09:48:37 volumio volumio[945]: info: May 24 09:48:37 volumio volumio[945]: ---------------------------- MPD announces state update: player May 24 09:48:37 volumio volumio[945]: info: ControllerMpd::getState May 24 09:48:37 volumio volumio[945]: verbose: ControllerMpd::sendMpdCommand status May 24 09:48:37 volumio volumio[945]: info: sendMpdCommand status took 1 milliseconds May 24 09:48:37 volumio volumio[945]: verbose: ControllerMpd::parseState May 24 09:48:37 volumio volumio[945]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 24 09:48:37 volumio volumio[945]: info: sendMpdCommand playlistinfo took 1 milliseconds May 24 09:48:37 volumio volumio[945]: verbose: ControllerMpd::parseTrackInfo May 24 09:48:37 volumio volumio[945]: info: ControllerMpd::pushState May 24 09:48:37 volumio volumio[945]: info: CoreCommandRouter::servicePushState May 24 09:48:37 volumio volumio[945]: info: CoreStateMachine::pushState May 24 09:48:37 volumio volumio[945]: info: CorePlayQueue::getTrack 0 May 24 09:48:37 volumio volumio[945]: error: ControllerMpd::pushError: TypeError: Cannot read property 'name' of undefined May 24 09:48:37 volumio volumio[945]: info: ------------------------------ 7ms May 24 09:48:42 volumio volumio[945]: info: Clearing queue after UPNP request May 24 09:48:42 volumio volumio[945]: info: CoreStateMachine::ClearQueue May 24 09:48:42 volumio volumio[945]: info: CoreStateMachine::stop May 24 09:48:42 volumio volumio[945]: info: CoreStateMachine::setConsumeUpdateService undefined May 24 09:48:42 volumio volumio[945]: info: CoreStateMachine::stPlaybackTimer May 24 09:48:42 volumio volumio[945]: info: CoreStateMachine::updateTrackBlock May 24 09:48:42 volumio volumio[945]: info: CorePlayQueue::getTrackBlock May 24 09:48:42 volumio volumio[945]: info: CoreStateMachine::pushState May 24 09:48:42 volumio volumio[945]: info: CorePlayQueue::getTrack 0 May 24 09:48:42 volumio volumio[945]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 24 09:48:42 volumio volumio[945]: info: CoreCommandRouter::volumioPushState May 24 09:48:42 volumio volumio[945]: info: CoreStateMachine::serviceStop May 24 09:48:42 volumio volumio[945]: info: CorePlayQueue::getTrack 0 May 24 09:48:42 volumio volumio[945]: info: ControllerMpd::stop May 24 09:48:42 volumio volumio[945]: verbose: ControllerMpd::sendMpdCommand stop May 24 09:48:42 volumio volumio[945]: info: CorePlayQueue::clearPlayQueue May 24 09:48:42 volumio volumio[945]: info: CorePlayQueue::saveQueue May 24 09:48:42 volumio volumio[945]: info: CoreCommandRouter::volumioPushState May 24 09:48:42 volumio volumio[945]: info: CoreCommandRouter::volumioPushQueue May 24 09:48:42 volumio volumio[945]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 24 09:48:42 volumio volumio[945]: SPOTIFY: SPOTIFY VOLUME 88 May 24 09:48:42 volumio volumio[945]: SPOTIFY: VOLUMIO VOLUME 100 May 24 09:48:42 volumio volumio[945]: SPOTIFY: DELTA VOLUME ENOUGH: true May 24 09:48:42 volumio volumio[945]: info: Setting Spotify Volume from Volumio: 100 May 24 09:48:42 volumio volumio[945]: SPOTIFY: RECEIVED VOLUMIO VOLUME 100 May 24 09:48:42 volumio volumio[945]: info: May 24 09:48:42 volumio volumio[945]: ---------------------------- MPD announces system playlist update May 24 09:48:42 volumio volumio[945]: info: Ignoring MPD Status Update May 24 09:48:42 volumio volumio[945]: info: sendMpdCommand stop took 29 milliseconds May 24 09:48:42 volumio volumio[945]: error: updateQueue error: null May 24 09:48:42 volumio volumio[945]: info: ------------------------------ 2ms May 24 09:48:42 volumio volumio[945]: info: Starting UPNP Playback May 24 09:48:42 volumio volumio[945]: info: Preparing playback through UPNP May 24 09:48:42 volumio volumio[945]: info: CoreCommandRouter::volumioGetState May 24 09:48:42 volumio volumio[945]: info: CorePlayQueue::getTrack 0 May 24 09:48:42 volumio volumio[945]: info: CoreStateMachine::setConsumeUpdateService mpd May 24 09:48:43 volumio volumio[945]: info: May 24 09:48:43 volumio volumio[945]: ---------------------------- MPD announces system playlist update May 24 09:48:43 volumio volumio[945]: info: Ignoring MPD Status Update May 24 09:48:43 volumio volumio[945]: info: ------------------------------ 2ms May 24 09:48:44 volumio volumio[945]: SPOTIFY: SETTING SPOTIFY VOLUME 100 May 24 09:48:44 volumio volumio[945]: info: Sending Spotify command with payload to local API: /player/volume May 24 09:48:46 volumio volumio[945]: info: May 24 09:48:46 volumio volumio[945]: ---------------------------- MPD announces state update: player May 24 09:48:46 volumio volumio[945]: info: ControllerMpd::getState May 24 09:48:46 volumio volumio[945]: verbose: ControllerMpd::sendMpdCommand status May 24 09:48:46 volumio volumio[945]: info: May 24 09:48:46 volumio volumio[945]: ---------------------------- MPD announces state update: player May 24 09:48:46 volumio volumio[945]: info: sendMpdCommand status took 7 milliseconds May 24 09:48:46 volumio volumio[945]: info: ControllerMpd::getState May 24 09:48:46 volumio volumio[945]: verbose: ControllerMpd::sendMpdCommand status May 24 09:48:46 volumio volumio[945]: verbose: ControllerMpd::parseState May 24 09:48:46 volumio volumio[945]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 24 09:48:46 volumio volumio[945]: info: sendMpdCommand status took 1 milliseconds May 24 09:48:46 volumio volumio[945]: info: sendMpdCommand playlistinfo took 2 milliseconds May 24 09:48:46 volumio volumio[945]: verbose: ControllerMpd::parseState May 24 09:48:46 volumio volumio[945]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 24 09:48:46 volumio volumio[945]: verbose: ControllerMpd::parseTrackInfo May 24 09:48:46 volumio volumio[945]: info: ControllerMpd::pushState May 24 09:48:46 volumio volumio[945]: info: CoreCommandRouter::servicePushState May 24 09:48:46 volumio volumio[945]: verbose: In UPNP mode May 24 09:48:46 volumio volumio[945]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"48 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"AirMusic.LPCM","artist":null,"album":null,"uri":"http://192.168.1.44:39763/AirMusic.LPCM","trackType":"LPCM"} May 24 09:48:46 volumio volumio[945]: verbose: CURRENT POSITION 0 May 24 09:48:46 volumio volumio[945]: info: CoreStateMachine::syncState stateService play May 24 09:48:46 volumio volumio[945]: info: CoreStateMachine::syncState currentStatus stop May 24 09:48:46 volumio volumio[945]: info: ------------------------------ 13ms May 24 09:48:46 volumio volumio[945]: info: sendMpdCommand playlistinfo took 3 milliseconds May 24 09:48:46 volumio volumio[945]: verbose: ControllerMpd::parseTrackInfo May 24 09:48:46 volumio volumio[945]: info: ControllerMpd::pushState May 24 09:48:46 volumio volumio[945]: info: CoreCommandRouter::servicePushState May 24 09:48:46 volumio volumio[945]: verbose: In UPNP mode May 24 09:48:46 volumio volumio[945]: verbose: STATE SERVICE {"status":"play","position":0,"seek":0,"duration":0,"samplerate":"48 kHz","bitdepth":"16 bit","channels":2,"random":false,"updatedb":false,"repeat":false,"bitrate":null,"isStreaming":false,"title":"AirMusic.LPCM","artist":null,"album":null,"uri":"http://192.168.1.44:39763/AirMusic.LPCM","trackType":"LPCM"} May 24 09:48:46 volumio volumio[945]: verbose: CURRENT POSITION 0 May 24 09:48:46 volumio volumio[945]: info: CoreStateMachine::syncState stateService play May 24 09:48:46 volumio volumio[945]: info: CoreStateMachine::syncState currentStatus play May 24 09:48:46 volumio volumio[945]: info: Received an update from plugin. extracting info from payload May 24 09:48:46 volumio volumio[945]: info: CoreStateMachine::pushState May 24 09:48:46 volumio volumio[945]: info: CorePlayQueue::getTrack 0 May 24 09:48:46 volumio volumio[945]: error: ControllerMpd::pushError: TypeError: Cannot read property 'name' of undefined May 24 09:48:46 volumio volumio[945]: info: ------------------------------ 10ms May 24 09:49:29 volumio volumio[945]: info: May 24 09:49:29 volumio volumio[945]: ---------------------------- MPD announces state update: player May 24 09:49:29 volumio volumio[945]: info: ControllerMpd::getState May 24 09:49:29 volumio volumio[945]: verbose: ControllerMpd::sendMpdCommand status May 24 09:49:29 volumio volumio[945]: info: sendMpdCommand status took 1 milliseconds May 24 09:49:29 volumio volumio[945]: verbose: ControllerMpd::parseState May 24 09:49:29 volumio volumio[945]: verbose: ControllerMpd::sendMpdCommand playlistinfo May 24 09:49:29 volumio volumio[945]: info: sendMpdCommand playlistinfo took 1 milliseconds May 24 09:49:29 volumio volumio[945]: verbose: ControllerMpd::parseTrackInfo May 24 09:49:29 volumio volumio[945]: info: ControllerMpd::pushState May 24 09:49:29 volumio volumio[945]: info: CoreCommandRouter::servicePushState May 24 09:49:29 volumio volumio[945]: info: CoreStateMachine::pushState May 24 09:49:29 volumio volumio[945]: info: CorePlayQueue::getTrack 0 May 24 09:49:29 volumio volumio[945]: error: ControllerMpd::pushError: TypeError: Cannot read property 'name' of undefined May 24 09:49:29 volumio volumio[945]: info: ------------------------------ 6ms May 24 09:49:32 volumio volumio[945]: info: Airplay started streaming, receiving metadatas May 24 09:49:32 volumio volumio[945]: info: CorePlayQueue::getTrack 0 May 24 09:49:32 volumio volumio[945]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 24 09:49:32 volumio volumio[945]: TypeError: Cannot read property 'name' of undefined May 24 09:49:32 volumio volumio[945]: at CoreStateMachine.getState (/volumio/app/statemachine.js:126:48) May 24 09:49:32 volumio volumio[945]: at AirPlayInterface.prepareAirplayPlayback (/volumio/app/plugins/music_service/airplay_emulation/index.js:559:47) May 24 09:49:32 volumio volumio[945]: at ShairportSyncReaderUDP. (/volumio/app/plugins/music_service/airplay_emulation/index.js:266:12) May 24 09:49:32 volumio volumio[945]: at ShairportSyncReaderUDP.emit (events.js:412:35) May 24 09:49:32 volumio volumio[945]: at ShairportSyncReaderUDP.useData (/volumio/app/plugins/music_service/airplay_emulation/shairport-sync-reader/shairport-sync-reader-base.js:86:16) May 24 09:49:32 volumio volumio[945]: at Socket. (/volumio/app/plugins/music_service/airplay_emulation/shairport-sync-reader/shairport-sync-reader-udp.js:21:12) May 24 09:49:32 volumio volumio[945]: at Socket.emit (events.js:400:28) May 24 09:49:32 volumio volumio[945]: at UDP.onMessage [as onmessage] (dgram.js:931:8) May 24 09:49:32 volumio volumio[945]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 24 09:49:32 volumio shairport-sync[1708]: % Total % Received % Xferd Average Speed Time Time Time Current May 24 09:49:32 volumio shairport-sync[1708]: Dload Upload Total Spent Left Speed May 24 09:49:32 volumio sudo[5354]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-05-24 09:48 May 24 09:49:32 volumio sudo[5354]: 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="147953990fca4aa103a8f90538ef56fb0454638c" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="9ab87de061b3649c303da550e73c92d340b0f989" VOLUMIO_ARCH="x64" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu 24 Apr 2025 10:07:11 AM CEST" VOLUMIO_VERSION="3.804" VOLUMIO_HARDWARE="x86_amd64" VOLUMIO_DEVICENAME="x86_64" VOLUMIO_HASH="dc77d77f02ef88ea816c3d31de871e8f"