-- Logs begin at Thu 2019-02-14 10:11:59 GMT, end at Sun 2025-05-25 17:35:38 BST. -- May 25 17:34:02 audio-server volumiologrotate[582]: ls: cannot access '/var/log/samba/log.wb-AUDIO': No such file or directory May 25 17:34:02 audio-server volumiologrotate[582]: ls: cannot access 'SERVER': No such file or directory May 25 17:34:05 audio-server go-librespot[6940]: time="2025-05-25T17:34:05+01:00" level=trace msg="received accesspoint ping" May 25 17:34:05 audio-server go-librespot[6940]: time="2025-05-25T17:34:05+01:00" level=trace msg="received accesspoint pong ack" May 25 17:34:05 audio-server go-librespot[6940]: time="2025-05-25T17:34:05+01:00" level=trace msg="sent dealer ping" May 25 17:34:05 audio-server go-librespot[6940]: time="2025-05-25T17:34:05+01:00" level=trace msg="received dealer pong" May 25 17:34:07 audio-server volumio[6762]: error: [ytcr] Failed to obtain manual pairing code: timeout. May 25 17:34:07 audio-server volumio[6762]: info: CoreCommandRouter::getUIConfigOnPlugin May 25 17:34:07 audio-server volumio[6762]: (node:6762) UnhandledPromiseRejectionWarning: ConnectionError: (YouTube) Connection error in sending message 'autoplayUpNext' May 25 17:34:07 audio-server volumio[6762]: at Session._Session_doSendMessage (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/cjs/lib/app/Session.js:505:16) May 25 17:34:07 audio-server volumio[6762]: at runMicrotasks () May 25 17:34:07 audio-server volumio[6762]: at processTicksAndRejections (internal/process/task_queues.js:93:5) May 25 17:34:07 audio-server volumio[6762]: at async SendMessageTask.run (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/cjs/lib/app/Session.js:552:9) May 25 17:34:07 audio-server volumio[6762]: at async AsyncTaskQueue.start (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/cjs/lib/utils/AsyncTaskQueue.js:51:25) May 25 17:34:07 audio-server volumio[6762]: (node:6762) 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: 4) May 25 17:34:07 audio-server volumio[6762]: (node:6762) UnhandledPromiseRejectionWarning: BadResponseError: (YouTube) Bad response received for messages 'onHasPreviousNextChanged + onAutoplayModeChanged' May 25 17:34:07 audio-server volumio[6762]: at Session._Session_doSendMessage (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/cjs/lib/app/Session.js:511:12) May 25 17:34:07 audio-server volumio[6762]: at runMicrotasks () May 25 17:34:07 audio-server volumio[6762]: at processTicksAndRejections (internal/process/task_queues.js:93:5) May 25 17:34:07 audio-server volumio[6762]: at async SendMessageTask.run (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/cjs/lib/app/Session.js:552:9) May 25 17:34:07 audio-server volumio[6762]: at async AsyncTaskQueue.start (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/cjs/lib/utils/AsyncTaskQueue.js:51:25) May 25 17:34:07 audio-server volumio[6762]: (node:6762) 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: 5) May 25 17:34:08 audio-server volumio[6762]: [YOUTUBEJS][Player]: Failed to extract signature decipher algorithm. May 25 17:34:18 audio-server volumio-remote-updater[585]: [2025-05-25 17:34:18] [disconnect] Disconnect close local:[1008,Pong timeout] remote:[1006] May 25 17:34:23 audio-server volumio-remote-updater[585]: [2025-05-25 17:34:23] [connect] Successful connection May 25 17:34:24 audio-server volumio[6762]: info: [ytcr] InnertubeLoader: going to refresh po_token in 43100 seconds May 25 17:34:24 audio-server volumio[6762]: info: CoreCommandRouter::volumioGetState May 25 17:34:24 audio-server volumio[6762]: info: CoreCommandRouter::servicePushState May 25 17:34:24 audio-server volumio[6762]: info: CoreStateMachine::pushState May 25 17:34:24 audio-server volumio[6762]: info: CoreCommandRouter::volumioPushState May 25 17:34:24 audio-server volumio[6762]: info: CoreCommandRouter::volumioGetState May 25 17:34:24 audio-server volumio[6762]: info: CoreCommandRouter::servicePushState May 25 17:34:24 audio-server volumio[6762]: info: CoreStateMachine::pushState May 25 17:34:24 audio-server volumio[6762]: info: CoreCommandRouter::volumioPushState May 25 17:34:24 audio-server volumio[6762]: info: CoreCommandRouter::volumioGetState May 25 17:34:24 audio-server volumio[6762]: info: CoreCommandRouter::servicePushState May 25 17:34:24 audio-server volumio[6762]: info: CoreStateMachine::pushState May 25 17:34:24 audio-server volumio[6762]: info: CoreCommandRouter::volumioPushState May 25 17:34:24 audio-server volumio[6762]: SPOTIFY: RECEIVED VOLUMIO VOLUME 58 May 25 17:34:24 audio-server volumio[6762]: SPOTIFY: RECEIVED VOLUMIO VOLUME 58 May 25 17:34:24 audio-server volumio[6762]: SPOTIFY: RECEIVED VOLUMIO VOLUME 58 May 25 17:34:24 audio-server volumio[6762]: info: [ASDebug] CurState: pause PrevState: pause May 25 17:34:24 audio-server volumio[6762]: info: [ASDebug] CurState: pause PrevState: pause May 25 17:34:24 audio-server volumio[6762]: info: [ASDebug] CurState: pause PrevState: pause May 25 17:34:24 audio-server volumio[6762]: info: [ASDebug] CurState: pause PrevState: pause May 25 17:34:24 audio-server volumio[6762]: info: [ASDebug] CurState: pause PrevState: pause May 25 17:34:24 audio-server volumio[6762]: info: [ASDebug] CurState: pause PrevState: pause May 25 17:34:24 audio-server volumio[6762]: warn: [yt-cast-receiver] DefaultPlaylistRequestHandler failed to mark video xVrfpsYzfMI as watched: May 25 17:34:24 audio-server volumio[6762]: (FetchError) request to https://s.youtube.com/api/stats/playback?cl=761628139&docid=xVrfpsYzfMI&ei=f0YzaOX3L7eip-oPlPWKwQs&fexp=&ns=yt&plid=AAY1-GZ8C9iFlYQ-&el=detailpage&len=181&list=RQ0M_dhlvBJ6FNO03c-I70WbdM0ag&of=sidReqaeP4yRcfYsI6hTkw&uga=m16&vm=CAIQABgEOjJBSHFpSlRMRnlyb2pzSmlPd3hmdFFnRFNKUkx1djI3UTU0dm5hdXpnYnZXaVdjQTYtd2JYQUZVQTZSVFVUY2xRM3VyaTg0U0VOR0VSSVQzV05lVVg2UFNoMS1BSElJSTAtMnl2YTJiWDNqaXhRQWZKQVdYUDI1Rm9xTHV3N0tURm9PMlBpZ2pLS1ZxYrgBAQ&ver=2&c=TVHTML5&cbrver=7.20230405.08.01&cver=7.20230405.08.01&cpn=KUpVQcNzCr74kfAJ&fmt=251&rtn=0&rt=0&ctheme=CLASSIC&cplayer=UNIPLAYER&ctrl=mdx-pair&referrer=https%3A%2F%2Fwww.youtube.com%2Ftv%23%2Fwatch%3Fv%3DxVrfpsYzfMI%26list%3DRQ0M_dhlvBJ6FNO03c-I70WbdM0ag&ctt=APmki7S9WmVLl_MfhP_jxocWB1clyNVwo33214m8h9FraQ5Qp4zt0VAJUIwp5nJFKYO5Un_Rk_RCUJYs4_HTHB4SW5BxTLqBwQ1hNx_ydsh674RmmyPsp7gXYMN-4h3yO3YgPdjmg58i&cttype=vvt&prettyPrint=false&alt=json failed, reason: Client network socket disconnected before secure TLS connection was established May 25 17:34:24 audio-server volumio[6762]: FetchError: request to https://s.youtube.com/api/stats/playback?cl=761628139&docid=xVrfpsYzfMI&ei=f0YzaOX3L7eip-oPlPWKwQs&fexp=&ns=yt&plid=AAY1-GZ8C9iFlYQ-&el=detailpage&len=181&list=RQ0M_dhlvBJ6FNO03c-I70WbdM0ag&of=sidReqaeP4yRcfYsI6hTkw&uga=m16&vm=CAIQABgEOjJBSHFpSlRMRnlyb2pzSmlPd3hmdFFnRFNKUkx1djI3UTU0dm5hdXpnYnZXaVdjQTYtd2JYQUZVQTZSVFVUY2xRM3VyaTg0U0VOR0VSSVQzV05lVVg2UFNoMS1BSElJSTAtMnl2YTJiWDNqaXhRQWZKQVdYUDI1Rm9xTHV3N0tURm9PMlBpZ2pLS1ZxYrgBAQ&ver=2&c=TVHTML5&cbrver=7.20230405.08.01&cver=7.20230405.08.01&cpn=KUpVQcNzCr74kfAJ&fmt=251&rtn=0&rt=0&ctheme=CLASSIC&cplayer=UNIPLAYER&ctrl=mdx-pair&referrer=https%3A%2F%2Fwww.youtube.com%2Ftv%23%2Fwatch%3Fv%3DxVrfpsYzfMI%26list%3DRQ0M_dhlvBJ6FNO03c-I70WbdM0ag&ctt=APmki7S9WmVLl_MfhP_jxocWB1clyNVwo33214m8h9FraQ5Qp4zt0VAJUIwp5nJFKYO5Un_Rk_RCUJYs4_HTHB4SW5BxTLqBwQ1hNx_ydsh674RmmyPsp7gXYMN-4h3yO3YgPdjmg58i&cttype=vvt&prettyPrint=false&alt=json failed, reason: Client network socket disconnected before secure TLS connection was established May 25 17:34:24 audio-server volumio[6762]: at ClientRequest. (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/node_modules/youtubei.js/bundle/node.cjs:2818:18) May 25 17:34:24 audio-server volumio[6762]: at ClientRequest.emit (events.js:315:20) May 25 17:34:24 audio-server volumio[6762]: at TLSSocket.socketErrorListener (_http_client.js:469:9) May 25 17:34:24 audio-server volumio[6762]: at TLSSocket.emit (events.js:315:20) May 25 17:34:24 audio-server volumio[6762]: at emitErrorNT (internal/streams/destroy.js:106:8) May 25 17:34:24 audio-server volumio[6762]: at emitErrorCloseNT (internal/streams/destroy.js:74:3) May 25 17:34:24 audio-server volumio[6762]: at processTicksAndRejections (internal/process/task_queues.js:80:21) May 25 17:34:24 audio-server volumio[6762]: error: [yt-cast-receiver] RPC connection error: May 25 17:34:24 audio-server volumio[6762]: (FetchError) request to https://www.youtube.com/api/lounge/bc/bind?AID=6&CI=0&RID=rpc&SID=E256E891971FF080&TYPE=xmlhttp&VER=8&app=ytcr&capabilities=dsp%2Cmic%2Cdpa%2Cntb&cst=m&device=LOUNGE_SCREEN&gsessionid=Xko-D5VtbcJ6Cyus6iOYWN4XqBQh1zee&id=1e1a0fbd-446f-4d48-bcdd-1ecdb642668a&loungeIdToken=AGdO5p-K4H5HqNh4lPZhAcHiOVhSqJU9Otnoc_P39WXABTuiZW5PHdinTqOoWnfeGvLCtVCdWEHrJUGsvvygRT1ZQk7iI21f4N99RowK2qjVDfWxDoV9Nps&mdxVersion=2&name=YouTube%20on%20Audio%20Server&obfuscatedGaiaId=&t=1&theme=cl&v=2&zx=03e547fd8f1e failed, reason: Client network socket disconnected before secure TLS connection was established May 25 17:34:24 audio-server volumio[6762]: FetchError: request to https://www.youtube.com/api/lounge/bc/bind?AID=6&CI=0&RID=rpc&SID=E256E891971FF080&TYPE=xmlhttp&VER=8&app=ytcr&capabilities=dsp%2Cmic%2Cdpa%2Cntb&cst=m&device=LOUNGE_SCREEN&gsessionid=Xko-D5VtbcJ6Cyus6iOYWN4XqBQh1zee&id=1e1a0fbd-446f-4d48-bcdd-1ecdb642668a&loungeIdToken=AGdO5p-K4H5HqNh4lPZhAcHiOVhSqJU9Otnoc_P39WXABTuiZW5PHdinTqOoWnfeGvLCtVCdWEHrJUGsvvygRT1ZQk7iI21f4N99RowK2qjVDfWxDoV9Nps&mdxVersion=2&name=YouTube%20on%20Audio%20Server&obfuscatedGaiaId=&t=1&theme=cl&v=2&zx=03e547fd8f1e failed, reason: Client network socket disconnected before secure TLS connection was established May 25 17:34:24 audio-server volumio[6762]: at ClientRequest. (/data/plugins/music_service/ytcr/node_modules/node-fetch/lib/index.js:1501:11) May 25 17:34:24 audio-server volumio[6762]: at ClientRequest.emit (events.js:315:20) May 25 17:34:24 audio-server volumio[6762]: at TLSSocket.socketErrorListener (_http_client.js:469:9) May 25 17:34:24 audio-server volumio[6762]: at TLSSocket.emit (events.js:315:20) May 25 17:34:24 audio-server volumio[6762]: at emitErrorNT (internal/streams/destroy.js:106:8) May 25 17:34:24 audio-server volumio[6762]: at emitErrorCloseNT (internal/streams/destroy.js:74:3) May 25 17:34:24 audio-server volumio[6762]: at processTicksAndRejections (internal/process/task_queues.js:80:21) May 25 17:34:24 audio-server volumio[6762]: error: [yt-cast-receiver] Retrying 1 / 3 May 25 17:34:25 audio-server volumio[6762]: verbose: New Socket.io Connection to 192.168.40.22 from 192.168.40.50 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/136.0.0.0 Safari/537.36 Edg/136.0.0.0 Engine version: 3 Transport: polling Total Clients: 2 May 25 17:34:25 audio-server volumio[6762]: verbose: New Socket.io Connection to 192.168.40.22:3000 from 192.168.40.168 UA: Dart/3.5 (dart:io) Engine version: 3 Transport: websocket Total Clients: 3 May 25 17:34:25 audio-server volumio[6762]: verbose: New Socket.io Connection to 192.168.40.22 from 192.168.40.50 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/136.0.0.0 Safari/537.36 Edg/136.0.0.0 Engine version: 3 Transport: polling Total Clients: 4 May 25 17:34:25 audio-server volumio-remote-updater[585]: [2025-05-25 17:34:25] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1748190863 101 May 25 17:34:25 audio-server volumio[6762]: verbose: New Socket.io Connection to 127.0.0.1:3000 from 127.0.0.1 UA: WebSocket++/0.8.2 Engine version: 4 Transport: websocket Total Clients: 5 May 25 17:34:25 audio-server volumio[6762]: (node:6762) UnhandledPromiseRejectionWarning: BadResponseError: (YouTube) Bad response received for messages 'onStateChange + nowPlaying + onHasPreviousNextChanged + autoplayUpNext' (AID: 13) May 25 17:34:25 audio-server volumio[6762]: at Session._Session_doSendMessage (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/cjs/lib/app/Session.js:511:12) May 25 17:34:25 audio-server volumio[6762]: at runMicrotasks () May 25 17:34:25 audio-server volumio[6762]: at processTicksAndRejections (internal/process/task_queues.js:93:5) May 25 17:34:25 audio-server volumio[6762]: at async SendMessageTask.run (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/cjs/lib/app/Session.js:552:9) May 25 17:34:25 audio-server volumio[6762]: at async AsyncTaskQueue.start (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/cjs/lib/utils/AsyncTaskQueue.js:51:25) May 25 17:34:25 audio-server volumio[6762]: (node:6762) 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: 6) May 25 17:34:25 audio-server volumio[6762]: error: [yt-cast-receiver] (YouTube) RPC connection terminated due to error: May 25 17:34:25 audio-server volumio[6762]: (BadResponseError) RPC connection request returned bad response May 25 17:34:25 audio-server volumio[6762]: Error info: { May 25 17:34:25 audio-server volumio[6762]: url: 'https://www.youtube.com/api/lounge/bc/bind?AID=13&CI=0&RID=rpc&SID=E256E891971FF080&TYPE=xmlhttp&VER=8&app=ytcr&capabilities=dsp%2Cmic%2Cdpa%2Cntb&cst=m&device=LOUNGE_SCREEN&gsessionid=Xko-D5VtbcJ6Cyus6iOYWN4XqBQh1zee&id=1e1a0fbd-446f-4d48-bcdd-1ecdb642668a&loungeIdToken=AGdO5p-K4H5HqNh4lPZhAcHiOVhSqJU9Otnoc_P39WXABTuiZW5PHdinTqOoWnfeGvLCtVCdWEHrJUGsvvygRT1ZQk7iI21f4N99RowK2qjVDfWxDoV9Nps&mdxVersion=2&name=YouTube%20on%20Audio%20Server&obfuscatedGaiaId=&t=1&theme=cl&v=2&zx=6e56c19cec5d', May 25 17:34:25 audio-server volumio[6762]: response: Response { May 25 17:34:25 audio-server volumio[6762]: size: 0, May 25 17:34:25 audio-server volumio[6762]: timeout: 0, May 25 17:34:25 audio-server volumio[6762]: [Symbol(Body internals)]: { May 25 17:34:25 audio-server volumio[6762]: body: Gunzip { May 25 17:34:25 audio-server volumio[6762]: _writeState: Uint32Array(2) [ 0, 0 ], May 25 17:34:25 audio-server volumio[6762]: _readableState: ReadableState { May 25 17:34:25 audio-server volumio[6762]: objectMode: false, May 25 17:34:25 audio-server volumio[6762]: highWaterMark: 16384, May 25 17:34:25 audio-server volumio[6762]: buffer: BufferList { head: null, tail: null, length: 0 }, May 25 17:34:25 audio-server volumio[6762]: length: 0, May 25 17:34:25 audio-server volumio[6762]: pipes: [], May 25 17:34:25 audio-server volumio[6762]: flowing: null, May 25 17:34:25 audio-server volumio[6762]: ended: false, May 25 17:34:25 audio-server volumio[6762]: endEmitted: false, May 25 17:34:25 audio-server volumio[6762]: reading: false, May 25 17:34:25 audio-server volumio[6762]: sync: false, May 25 17:34:25 audio-server volumio[6762]: needReadable: false, May 25 17:34:25 audio-server volumio[6762]: emittedReadable: false, May 25 17:34:25 audio-server volumio[6762]: readableListening: false, May 25 17:34:25 audio-server volumio[6762]: resumeScheduled: false, May 25 17:34:25 audio-server volumio[6762]: errorEmitted: false, May 25 17:34:25 audio-server volumio[6762]: emitClose: true, May 25 17:34:25 audio-server volumio[6762]: autoDestroy: true, May 25 17:34:25 audio-server volumio[6762]: destroyed: false, May 25 17:34:25 audio-server volumio[6762]: errored: null, May 25 17:34:25 audio-server volumio[6762]: closed: false, May 25 17:34:25 audio-server volumio[6762]: closeEmitted: false, May 25 17:34:25 audio-server volumio[6762]: defaultEncoding: 'utf8', May 25 17:34:25 audio-server volumio[6762]: awaitDrainWriters: null, May 25 17:34:25 audio-server volumio[6762]: multiAwaitDrain: false, May 25 17:34:25 audio-server volumio[6762]: readingMore: false, May 25 17:34:25 audio-server volumio[6762]: decoder: null, May 25 17:34:25 audio-server volumio[6762]: encoding: null, May 25 17:34:25 audio-server volumio[6762]: [Symbol(kPaused)]: null May 25 17:34:25 audio-server volumio[6762]: }, May 25 17:34:25 audio-server volumio[6762]: _events: [Object: null prototype] { May 25 17:34:25 audio-server volumio[6762]: prefinish: [Function: prefinish], May 25 17:34:25 audio-server volumio[6762]: unpipe: [Function: onunpipe], May 25 17:34:25 audio-server volumio[6762]: error: [ [Function: onerror], [Function (anonymous)] ], May 25 17:34:25 audio-server volumio[6762]: close: [Function: bound onceWrapper] { May 25 17:34:25 audio-server volumio[6762]: listener: [Function: onclose] May 25 17:34:25 audio-server volumio[6762]: }, May 25 17:34:25 audio-server volumio[6762]: finish: [Function: bound onceWrapper] { May 25 17:34:25 audio-server volumio[6762]: listener: [Function: onfinish] May 25 17:34:25 audio-server volumio[6762]: } May 25 17:34:25 audio-server volumio[6762]: }, May 25 17:34:25 audio-server volumio[6762]: _eventsCount: 5, May 25 17:34:25 audio-server volumio[6762]: _maxListeners: undefined, May 25 17:34:25 audio-server volumio[6762]: _writableState: WritableState { May 25 17:34:25 audio-server volumio[6762]: objectMode: false, May 25 17:34:25 audio-server volumio[6762]: highWaterMark: 16384, May 25 17:34:25 audio-server volumio[6762]: finalCalled: false, May 25 17:34:25 audio-server volumio[6762]: needDrain: false, May 25 17:34:25 audio-server volumio[6762]: ending: false, May 25 17:34:25 audio-server volumio[6762]: ended: false, May 25 17:34:25 audio-server volumio[6762]: finished: false, May 25 17:34:25 audio-server volumio[6762]: destroyed: false, May 25 17:34:25 audio-server volumio[6762]: decodeStrings: true, May 25 17:34:25 audio-server volumio[6762]: defaultEncoding: 'utf8', May 25 17:34:25 audio-server volumio[6762]: length: 0, May 25 17:34:25 audio-server volumio[6762]: writing: false, May 25 17:34:25 audio-server volumio[6762]: corked: 0, May 25 17:34:25 audio-server volumio[6762]: sync: true, May 25 17:34:25 audio-server volumio[6762]: bufferProcessing: false, May 25 17:34:25 audio-server volumio[6762]: onwrite: [Function: bound onwrite], May 25 17:34:25 audio-server volumio[6762]: writecb: null, May 25 17:34:25 audio-server volumio[6762]: writelen: 0, May 25 17:34:25 audio-server volumio[6762]: afterWriteTickInfo: null, May 25 17:34:25 audio-server volumio[6762]: buffered: [], May 25 17:34:25 audio-server volumio[6762]: bufferedIndex: 0, May 25 17:34:25 audio-server volumio[6762]: allBuffers: true, May 25 17:34:25 audio-server volumio[6762]: allNoop: true, May 25 17:34:25 audio-server volumio[6762]: pendingcb: 0, May 25 17:34:25 audio-server volumio[6762]: prefinished: false, May 25 17:34:25 audio-server volumio[6762]: errorEmitted: false, May 25 17:34:25 audio-server volumio[6762]: emitClose: true, May 25 17:34:25 audio-server volumio[6762]: autoDestroy: true, May 25 17:34:25 audio-server volumio[6762]: errored: null, May 25 17:34:25 audio-server volumio[6762]: closed: false May 25 17:34:25 audio-server volumio[6762]: }, May 25 17:34:25 audio-server volumio[6762]: allowHalfOpen: true, May 25 17:34:25 audio-server volumio[6762]: bytesWritten: 0, May 25 17:34:25 audio-server volumio[6762]: _handle: Zlib { May 25 17:34:25 audio-server volumio[6762]: onerror: [Function: zlibOnError], May 25 17:34:25 audio-server volumio[6762]: [Symbol(owner_symbol)]: [Circular *1] May 25 17:34:25 audio-server volumio[6762]: }, May 25 17:34:25 audio-server volumio[6762]: _outBuffer: , May 25 17:34:25 audio-server volumio[6762]: _outOffset: 0, May 25 17:34:25 audio-server volumio[6762]: _chunkSize: 16384, May 25 17:34:25 audio-server volumio[6762]: _defaultFlushFlag: 2, May 25 17:34:25 audio-server volumio[6762]: _finishFlushFlag: 2, May 25 17:34:25 audio-server volumio[6762]: _defaultFullFlushFlag: 3, May 25 17:34:25 audio-server volumio[6762]: _info: undefined, May 25 17:34:25 audio-server volumio[6762]: _maxOutputLength: 1073741823, May 25 17:34:25 audio-server volumio[6762]: _level: -1, May 25 17:34:25 audio-server volumio[6762]: _strategy: 0, May 25 17:34:25 audio-server volumio[6762]: [Symbol(kCapture)]: false, May 25 17:34:25 audio-server volumio[6762]: [Symbol(kTransformState)]: { May 25 17:34:25 audio-server volumio[6762]: afterTransform: [Function: bound afterTransform], May 25 17:34:25 audio-server volumio[6762]: needTransform: false, May 25 17:34:25 audio-server volumio[6762]: transforming: false, May 25 17:34:25 audio-server volumio[6762]: writecb: null, May 25 17:34:25 audio-server volumio[6762]: writechunk: null, May 25 17:34:25 audio-server volumio[6762]: writeencoding: null May 25 17:34:25 audio-server volumio[6762]: }, May 25 17:34:25 audio-server volumio[6762]: [Symbol(kError)]: null May 25 17:34:25 audio-server volumio[6762]: }, May 25 17:34:25 audio-server volumio[6762]: disturbed: false, May 25 17:34:25 audio-server volumio[6762]: error: null May 25 17:34:25 audio-server volumio[6762]: }, May 25 17:34:25 audio-server volumio[6762]: [Symbol(Response internals)]: { May 25 17:34:25 audio-server volumio[6762]: url: 'https://www.youtube.com/api/lounge/bc/bind?AID=13&CI=0&RID=rpc&SID=E256E891971FF080&TYPE=xmlhttp&VER=8&app=ytcr&capabilities=dsp%2Cmic%2Cdpa%2Cntb&cst=m&device=LOUNGE_SCREEN&gsessionid=Xko-D5VtbcJ6Cyus6iOYWN4XqBQh1zee&id=1e1a0fbd-446f-4d48-bcdd-1ecdb642668a&loungeIdToken=AGdO5p-K4H5HqNh4lPZhAcHiOVhSqJU9Otnoc_P39WXABTuiZW5PHdinTqOoWnfeGvLCtVCdWEHrJUGsvvygRT1ZQk7iI21f4N99RowK2qjVDfWxDoV9Nps&mdxVersion=2&name=YouTube%20on%20Audio%20Server&obfuscatedGaiaId=&t=1&theme=cl&v=2&zx=6e56c19cec5d', May 25 17:34:25 audio-server volumio[6762]: status: 400, May 25 17:34:25 audio-server volumio[6762]: statusText: 'Unknown SID', May 25 17:34:25 audio-server volumio[6762]: headers: Headers { May 25 17:34:25 audio-server volumio[6762]: [Symbol(map)]: [Object: null prototype] { May 25 17:34:25 audio-server volumio[6762]: 'cache-control': [ 'no-cache, no-store, max-age=0, must-revalidate' ], May 25 17:34:25 audio-server volumio[6762]: pragma: [ 'no-cache' ], May 25 17:34:25 audio-server volumio[6762]: expires: [ 'Mon, 01 Jan 1990 00:00:00 GMT' ], May 25 17:34:25 audio-server volumio[6762]: date: [ 'Sun, 25 May 2025 16:34:25 GMT' ], May 25 17:34:25 audio-server volumio[6762]: 'content-type': [ 'text/html; charset=UTF-8' ], May 25 17:34:25 audio-server volumio[6762]: 'content-encoding': [ 'gzip' ], May 25 17:34:25 audio-server volumio[6762]: 'x-content-type-options': [ 'nosniff' ], May 25 17:34:25 audio-server volumio[6762]: 'x-xss-protection': [ '1; mode=block' ], May 25 17:34:25 audio-server volumio[6762]: server: [ 'GSE' ], May 25 17:34:25 audio-server volumio[6762]: 'alt-svc': [ 'h3=":443"; ma=2592000,h3-29=":443"; ma=2592000' ], May 25 17:34:25 audio-server volumio[6762]: connection: [ 'close' ], May 25 17:34:25 audio-server volumio[6762]: 'transfer-encoding': [ 'chunked' ] May 25 17:34:25 audio-server volumio[6762]: } May 25 17:34:25 audio-server volumio[6762]: }, May 25 17:34:25 audio-server volumio[6762]: counter: 0 May 25 17:34:25 audio-server volumio[6762]: } May 25 17:34:25 audio-server volumio[6762]: } May 25 17:34:25 audio-server volumio[6762]: } May 25 17:34:25 audio-server volumio[6762]: Stack trace: May 25 17:34:25 audio-server volumio[6762]: BadResponseError: RPC connection request returned bad response May 25 17:34:25 audio-server volumio[6762]: at RPCConnection._RPCConnection_doConnect (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/cjs/lib/app/RPCConnection.js:129:11) May 25 17:34:25 audio-server volumio[6762]: at runMicrotasks () May 25 17:34:25 audio-server volumio[6762]: at processTicksAndRejections (internal/process/task_queues.js:93:5) May 25 17:34:25 audio-server volumio[6762]: at async RPCConnection._RPCConnection_handleDisconnect (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/cjs/lib/app/RPCConnection.js:145:13) May 25 17:34:25 audio-server volumio[6762]: (node:6762) UnhandledPromiseRejectionWarning: BadResponseError: (YouTube) Bad response received for messages 'onStateChange + nowPlaying + onHasPreviousNextChanged + autoplayUpNext' (AID: 10) May 25 17:34:25 audio-server volumio[6762]: at Session._Session_doSendMessage (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/cjs/lib/app/Session.js:511:12) May 25 17:34:25 audio-server volumio[6762]: at runMicrotasks () May 25 17:34:25 audio-server volumio[6762]: at processTicksAndRejections (internal/process/task_queues.js:93:5) May 25 17:34:25 audio-server volumio[6762]: at async SendMessageTask.run (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/cjs/lib/app/Session.js:552:9) May 25 17:34:25 audio-server volumio[6762]: at async AsyncTaskQueue.start (/data/plugins/music_service/ytcr/node_modules/yt-cast-receiver/dist/cjs/lib/utils/AsyncTaskQueue.js:51:25) May 25 17:34:25 audio-server volumio[6762]: (node:6762) 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: 7) May 25 17:34:26 audio-server volumio[6762]: info: [yt-cast-receiver] Player.play(): xVrfpsYzfMI @ 0s May 25 17:34:26 audio-server volumio[6762]: info: CoreCommandRouter::volumioGetState May 25 17:34:26 audio-server volumio[6762]: info: CoreCommandRouter::volumioGetState May 25 17:34:26 audio-server volumio[6762]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 5 May 25 17:34:26 audio-server volumio[6762]: info: CoreCommandRouter::volumioGetState May 25 17:34:26 audio-server volumio[6762]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 6 May 25 17:34:26 audio-server volumio[6762]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 7 May 25 17:34:26 audio-server volumio[6762]: verbose: New Socket.io Connection to localhost:3000 from 127.0.0.1 UA: node-XMLHttpRequest Engine version: 3 Transport: polling Total Clients: 8 May 25 17:34:26 audio-server volumio[6762]: info: CoreCommandRouter::volumioGetState May 25 17:34:26 audio-server volumio[6762]: SPOTIFY: RECEIVED VOLUMIO VOLUME 58 May 25 17:34:26 audio-server volumio[6762]: verbose: New Socket.io Connection to 192.168.40.22 from 192.168.40.50 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/136.0.0.0 Safari/537.36 Edg/136.0.0.0 Engine version: 3 Transport: polling Total Clients: 9 May 25 17:34:26 audio-server volumio[6762]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled May 25 17:34:26 audio-server volumio[6762]: info: CoreCommandRouter::volumioGetVisibleSources May 25 17:34:26 audio-server volumio[6762]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 25 17:34:26 audio-server volumio[6762]: info: CoreCommandRouter::volumioGetState May 25 17:34:26 audio-server volumio[6762]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback May 25 17:34:26 audio-server volumio[6762]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom May 25 17:34:26 audio-server volumio[6762]: info: Received Get System Info May 25 17:34:26 audio-server volumio[6762]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 25 17:34:26 audio-server volumio[6762]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 25 17:34:26 audio-server volumio[6762]: info: Discovery: Getting this device information May 25 17:34:26 audio-server volumio[6762]: info: CoreCommandRouter::volumioGetState May 25 17:34:26 audio-server volumio[6762]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 25 17:34:26 audio-server volumio[6762]: info: CoreCommandRouter::volumioGetState May 25 17:34:26 audio-server volumio[6762]: info: Listing playlists May 25 17:34:26 audio-server volumio[6762]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache May 25 17:34:27 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:34:27 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:34:27 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:34:27 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:34:27 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:34:27 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:34:27 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:34:27 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:34:27 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:34:27 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:34:27 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:34:27 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:34:27 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:34:27 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:34:27 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:34:27 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:34:27 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:34:27 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:34:27 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:34:27 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:34:27 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:34:27 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:34:27 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:34:27 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:34:27 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:34:27 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:34:27 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:34:27 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:34:27 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:34:27 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:34:27 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:34:27 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:34:28 audio-server volumio[6762]: info: [yt-cast-receiver] (YouTube) Sender disconnected (implicit): SAMSUNG SM-A526B May 25 17:34:28 audio-server volumio[6762]: info: [yt-cast-receiver] Player.reset() May 25 17:34:28 audio-server volumio[6762]: info: [yt-cast-receiver] Player.stop() May 25 17:34:28 audio-server volumio[6762]: error: [ytcr] MPD error: May 25 17:34:28 audio-server volumio[6762]: (MPDError) Failed to decode https://rr3---sn-aigl6nz7.googlevideo.com/videoplayback?expire=1748212467&ei=kkYzaPjaOrHPi9oP-bXT-QU&ip=109.234.178.51&id=o-AIl6J6buxPzHWK0ivDYGRkgJrZmvoFLDGJxjChW1vemO&itag=251&source=youtube&requiressl=yes&xpc=EgVo2aDSNQ%3D%3D&met=1748190866%2C&mh=8C&mm=31%2C26&mn=sn-aigl6nz7%2Csn-5hne6n6e&ms=au%2Conr&mv=m&mvi=3&pl=21&rms=au%2Cau&initcwndbps=4610000&siu=1&bui=AecWEAbSRACw-YAWpNjeJLYzVVhIp6bXT3pmrSbJd9mHmN8s1bNT0rS4-tpuB6Wjky7ap0yw4g&spc=wk1kZnMI3jrU&vprv=1&svpuc=1&mime=audio%2Fwebm&ns=M15NybPcf6g3EIACV3e7gIAQ&rqh=1&gir=yes&clen=3256805&dur=180.041&lmt=1726018916002857&mt=1748190770&fvip=3&keepalive=yes&lmw=1&c=TVHTML5&sefc=1&txp=5532434&n=xYE_-iR3u6k_36xo1oeS&sparams=expire%2Cei%2Cip%2Cid%2Citag%2Csource%2Crequiressl%2Cxpc%2Csiu%2Cbui%2Cspc%2Cvprv%2Csvpuc%2Cmime%2Cns%2Crqh%2Cgir%2Cclen%2Cdur%2Clmt&sig=AJfQdSswRQIhANGiNrK76LSep788dct8aI95HnMKUR1WiIsBEa9ruOFDAiAY8IV5nZKsdnzhi3tgQs8uvLrAHBPQILPl_ZAnQdS1Cg%3D%3D&lsparams=met%2Cmh%2Cmm%2Cmn%2Cms%2Cmv%2Cmvi%2Cpl%2Crms%2Cinitcwndbps&lsig=ACuhMU0w; got HTTP status 403 May 25 17:34:28 audio-server volumio[6762]: MPDError: Failed to decode https://rr3---sn-aigl6nz7.googlevideo.com/videoplayback?expire=1748212467&ei=kkYzaPjaOrHPi9oP-bXT-QU&ip=109.234.178.51&id=o-AIl6J6buxPzHWK0ivDYGRkgJrZmvoFLDGJxjChW1vemO&itag=251&source=youtube&requiressl=yes&xpc=EgVo2aDSNQ%3D%3D&met=1748190866%2C&mh=8C&mm=31%2C26&mn=sn-aigl6nz7%2Csn-5hne6n6e&ms=au%2Conr&mv=m&mvi=3&pl=21&rms=au%2Cau&initcwndbps=4610000&siu=1&bui=AecWEAbSRACw-YAWpNjeJLYzVVhIp6bXT3pmrSbJd9mHmN8s1bNT0rS4-tpuB6Wjky7ap0yw4g&spc=wk1kZnMI3jrU&vprv=1&svpuc=1&mime=audio%2Fwebm&ns=M15NybPcf6g3EIACV3e7gIAQ&rqh=1&gir=yes&clen=3256805&dur=180.041&lmt=1726018916002857&mt=1748190770&fvip=3&keepalive=yes&lmw=1&c=TVHTML5&sefc=1&txp=5532434&n=xYE_-iR3u6k_36xo1oeS&sparams=expire%2Cei%2Cip%2Cid%2Citag%2Csource%2Crequiressl%2Cxpc%2Csiu%2Cbui%2Cspc%2Cvprv%2Csvpuc%2Cmime%2Cns%2Crqh%2Cgir%2Cclen%2Cdur%2Clmt&sig=AJfQdSswRQIhANGiNrK76LSep788dct8aI95HnMKUR1WiIsBEa9ruOFDAiAY8IV5nZKsdnzhi3tgQs8uvLrAHBPQILPl_ZAnQdS1Cg%3D%3D&lsparams=met%2Cmh%2Cmm%2Cmn%2Cms%2Cmv%2Cmvi%2Cpl%2Crms%2Cinitcwndbps&lsig=ACuhMU0w; got HTTP status 403 May 25 17:34:28 audio-server volumio[6762]: at MPDClient._receive (/data/plugins/music_service/ytcr/node_modules/mpd2/lib/index.js:147:24) May 25 17:34:28 audio-server volumio[6762]: at Socket.emit (events.js:315:20) May 25 17:34:28 audio-server volumio[6762]: at addChunk (internal/streams/readable.js:309:12) May 25 17:34:28 audio-server volumio[6762]: at readableAddChunk (internal/streams/readable.js:280:11) May 25 17:34:28 audio-server volumio[6762]: at Socket.Readable.push (internal/streams/readable.js:223:10) May 25 17:34:28 audio-server volumio[6762]: at Pipe.onStreamRead (internal/stream_base_commons.js:188:23) May 25 17:34:28 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:34:28 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:34:28 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:34:28 audio-server volumio[6762]: info: CoreCommandRouter::volumioGetState May 25 17:34:28 audio-server volumio[6762]: info: CoreCommandRouter::servicePushState May 25 17:34:28 audio-server volumio[6762]: info: CoreStateMachine::pushState May 25 17:34:28 audio-server volumio[6762]: info: CoreCommandRouter::volumioPushState May 25 17:34:28 audio-server volumio[6762]: info: CoreCommandRouter::servicePushState May 25 17:34:28 audio-server volumio[6762]: info: CoreStateMachine::pushState May 25 17:34:28 audio-server volumio[6762]: info: CoreCommandRouter::volumioPushState May 25 17:34:28 audio-server volumio[6762]: info: [ytcr] ***** Sender disconnected ***** May 25 17:34:28 audio-server volumio[6762]: info: CoreCommandRouter::getUIConfigOnPlugin May 25 17:34:28 audio-server volumio[6762]: info: CoreCommandRouter::volumioGetState May 25 17:34:28 audio-server volumio[6762]: info: CoreCommandRouter::servicePushState May 25 17:34:28 audio-server volumio[6762]: info: CoreStateMachine::pushState May 25 17:34:28 audio-server volumio[6762]: info: CoreCommandRouter::volumioPushState May 25 17:34:28 audio-server volumio[6762]: info: CoreCommandRouter::servicePushState May 25 17:34:28 audio-server volumio[6762]: info: CoreStateMachine::pushState May 25 17:34:28 audio-server volumio[6762]: info: CoreCommandRouter::volumioPushState May 25 17:34:28 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:34:28 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:34:28 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:34:28 audio-server volumio[6762]: info: [ASDebug] CurState: pause PrevState: pause May 25 17:34:28 audio-server volumio[6762]: info: [ASDebug] CurState: pause PrevState: pause May 25 17:34:28 audio-server volumio[6762]: info: [ASDebug] CurState: pause PrevState: pause May 25 17:34:28 audio-server volumio[6762]: info: [ASDebug] CurState: pause PrevState: pause May 25 17:34:28 audio-server volumio[6762]: info: [ASDebug] CurState: pause PrevState: pause May 25 17:34:28 audio-server volumio[6762]: info: [ASDebug] CurState: pause PrevState: pause May 25 17:34:28 audio-server volumio[6762]: info: [ASDebug] CurState: pause PrevState: pause May 25 17:34:28 audio-server volumio[6762]: info: [ASDebug] CurState: pause PrevState: pause May 25 17:34:28 audio-server volumio[6762]: SPOTIFY: RECEIVED VOLUMIO VOLUME 58 May 25 17:34:28 audio-server volumio[6762]: SPOTIFY: RECEIVED VOLUMIO VOLUME 58 May 25 17:34:28 audio-server volumio[6762]: SPOTIFY: RECEIVED VOLUMIO VOLUME 58 May 25 17:34:28 audio-server volumio[6762]: SPOTIFY: RECEIVED VOLUMIO VOLUME 58 May 25 17:34:28 audio-server volumio[6762]: info: CoreCommandRouter::volumioGetState May 25 17:34:28 audio-server volumio[6762]: info: CoreCommandRouter::servicePushState May 25 17:34:28 audio-server volumio[6762]: info: CoreStateMachine::pushState May 25 17:34:28 audio-server volumio[6762]: info: CoreCommandRouter::volumioPushState May 25 17:34:28 audio-server volumio[6762]: info: CoreCommandRouter::servicePushState May 25 17:34:28 audio-server volumio[6762]: info: CoreStateMachine::pushState May 25 17:34:28 audio-server volumio[6762]: info: CoreCommandRouter::volumioPushState May 25 17:34:28 audio-server volumio[6762]: info: [ASDebug] CurState: pause PrevState: pause May 25 17:34:28 audio-server volumio[6762]: info: [ASDebug] CurState: pause PrevState: pause May 25 17:34:28 audio-server volumio[6762]: info: [ASDebug] CurState: pause PrevState: pause May 25 17:34:28 audio-server volumio[6762]: info: [ASDebug] CurState: pause PrevState: pause May 25 17:34:28 audio-server volumio[6762]: SPOTIFY: RECEIVED VOLUMIO VOLUME 58 May 25 17:34:28 audio-server volumio[6762]: SPOTIFY: RECEIVED VOLUMIO VOLUME 58 May 25 17:34:35 audio-server go-librespot[6940]: time="2025-05-25T17:34:35+01:00" level=trace msg="sent dealer ping" May 25 17:34:35 audio-server go-librespot[6940]: time="2025-05-25T17:34:35+01:00" level=trace msg="received dealer pong" May 25 17:34:36 audio-server volumio[6762]: info: [yt-cast-receiver] (YouTube) Sender connected: SAMSUNG SM-A526B (user: Ollie) May 25 17:34:36 audio-server volumio[6762]: info: [ytcr] ***** Sender connected ***** May 25 17:34:36 audio-server volumio[6762]: info: CoreCommandRouter::getUIConfigOnPlugin May 25 17:34:37 audio-server volumio[6762]: [YOUTUBEJS][Player]: Failed to extract signature decipher algorithm. May 25 17:34:53 audio-server volumio[6762]: info: CALLMETHOD: music_service ytcr configSaveOther [object Object] May 25 17:34:53 audio-server volumio[6762]: info: CoreCommandRouter::executeOnPlugin: ytcr , configSaveOther May 25 17:34:53 audio-server volumio[6762]: info: CALLMETHOD: music_service ytcr configSaveOther [object Object] May 25 17:34:53 audio-server volumio[6762]: info: CoreCommandRouter::executeOnPlugin: ytcr , configSaveOther May 25 17:34:54 audio-server volumio[6762]: info: [yt-cast-receiver] Player.play(): xVrfpsYzfMI @ 0s May 25 17:34:54 audio-server volumio[6762]: info: CoreCommandRouter::volumioGetState May 25 17:34:55 audio-server volumio[6762]: info: CoreCommandRouter::volumioGetState May 25 17:34:56 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:34:56 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:34:56 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:34:56 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:34:56 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:34:56 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:34:56 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:34:56 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:34:56 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:34:56 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:34:56 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:34:56 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:34:56 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:34:56 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:34:56 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:34:56 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:34:56 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:34:56 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:34:56 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:34:56 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:34:56 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:34:56 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:34:56 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:34:56 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:34:56 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:34:56 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:34:56 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:34:56 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:34:56 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:34:56 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:34:56 audio-server volumio[6762]: error: [ytcr] MPD error: May 25 17:34:56 audio-server volumio[6762]: (MPDError) Failed to decode https://rr3---sn-aigl6nz7.googlevideo.com/videoplayback?expire=1748212496&ei=sEYzaL6NE9mJ6dsPxNSlyAg&ip=109.234.178.51&id=o-ANkaosggZ3afqeD-gdrhHRHgULs3Yed-H7p2ti8N7w-N&itag=251&source=youtube&requiressl=yes&xpc=EgVo2aDSNQ%3D%3D&met=1748190896%2C&mh=8C&mm=31%2C26&mn=sn-aigl6nz7%2Csn-5hneknek&ms=au%2Conr&mv=m&mvi=3&pl=21&rms=au%2Cau&initcwndbps=4305000&siu=1&bui=AecWEAbUuCNHmwLI32W4v2eIKZn3O7sLTJPbtd7cyTm2ajDV-kGEfdje_IEdlsGEctfk-2yCow&spc=wk1kZq3k1LQm&vprv=1&svpuc=1&mime=audio%2Fwebm&ns=47eS4RePnmzZ9NKnfrovzzEQ&rqh=1&gir=yes&clen=3256805&dur=180.041&lmt=1726018916002857&mt=1748190531&fvip=4&keepalive=yes&lmw=1&c=TVHTML5&sefc=1&txp=5532434&n=JXTHLaD7XYXR06Ub0W9W&sparams=expire%2Cei%2Cip%2Cid%2Citag%2Csource%2Crequiressl%2Cxpc%2Csiu%2Cbui%2Cspc%2Cvprv%2Csvpuc%2Cmime%2Cns%2Crqh%2Cgir%2Cclen%2Cdur%2Clmt&sig=AJfQdSswRgIhANIjnGKhpI-JBvKE27FMUmCUwbsFqVPtg_iIIjUv2RWvAiEAxhV799x3ajgnZBp2NIA339fI29MLR0JPOWFh30haHac%3D&lsparams=met%2Cmh%2Cmm%2Cmn%2Cms%2Cmv%2Cmvi%2Cpl%2Crms%2Cinitcwndbps&lsig=ACuhMU0wRQ; got HTTP status 403 May 25 17:34:56 audio-server volumio[6762]: MPDError: Failed to decode https://rr3---sn-aigl6nz7.googlevideo.com/videoplayback?expire=1748212496&ei=sEYzaL6NE9mJ6dsPxNSlyAg&ip=109.234.178.51&id=o-ANkaosggZ3afqeD-gdrhHRHgULs3Yed-H7p2ti8N7w-N&itag=251&source=youtube&requiressl=yes&xpc=EgVo2aDSNQ%3D%3D&met=1748190896%2C&mh=8C&mm=31%2C26&mn=sn-aigl6nz7%2Csn-5hneknek&ms=au%2Conr&mv=m&mvi=3&pl=21&rms=au%2Cau&initcwndbps=4305000&siu=1&bui=AecWEAbUuCNHmwLI32W4v2eIKZn3O7sLTJPbtd7cyTm2ajDV-kGEfdje_IEdlsGEctfk-2yCow&spc=wk1kZq3k1LQm&vprv=1&svpuc=1&mime=audio%2Fwebm&ns=47eS4RePnmzZ9NKnfrovzzEQ&rqh=1&gir=yes&clen=3256805&dur=180.041&lmt=1726018916002857&mt=1748190531&fvip=4&keepalive=yes&lmw=1&c=TVHTML5&sefc=1&txp=5532434&n=JXTHLaD7XYXR06Ub0W9W&sparams=expire%2Cei%2Cip%2Cid%2Citag%2Csource%2Crequiressl%2Cxpc%2Csiu%2Cbui%2Cspc%2Cvprv%2Csvpuc%2Cmime%2Cns%2Crqh%2Cgir%2Cclen%2Cdur%2Clmt&sig=AJfQdSswRgIhANIjnGKhpI-JBvKE27FMUmCUwbsFqVPtg_iIIjUv2RWvAiEAxhV799x3ajgnZBp2NIA339fI29MLR0JPOWFh30haHac%3D&lsparams=met%2Cmh%2Cmm%2Cmn%2Cms%2Cmv%2Cmvi%2Cpl%2Crms%2Cinitcwndbps&lsig=ACuhMU0wRQ; got HTTP status 403 May 25 17:34:56 audio-server volumio[6762]: at MPDClient._receive (/data/plugins/music_service/ytcr/node_modules/mpd2/lib/index.js:147:24) May 25 17:34:56 audio-server volumio[6762]: at Socket.emit (events.js:315:20) May 25 17:34:56 audio-server volumio[6762]: at addChunk (internal/streams/readable.js:309:12) May 25 17:34:56 audio-server volumio[6762]: at readableAddChunk (internal/streams/readable.js:280:11) May 25 17:34:56 audio-server volumio[6762]: at Socket.Readable.push (internal/streams/readable.js:223:10) May 25 17:34:56 audio-server volumio[6762]: at Pipe.onStreamRead (internal/stream_base_commons.js:188:23) May 25 17:34:56 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:34:56 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:34:56 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:34:56 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:34:56 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:34:56 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:34:56 audio-server volumio[6762]: info: CoreCommandRouter::volumioGetState May 25 17:34:56 audio-server volumio[6762]: info: CoreCommandRouter::servicePushState May 25 17:34:56 audio-server volumio[6762]: info: CoreStateMachine::pushState May 25 17:34:56 audio-server volumio[6762]: info: CoreCommandRouter::volumioPushState May 25 17:34:56 audio-server volumio[6762]: info: [ASDebug] CurState: pause PrevState: pause May 25 17:34:56 audio-server volumio[6762]: info: [ASDebug] CurState: pause PrevState: pause May 25 17:34:56 audio-server volumio[6762]: SPOTIFY: RECEIVED VOLUMIO VOLUME 58 May 25 17:34:57 audio-server sudo[15154]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 May 25 17:34:57 audio-server sudo[15154]: pam_unix(sudo:session): session opened for user root by (uid=0) May 25 17:34:57 audio-server sudo[15154]: pam_unix(sudo:session): session closed for user root May 25 17:34:57 audio-server sudo[15157]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 May 25 17:34:57 audio-server sudo[15157]: pam_unix(sudo:session): session opened for user root by (uid=0) May 25 17:34:57 audio-server sudo[15157]: pam_unix(sudo:session): session closed for user root May 25 17:34:57 audio-server volumio[6762]: verbose: New Socket.io Connection to 192.168.40.22 from 192.168.40.50 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/136.0.0.0 Safari/537.36 Edg/136.0.0.0 Engine version: 3 Transport: polling Total Clients: 7 May 25 17:34:57 audio-server volumio[6762]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled May 25 17:34:57 audio-server volumio[6762]: info: CoreCommandRouter::volumioGetVisibleSources May 25 17:34:57 audio-server volumio[6762]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 25 17:34:57 audio-server volumio[6762]: info: CoreCommandRouter::volumioGetState May 25 17:34:57 audio-server volumio[6762]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback May 25 17:34:57 audio-server volumio[6762]: info: CoreCommandRouter::getUIConfigOnPlugin May 25 17:34:57 audio-server volumio[6762]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom May 25 17:34:57 audio-server volumio[6762]: info: Received Get System Info May 25 17:34:57 audio-server volumio[6762]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 25 17:34:57 audio-server volumio[6762]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 25 17:34:57 audio-server volumio[6762]: info: Discovery: Getting this device information May 25 17:34:57 audio-server volumio[6762]: info: CoreCommandRouter::volumioGetState May 25 17:34:57 audio-server volumio[6762]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 25 17:34:57 audio-server volumio[6762]: info: CoreCommandRouter::volumioGetState May 25 17:34:57 audio-server volumio[6762]: info: Listing playlists May 25 17:34:57 audio-server volumio[6762]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings May 25 17:34:57 audio-server volumio[6762]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings May 25 17:34:57 audio-server volumio[6762]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache May 25 17:34:58 audio-server volumio[6762]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 25 17:34:58 audio-server volumio[6762]: info: Received Get System Info May 25 17:34:58 audio-server volumio[6762]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 25 17:34:58 audio-server volumio[6762]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 25 17:34:58 audio-server volumio[6762]: info: Discovery: Getting this device information May 25 17:34:58 audio-server volumio[6762]: info: CoreCommandRouter::volumioGetState May 25 17:34:58 audio-server volumio[6762]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 25 17:34:59 audio-server volumio[6762]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard May 25 17:35:00 audio-server volumio[6762]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 25 17:35:00 audio-server volumio[6762]: info: Received Get System Info May 25 17:35:00 audio-server volumio[6762]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 25 17:35:00 audio-server volumio[6762]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 25 17:35:00 audio-server volumio[6762]: info: Discovery: Getting this device information May 25 17:35:00 audio-server volumio[6762]: info: CoreCommandRouter::volumioGetState May 25 17:35:00 audio-server volumio[6762]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 25 17:35:00 audio-server volumio[6762]: info: [yt-cast-receiver] Player.resume() May 25 17:35:00 audio-server volumio[6762]: info: [yt-cast-receiver] Player.play(): xVrfpsYzfMI @ 0s May 25 17:35:00 audio-server volumio[6762]: info: CoreCommandRouter::volumioGetState May 25 17:35:00 audio-server volumio[6762]: info: CoreCommandRouter::volumioGetState May 25 17:35:01 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:35:01 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:35:01 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:35:01 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:35:01 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:35:01 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:35:01 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:35:01 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:35:01 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:35:01 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:35:01 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:35:01 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:35:01 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:35:01 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:35:01 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:35:01 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:35:01 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:35:01 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:35:01 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:35:01 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:35:01 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:35:01 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:35:01 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:35:01 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:35:01 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:35:01 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:35:01 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:35:01 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:35:02 audio-server volumio[6762]: error: [ytcr] MPD error: May 25 17:35:02 audio-server volumio[6762]: (MPDError) Failed to decode https://rr3---sn-aigl6nz7.googlevideo.com/videoplayback?expire=1748212501&ei=tUYzaKXDIJ7Qp-oP1bCSoQE&ip=109.234.178.51&id=o-AMJ6g6fBeHhItu3sDp_s8LBdTqzFW_eqhTiseL-wac4S&itag=251&source=youtube&requiressl=yes&xpc=EgVo2aDSNQ%3D%3D&met=1748190901%2C&mh=8C&mm=31%2C26&mn=sn-aigl6nz7%2Csn-5hneknek&ms=au%2Conr&mv=m&mvi=3&pl=21&rms=au%2Cau&initcwndbps=4305000&siu=1&bui=AecWEAbo-XRhQzIkw5eAn1Fy5nbJUW5Ubo3bX-ItgNSNVg5qGhfmng65DlQJDHpIGDSsUXFL8w&spc=wk1kZnMRmtCX&vprv=1&svpuc=1&mime=audio%2Fwebm&ns=U_bKVE9niONQTEFd_vCRnrUQ&rqh=1&gir=yes&clen=3256805&dur=180.041&lmt=1726018916002857&mt=1748190531&fvip=4&keepalive=yes&lmw=1&c=TVHTML5&sefc=1&txp=5532434&n=4jF1xc0NAzSLqHm__WS_&sparams=expire%2Cei%2Cip%2Cid%2Citag%2Csource%2Crequiressl%2Cxpc%2Csiu%2Cbui%2Cspc%2Cvprv%2Csvpuc%2Cmime%2Cns%2Crqh%2Cgir%2Cclen%2Cdur%2Clmt&sig=AJfQdSswRQIgPvRVBG4nQN-1t4XriCp-MGV6MM2SmlVBm9CBYGMJZBICIQD7dPkBNleRQdYDArg_TuE1zmTVIGYCVFY3zxxMj3UrNw%3D%3D&lsparams=met%2Cmh%2Cmm%2Cmn%2Cms%2Cmv%2Cmvi%2Cpl%2Crms%2Cinitcwndbps&lsig=ACuhMU0w; got HTTP status 403 May 25 17:35:02 audio-server volumio[6762]: MPDError: Failed to decode https://rr3---sn-aigl6nz7.googlevideo.com/videoplayback?expire=1748212501&ei=tUYzaKXDIJ7Qp-oP1bCSoQE&ip=109.234.178.51&id=o-AMJ6g6fBeHhItu3sDp_s8LBdTqzFW_eqhTiseL-wac4S&itag=251&source=youtube&requiressl=yes&xpc=EgVo2aDSNQ%3D%3D&met=1748190901%2C&mh=8C&mm=31%2C26&mn=sn-aigl6nz7%2Csn-5hneknek&ms=au%2Conr&mv=m&mvi=3&pl=21&rms=au%2Cau&initcwndbps=4305000&siu=1&bui=AecWEAbo-XRhQzIkw5eAn1Fy5nbJUW5Ubo3bX-ItgNSNVg5qGhfmng65DlQJDHpIGDSsUXFL8w&spc=wk1kZnMRmtCX&vprv=1&svpuc=1&mime=audio%2Fwebm&ns=U_bKVE9niONQTEFd_vCRnrUQ&rqh=1&gir=yes&clen=3256805&dur=180.041&lmt=1726018916002857&mt=1748190531&fvip=4&keepalive=yes&lmw=1&c=TVHTML5&sefc=1&txp=5532434&n=4jF1xc0NAzSLqHm__WS_&sparams=expire%2Cei%2Cip%2Cid%2Citag%2Csource%2Crequiressl%2Cxpc%2Csiu%2Cbui%2Cspc%2Cvprv%2Csvpuc%2Cmime%2Cns%2Crqh%2Cgir%2Cclen%2Cdur%2Clmt&sig=AJfQdSswRQIgPvRVBG4nQN-1t4XriCp-MGV6MM2SmlVBm9CBYGMJZBICIQD7dPkBNleRQdYDArg_TuE1zmTVIGYCVFY3zxxMj3UrNw%3D%3D&lsparams=met%2Cmh%2Cmm%2Cmn%2Cms%2Cmv%2Cmvi%2Cpl%2Crms%2Cinitcwndbps&lsig=ACuhMU0w; got HTTP status 403 May 25 17:35:02 audio-server volumio[6762]: at MPDClient._receive (/data/plugins/music_service/ytcr/node_modules/mpd2/lib/index.js:147:24) May 25 17:35:02 audio-server volumio[6762]: at Socket.emit (events.js:315:20) May 25 17:35:02 audio-server volumio[6762]: at addChunk (internal/streams/readable.js:309:12) May 25 17:35:02 audio-server volumio[6762]: at readableAddChunk (internal/streams/readable.js:280:11) May 25 17:35:02 audio-server volumio[6762]: at Socket.Readable.push (internal/streams/readable.js:223:10) May 25 17:35:02 audio-server volumio[6762]: at Pipe.onStreamRead (internal/stream_base_commons.js:188:23) May 25 17:35:02 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:35:02 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:35:02 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:35:02 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:35:02 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:35:02 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:35:02 audio-server volumio[6762]: info: CoreCommandRouter::volumioGetState May 25 17:35:02 audio-server volumio[6762]: info: CoreCommandRouter::servicePushState May 25 17:35:02 audio-server volumio[6762]: info: CoreStateMachine::pushState May 25 17:35:02 audio-server volumio[6762]: info: CoreCommandRouter::volumioPushState May 25 17:35:02 audio-server volumio[6762]: info: [ASDebug] CurState: pause PrevState: pause May 25 17:35:02 audio-server volumio[6762]: info: [ASDebug] CurState: pause PrevState: pause May 25 17:35:02 audio-server volumio[6762]: SPOTIFY: RECEIVED VOLUMIO VOLUME 58 May 25 17:35:02 audio-server volumiologrotate[582]: ls: cannot access '/var/log/samba/log.wb-AUDIO': No such file or directory May 25 17:35:02 audio-server volumiologrotate[582]: ls: cannot access 'SERVER': No such file or directory May 25 17:35:04 audio-server volumio[6762]: info: [yt-cast-receiver] Player.resume() May 25 17:35:04 audio-server volumio[6762]: info: [yt-cast-receiver] Player.play(): xVrfpsYzfMI @ 0s May 25 17:35:04 audio-server volumio[6762]: info: CoreCommandRouter::volumioGetState May 25 17:35:04 audio-server volumio[6762]: info: CoreCommandRouter::volumioGetState May 25 17:35:05 audio-server go-librespot[6940]: time="2025-05-25T17:35:05+01:00" level=trace msg="sent dealer ping" May 25 17:35:05 audio-server go-librespot[6940]: time="2025-05-25T17:35:05+01:00" level=trace msg="received dealer pong" May 25 17:35:05 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:35:05 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:35:05 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:35:05 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:35:05 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:35:05 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:35:05 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:35:05 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:35:05 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:35:05 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:35:05 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:35:05 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:35:05 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:35:05 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:35:05 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:35:05 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:35:05 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:35:05 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:35:05 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:35:05 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:35:05 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:35:05 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:35:05 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:35:05 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:35:05 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:35:05 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:35:05 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:35:05 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:35:06 audio-server volumio[6762]: error: [ytcr] MPD error: May 25 17:35:06 audio-server volumio[6762]: (MPDError) Failed to decode https://rr3---sn-aigl6nz7.googlevideo.com/videoplayback?expire=1748212505&ei=uUYzaNLZKLnOp-oPqvbBgAg&ip=109.234.178.51&id=o-AP1RD2ZIsstGwzygHZWiq0NCZYtMwo-y1CeZdoWU-QEi&itag=251&source=youtube&requiressl=yes&xpc=EgVo2aDSNQ%3D%3D&met=1748190905%2C&mh=8C&mm=31%2C26&mn=sn-aigl6nz7%2Csn-5hneknek&ms=au%2Conr&mv=m&mvi=3&pl=21&rms=au%2Cau&initcwndbps=4305000&siu=1&bui=AecWEAZq-gf31GRDJYn7SndzvLcXbHzbD48n54hSP_gwevwGx3x6Ja6rdgg3cj4N0j4thYn_Ww&spc=wk1kZk-yOO1N&vprv=1&svpuc=1&mime=audio%2Fwebm&ns=e4NnqkTXD_zJ4r1Io92N-ysQ&rqh=1&gir=yes&clen=3256805&dur=180.041&lmt=1726018916002857&mt=1748190531&fvip=4&keepalive=yes&lmw=1&c=TVHTML5&sefc=1&txp=5532434&n=cuUelXk6kPerbUu9eIBR&sparams=expire%2Cei%2Cip%2Cid%2Citag%2Csource%2Crequiressl%2Cxpc%2Csiu%2Cbui%2Cspc%2Cvprv%2Csvpuc%2Cmime%2Cns%2Crqh%2Cgir%2Cclen%2Cdur%2Clmt&sig=AJfQdSswRAIgQxA76fY642tbZEzGyrPNzFtwnUAOSn11JmwaOp9q9rUCIDZznvm6fMA0iSaTlkVti6ibTtvDux_8c4PnuZ-W78qh&lsparams=met%2Cmh%2Cmm%2Cmn%2Cms%2Cmv%2Cmvi%2Cpl%2Crms%2Cinitcwndbps&lsig=ACuhMU0wRQIgFq3d; got HTTP status 403 May 25 17:35:06 audio-server volumio[6762]: MPDError: Failed to decode https://rr3---sn-aigl6nz7.googlevideo.com/videoplayback?expire=1748212505&ei=uUYzaNLZKLnOp-oPqvbBgAg&ip=109.234.178.51&id=o-AP1RD2ZIsstGwzygHZWiq0NCZYtMwo-y1CeZdoWU-QEi&itag=251&source=youtube&requiressl=yes&xpc=EgVo2aDSNQ%3D%3D&met=1748190905%2C&mh=8C&mm=31%2C26&mn=sn-aigl6nz7%2Csn-5hneknek&ms=au%2Conr&mv=m&mvi=3&pl=21&rms=au%2Cau&initcwndbps=4305000&siu=1&bui=AecWEAZq-gf31GRDJYn7SndzvLcXbHzbD48n54hSP_gwevwGx3x6Ja6rdgg3cj4N0j4thYn_Ww&spc=wk1kZk-yOO1N&vprv=1&svpuc=1&mime=audio%2Fwebm&ns=e4NnqkTXD_zJ4r1Io92N-ysQ&rqh=1&gir=yes&clen=3256805&dur=180.041&lmt=1726018916002857&mt=1748190531&fvip=4&keepalive=yes&lmw=1&c=TVHTML5&sefc=1&txp=5532434&n=cuUelXk6kPerbUu9eIBR&sparams=expire%2Cei%2Cip%2Cid%2Citag%2Csource%2Crequiressl%2Cxpc%2Csiu%2Cbui%2Cspc%2Cvprv%2Csvpuc%2Cmime%2Cns%2Crqh%2Cgir%2Cclen%2Cdur%2Clmt&sig=AJfQdSswRAIgQxA76fY642tbZEzGyrPNzFtwnUAOSn11JmwaOp9q9rUCIDZznvm6fMA0iSaTlkVti6ibTtvDux_8c4PnuZ-W78qh&lsparams=met%2Cmh%2Cmm%2Cmn%2Cms%2Cmv%2Cmvi%2Cpl%2Crms%2Cinitcwndbps&lsig=ACuhMU0wRQIgFq3d; got HTTP status 403 May 25 17:35:06 audio-server volumio[6762]: at MPDClient._receive (/data/plugins/music_service/ytcr/node_modules/mpd2/lib/index.js:147:24) May 25 17:35:06 audio-server volumio[6762]: at Socket.emit (events.js:315:20) May 25 17:35:06 audio-server volumio[6762]: at addChunk (internal/streams/readable.js:309:12) May 25 17:35:06 audio-server volumio[6762]: at readableAddChunk (internal/streams/readable.js:280:11) May 25 17:35:06 audio-server volumio[6762]: at Socket.Readable.push (internal/streams/readable.js:223:10) May 25 17:35:06 audio-server volumio[6762]: at Pipe.onStreamRead (internal/stream_base_commons.js:188:23) May 25 17:35:06 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:35:06 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:35:06 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:35:06 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:35:06 audio-server volumio[6762]: info: Ignoring MPD Status Update May 25 17:35:06 audio-server volumio[6762]: info: CoreCommandRouter::volumioGetState May 25 17:35:06 audio-server volumio[6762]: info: CoreCommandRouter::servicePushState May 25 17:35:06 audio-server volumio[6762]: info: CoreStateMachine::pushState May 25 17:35:06 audio-server volumio[6762]: info: CoreCommandRouter::volumioPushState May 25 17:35:06 audio-server volumio[6762]: info: [ASDebug] CurState: pause PrevState: pause May 25 17:35:06 audio-server volumio[6762]: info: [ASDebug] CurState: pause PrevState: pause May 25 17:35:06 audio-server volumio[6762]: SPOTIFY: RECEIVED VOLUMIO VOLUME 58 May 25 17:35:07 audio-server volumio[6762]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted May 25 17:35:10 audio-server volumio[6762]: info: [yt-cast-receiver] Player.pause() May 25 17:35:15 audio-server volumio[6762]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings May 25 17:35:15 audio-server volumio[6762]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined May 25 17:35:15 audio-server volumio[6762]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates May 25 17:35:15 audio-server volumio[6762]: info: Received Get System Version May 25 17:35:15 audio-server volumio[6762]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion May 25 17:35:15 audio-server volumio[6762]: info: Received Get System Info May 25 17:35:15 audio-server volumio[6762]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo May 25 17:35:15 audio-server volumio[6762]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice May 25 17:35:15 audio-server volumio[6762]: info: Discovery: Getting this device information May 25 17:35:15 audio-server volumio[6762]: info: CoreCommandRouter::volumioGetState May 25 17:35:15 audio-server volumio[6762]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses May 25 17:35:18 audio-server volumio[6762]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus May 25 17:35:18 audio-server volumio[6762]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioToken May 25 17:35:21 audio-server volumio[6762]: info: CoreCommandRouter::volumioRemoveToBrowseSourcesYouTube2 May 25 17:35:21 audio-server volumio[6762]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources May 25 17:35:21 audio-server volumio[6762]: Cannot find translation for source Spotify May 25 17:35:21 audio-server volumio[6762]: info: Disabling plugin youtube2 May 25 17:35:21 audio-server volumio[6762]: info: Done. May 25 17:35:21 audio-server volumio[6762]: info: [yt-cast-receiver] Player.reset() May 25 17:35:21 audio-server volumio[6762]: info: CoreCommandRouter::volumioGetState May 25 17:35:21 audio-server volumio[6762]: info: CoreCommandRouter::servicePushState May 25 17:35:21 audio-server volumio[6762]: info: CoreStateMachine::pushState May 25 17:35:21 audio-server volumio[6762]: info: CoreCommandRouter::volumioPushState May 25 17:35:21 audio-server volumio[6762]: info: CoreCommandRouter::servicePushState May 25 17:35:21 audio-server volumio[6762]: info: CoreStateMachine::pushState May 25 17:35:21 audio-server volumio[6762]: info: CoreCommandRouter::volumioPushState May 25 17:35:21 audio-server volumio[6762]: info: [ASDebug] CurState: pause PrevState: pause May 25 17:35:21 audio-server volumio[6762]: info: [ASDebug] CurState: pause PrevState: pause May 25 17:35:21 audio-server volumio[6762]: info: [ASDebug] CurState: pause PrevState: pause May 25 17:35:21 audio-server volumio[6762]: info: [ASDebug] CurState: pause PrevState: pause May 25 17:35:21 audio-server volumio[6762]: SPOTIFY: RECEIVED VOLUMIO VOLUME 58 May 25 17:35:21 audio-server volumio[6762]: SPOTIFY: RECEIVED VOLUMIO VOLUME 58 May 25 17:35:21 audio-server volumio[6762]: verbose: UNSET VOLATILE: Service: ytcr May 25 17:35:21 audio-server volumio[6762]: info: CoreCommandRouter::servicePushState May 25 17:35:21 audio-server volumio[6762]: info: CoreStateMachine::pushState May 25 17:35:21 audio-server volumio[6762]: info: CoreCommandRouter::volumioPushState May 25 17:35:21 audio-server volumio[6762]: info: CoreCommandRouter::servicePushState May 25 17:35:21 audio-server volumio[6762]: info: CoreStateMachine::pushState May 25 17:35:21 audio-server volumio[6762]: info: CoreCommandRouter::volumioPushState May 25 17:35:21 audio-server volumio[6762]: info: [ASDebug] CurState: pause PrevState: pause May 25 17:35:21 audio-server volumio[6762]: info: [ASDebug] CurState: pause PrevState: pause May 25 17:35:21 audio-server volumio[6762]: info: [ASDebug] CurState: pause PrevState: pause May 25 17:35:21 audio-server volumio[6762]: info: [ASDebug] CurState: pause PrevState: pause May 25 17:35:21 audio-server volumio[6762]: SPOTIFY: RECEIVED VOLUMIO VOLUME 58 May 25 17:35:21 audio-server volumio[6762]: SPOTIFY: RECEIVED VOLUMIO VOLUME 58 May 25 17:35:21 audio-server volumio[6762]: info: Disabling plugin ytcr May 25 17:35:21 audio-server volumio[6762]: info: Done. May 25 17:35:22 audio-server volumio[6762]: info: Enabling plugin ampswitch May 25 17:35:22 audio-server volumio[6762]: info: Loading plugin "ampswitch"... May 25 17:35:22 audio-server volumio[6762]: info: Applying required configuration parameters for plugin ampswitch May 25 17:35:22 audio-server volumio[6762]: info: PLUGIN START: ampswitch May 25 17:35:22 audio-server volumio[6762]: info: Done. May 25 17:35:22 audio-server volumio[6762]: info: CoreCommandRouter::volumioGetState May 25 17:35:22 audio-server volumio[6762]: info: CorePlayQueue::getTrack 7 May 25 17:35:22 audio-server volumio[6762]: info: [ASDebug] CurState: pause PrevState: pause May 25 17:35:22 audio-server volumio[6762]: info: [ASDebug] CurState: pause PrevState: pause May 25 17:35:22 audio-server volumio[6762]: info: [ASDebug] CurState: pause PrevState: pause May 25 17:35:22 audio-server volumio[6762]: info: [ASDebug] CurState: pause PrevState: pause May 25 17:35:28 audio-server volumio[6762]: info: CoreCommandRouter::volumioGetState May 25 17:35:28 audio-server volumio[6762]: info: CorePlayQueue::getTrack 7 May 25 17:35:32 audio-server go-librespot[6940]: time="2025-05-25T17:35:32+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 250" May 25 17:35:32 audio-server go-librespot[6940]: time="2025-05-25T17:35:32+01:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update May 25 17:35:35 audio-server go-librespot[6940]: time="2025-05-25T17:35:35+01:00" level=trace msg="sent dealer ping" May 25 17:35:35 audio-server go-librespot[6940]: time="2025-05-25T17:35:35+01:00" level=trace msg="received dealer pong" May 25 17:35:36 audio-server go-librespot[6940]: time="2025-05-25T17:35:36+01:00" level=debug msg="handling transfer player command from 7aad6f090304d87706fe1997a0cce83587a168b7" May 25 17:35:36 audio-server go-librespot[6940]: time="2025-05-25T17:35:36+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 342" May 25 17:35:36 audio-server go-librespot[6940]: time="2025-05-25T17:35:36+01:00" level=debug msg="resolved context of track" uri="spotify:user:raz5cuzm65j8hcerl1dq7cxpm:collection" May 25 17:35:36 audio-server go-librespot[6940]: time="2025-05-25T17:35:36+01:00" level=trace msg="fetched new page 0 with 1154 items (list: 1154)" uri="spotify:user:raz5cuzm65j8hcerl1dq7cxpm:collection" May 25 17:35:36 audio-server go-librespot[6940]: time="2025-05-25T17:35:36+01:00" level=debug msg="shuffled context with seed 10612178982933516377 (len: 1154, keep: 589)" uri="spotify:user:raz5cuzm65j8hcerl1dq7cxpm:collection" May 25 17:35:36 audio-server go-librespot[6940]: time="2025-05-25T17:35:36+01:00" level=debug msg="loading track (paused: true, position: 1294ms)" uri="spotify:track:2zeXML6bri6wdCkAC58DPr" May 25 17:35:36 audio-server go-librespot[6940]: time="2025-05-25T17:35:36+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 25 17:35:36 audio-server go-librespot[6940]: time="2025-05-25T17:35:36+01:00" level=trace msg="emitting websocket event: will_play" May 25 17:35:36 audio-server volumio[6762]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:2zeXML6bri6wdCkAC58DPr","play_origin":"playlist"}} May 25 17:35:36 audio-server go-librespot[6940]: time="2025-05-25T17:35:36+01:00" level=debug msg="selected format OGG_VORBIS_320 (dcc72016f7420b0c23a868a8b947fd8896b238fa)" uri="spotify:track:2zeXML6bri6wdCkAC58DPr" May 25 17:35:36 audio-server go-librespot[6940]: time="2025-05-25T17:35:36+01:00" level=debug msg="requested aes key for file dcc72016f7420b0c23a868a8b947fd8896b238fa, gid: 2zeXML6bri6wdCkAC58DPr" May 25 17:35:36 audio-server go-librespot[6940]: time="2025-05-25T17:35:36+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 345" May 25 17:35:36 audio-server go-librespot[6940]: time="2025-05-25T17:35:36+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1703" May 25 17:35:36 audio-server go-librespot[6940]: time="2025-05-25T17:35:36+01:00" level=debug msg="fetched first chunk of 13, total size is 6720804 bytes" uri="spotify:track:2zeXML6bri6wdCkAC58DPr" May 25 17:35:36 audio-server go-librespot[6940]: time="2025-05-25T17:35:36+01:00" level=trace msg="seek to 1294ms (diff: 29ms, samples: 57065, bytes: 84487)" uri="spotify:track:2zeXML6bri6wdCkAC58DPr" May 25 17:35:36 audio-server go-librespot[6940]: time="2025-05-25T17:35:36+01:00" level=debug msg="created new output device" May 25 17:35:36 audio-server go-librespot[6940]: time="2025-05-25T17:35:36+01:00" level=info msg="loaded track \"Mijn Benzine - slowed\" (paused: true, position: 1294ms, duration: 152566ms, prefetched: false)" uri="spotify:track:2zeXML6bri6wdCkAC58DPr" May 25 17:35:36 audio-server go-librespot[6940]: time="2025-05-25T17:35:36+01:00" level=debug msg="fetched chunk 1/12, size: 524288" uri="spotify:track:2zeXML6bri6wdCkAC58DPr" May 25 17:35:36 audio-server go-librespot[6940]: time="2025-05-25T17:35:36+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 25 17:35:36 audio-server go-librespot[6940]: time="2025-05-25T17:35:36+01:00" level=trace msg="emitting websocket event: metadata" May 25 17:35:36 audio-server go-librespot[6940]: time="2025-05-25T17:35:36+01:00" level=trace msg="emitting websocket event: active" May 25 17:35:36 audio-server go-librespot[6940]: time="2025-05-25T17:35:36+01:00" level=debug msg="sending successful reply for dealer request" May 25 17:35:36 audio-server volumio[6762]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:2zeXML6bri6wdCkAC58DPr","name":"Mijn Benzine - slowed","artist_names":["Opgekonkerd"],"album_name":"Mijn Benzine","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02bd83ec934abdff7e27d35f16","position":1294,"duration":152566,"release_date":"year:2025 month:5 day:2","track_number":2,"disc_number":1}} May 25 17:35:36 audio-server volumio[6762]: SPOTIFY: received: {"type":"active","data":null} May 25 17:35:36 audio-server volumio[6762]: info: Aligning Spotify Volume to Volumio Volume May 25 17:35:36 audio-server volumio[6762]: info: CoreCommandRouter::volumioGetState May 25 17:35:36 audio-server volumio[6762]: info: CorePlayQueue::getTrack 7 May 25 17:35:36 audio-server volumio[6762]: info: Setting Spotify Volume from Volumio: 58 May 25 17:35:36 audio-server go-librespot[6940]: time="2025-05-25T17:35:36+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1298" May 25 17:35:36 audio-server go-librespot[6940]: time="2025-05-25T17:35:36+01:00" level=debug msg="fetched chunk 2/12, size: 524288" uri="spotify:track:2zeXML6bri6wdCkAC58DPr" May 25 17:35:36 audio-server go-librespot[6940]: time="2025-05-25T17:35:36+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 25 17:35:36 audio-server go-librespot[6940]: time="2025-05-25T17:35:36+01:00" level=trace msg="emitting websocket event: paused" May 25 17:35:36 audio-server volumio[6762]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:2zeXML6bri6wdCkAC58DPr","play_origin":"playlist"}} May 25 17:35:36 audio-server volumio[6762]: info: Spotify is playing in volatile mode May 25 17:35:36 audio-server volumio[6762]: info: CoreStateMachine::setConsumeUpdateService undefined May 25 17:35:36 audio-server go-librespot[6940]: time="2025-05-25T17:35:36+01:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update May 25 17:35:36 audio-server volumio[6762]: SPOTIFY: UNSET VOLATILE May 25 17:35:36 audio-server volumio[6762]: SPOTIFY: {"status":"pause","albumart":"/albumart","uri":"","trackType":"","codec":"","seek":0,"duration":0,"consume":false,"volume":58,"dbVolume":null,"mute":false,"disableVolumeControl":false,"stream":false,"updatedb":false,"volatile":true,"service":"ytcr"} May 25 17:35:36 audio-server volumio[6762]: info: Setting Spotify stop after unset volatile call May 25 17:35:36 audio-server go-librespot[6940]: time="2025-05-25T17:35:36+01:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update May 25 17:35:36 audio-server go-librespot[6940]: time="2025-05-25T17:35:36+01:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update May 25 17:35:36 audio-server volumio[6762]: SPOTIFY: PUSH STATE SPOTIFY May 25 17:35:36 audio-server volumio[6762]: SPOTIFY: {"status":"pause","service":"spop","title":"Mijn Benzine - slowed","artist":"Opgekonkerd","album":"Mijn Benzine","albumart":"https://i.scdn.co/image/ab67616d00001e02bd83ec934abdff7e27d35f16","uri":"spotify:track:2zeXML6bri6wdCkAC58DPr","trackType":"spotify","seek":1294,"duration":152,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":true,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} May 25 17:35:36 audio-server volumio[6762]: info: CoreCommandRouter::servicePushState May 25 17:35:36 audio-server volumio[6762]: info: CoreStateMachine::pushState May 25 17:35:36 audio-server volumio[6762]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 25 17:35:36 audio-server volumio[6762]: info: CoreCommandRouter::volumioPushState May 25 17:35:36 audio-server volumio[6762]: info: [ASDebug] CurState: pause PrevState: pause May 25 17:35:36 audio-server volumio[6762]: info: [ASDebug] CurState: pause PrevState: pause May 25 17:35:36 audio-server volumio[6762]: info: [ASDebug] CurState: pause PrevState: pause May 25 17:35:36 audio-server volumio[6762]: SPOTIFY: RECEIVED VOLUMIO VOLUME 58 May 25 17:35:36 audio-server go-librespot[6940]: time="2025-05-25T17:35:36+01:00" level=debug msg="fetched chunk 3/12, size: 524288" uri="spotify:track:2zeXML6bri6wdCkAC58DPr" May 25 17:35:37 audio-server volumio[6762]: info: Spotify Stop May 25 17:35:37 audio-server volumio[6762]: SPOTIFY: SPOTIFY STOP May 25 17:35:37 audio-server volumio[6762]: SPOTIFY: {"status":"pause","title":"Mijn Benzine - slowed","artist":"Opgekonkerd","album":"Mijn Benzine","albumart":"https://i.scdn.co/image/ab67616d00001e02bd83ec934abdff7e27d35f16","uri":"spotify:track:2zeXML6bri6wdCkAC58DPr","trackType":"spotify","codec":"ogg","seek":1294,"duration":152,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2,"random":true,"repeat":null,"repeatSingle":null,"consume":false,"volume":58,"dbVolume":null,"mute":false,"disableVolumeControl":false,"stream":false,"updatedb":false,"volatile":true,"service":"spop"} May 25 17:35:37 audio-server go-librespot[6940]: time="2025-05-25T17:35:37+01:00" level=debug msg="handling resume player command from 7aad6f090304d87706fe1997a0cce83587a168b7" May 25 17:35:37 audio-server go-librespot[6940]: time="2025-05-25T17:35:37+01:00" level=trace msg="seek to 1294ms (diff: 29ms, samples: 57065, bytes: 84487)" uri="spotify:track:2zeXML6bri6wdCkAC58DPr" May 25 17:35:37 audio-server go-librespot[6940]: time="2025-05-25T17:35:37+01:00" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 124988 us, period size = 5512 frames, buffer time = 500000 us, buffer size = 22050 frames, periods per buffer = 4 frames" May 25 17:35:37 audio-server go-librespot[6940]: time="2025-05-25T17:35:37+01:00" level=debug msg="resume track at 1265ms" May 25 17:35:37 audio-server go-librespot[6940]: time="2025-05-25T17:35:37+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 25 17:35:37 audio-server go-librespot[6940]: time="2025-05-25T17:35:37+01:00" level=trace msg="scheduling prefetch in 121s" May 25 17:35:37 audio-server go-librespot[6940]: time="2025-05-25T17:35:37+01:00" level=debug msg="sending successful reply for dealer request" May 25 17:35:37 audio-server go-librespot[6940]: time="2025-05-25T17:35:37+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" May 25 17:35:37 audio-server go-librespot[6940]: time="2025-05-25T17:35:37+01:00" level=trace msg="emitting websocket event: playing" May 25 17:35:37 audio-server volumio[6762]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:2zeXML6bri6wdCkAC58DPr","play_origin":"playlist"}} May 25 17:35:37 audio-server volumio[6762]: SPOTIFY: PUSH STATE SPOTIFY May 25 17:35:37 audio-server volumio[6762]: SPOTIFY: {"status":"play","service":"spop","title":"Mijn Benzine - slowed","artist":"Opgekonkerd","album":"Mijn Benzine","albumart":"https://i.scdn.co/image/ab67616d00001e02bd83ec934abdff7e27d35f16","uri":"spotify:track:2zeXML6bri6wdCkAC58DPr","trackType":"spotify","seek":1294,"duration":152,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":true,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} May 25 17:35:37 audio-server volumio[6762]: info: CoreCommandRouter::servicePushState May 25 17:35:37 audio-server volumio[6762]: info: CoreStateMachine::pushState May 25 17:35:37 audio-server volumio[6762]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo May 25 17:35:37 audio-server volumio[6762]: info: CoreCommandRouter::volumioPushState May 25 17:35:37 audio-server volumio[6762]: info: [ASDebug] CurState: play PrevState: pause May 25 17:35:37 audio-server volumio[6762]: info: [ASDebug] Togle GPIO: ON May 25 17:35:37 audio-server volumio[6762]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 25 17:35:37 audio-server volumio[6762]: Error: ESPIPE: invalid seek, write May 25 17:35:37 audio-server volumio[6762]: at Object.writeSync (fs.js:711:3) May 25 17:35:37 audio-server volumio[6762]: at Gpio.writeSync (/data/plugins/system_controller/ampswitch/node_modules/onoff/onoff.js:243:8) May 25 17:35:37 audio-server volumio[6762]: at AmpSwitchController.on (/data/plugins/system_controller/ampswitch/index.js:207:23) May 25 17:35:37 audio-server volumio[6762]: at AmpSwitchController.parseStatus (/data/plugins/system_controller/ampswitch/index.js:190:86) May 25 17:35:37 audio-server volumio[6762]: at Socket.Emitter.emit (/data/plugins/system_controller/ampswitch/node_modules/component-emitter/index.js:145:20) May 25 17:35:37 audio-server volumio[6762]: at Socket.onevent (/data/plugins/system_controller/ampswitch/node_modules/socket.io-client/lib/socket.js:278:10) May 25 17:35:37 audio-server volumio[6762]: at Socket.onpacket (/data/plugins/system_controller/ampswitch/node_modules/socket.io-client/lib/socket.js:236:12) May 25 17:35:37 audio-server volumio[6762]: at Manager. (/data/plugins/system_controller/ampswitch/node_modules/component-bind/index.js:21:15) May 25 17:35:37 audio-server volumio[6762]: at Manager.Emitter.emit (/data/plugins/system_controller/ampswitch/node_modules/component-emitter/index.js:145:20) May 25 17:35:37 audio-server volumio[6762]: at Manager.ondecoded (/data/plugins/system_controller/ampswitch/node_modules/socket.io-client/lib/manager.js:349:8) May 25 17:35:37 audio-server volumio[6762]: at Decoder. (/data/plugins/system_controller/ampswitch/node_modules/component-bind/index.js:21:15) May 25 17:35:37 audio-server volumio[6762]: at Decoder.Emitter.emit (/data/plugins/system_controller/ampswitch/node_modules/component-emitter/index.js:145:20) May 25 17:35:37 audio-server volumio[6762]: at Decoder.add (/data/plugins/system_controller/ampswitch/node_modules/socket.io-parser/index.js:254:12) May 25 17:35:37 audio-server volumio[6762]: at Manager.ondata (/data/plugins/system_controller/ampswitch/node_modules/socket.io-client/lib/manager.js:339:16) May 25 17:35:37 audio-server volumio[6762]: at Socket. (/data/plugins/system_controller/ampswitch/node_modules/component-bind/index.js:21:15) May 25 17:35:37 audio-server volumio[6762]: at Socket.Emitter.emit (/data/plugins/system_controller/ampswitch/node_modules/component-emitter/index.js:145:20) { May 25 17:35:37 audio-server volumio[6762]: errno: -29, May 25 17:35:37 audio-server volumio[6762]: syscall: 'write', May 25 17:35:37 audio-server volumio[6762]: code: 'ESPIPE' May 25 17:35:37 audio-server volumio[6762]: } May 25 17:35:37 audio-server volumio[6762]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| May 25 17:35:38 audio-server sudo[15285]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-05-25 17:34 May 25 17:35:38 audio-server sudo[15285]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Raspbian GNU/Linux 10 (buster)" NAME="Raspbian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=raspbian ID_LIKE=debian HOME_URL="http://www.raspbian.org/" SUPPORT_URL="http://www.raspbian.org/RaspbianForums" BUG_REPORT_URL="http://www.raspbian.org/RaspbianBugs" VOLUMIO_BUILD_VERSION="570c5791513f5bac7da274aba6690c1a961705de" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="35e4a13c94df42ebab19fd6178d6be47190c244d" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Tue 13 May 2025 05:16:30 PM CEST" VOLUMIO_VERSION="3.812" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="3934ee440d5d3f0186049a23752ad680"