-- Logs begin at Thu 2019-02-14 11:11:59 CET, end at Fri 2025-02-21 17:33:58 CET. -- Feb 21 17:33:51 musickochen systemd-timedated[1247]: Changed local time to Fri Feb 21 17:33:51 2025 Feb 21 17:33:51 musickochen sudo[1245]: pam_unix(sudo:session): session closed for user root Feb 21 17:33:51 musickochen volumio-time-update[490]: volumio-time-update-util: System time updated successfully. Feb 21 17:33:51 musickochen systemd[1]: Starting Daily apt download activities... Feb 21 17:33:51 musickochen systemd[1]: Started Volumio Time Update Utility. Feb 21 17:33:51 musickochen systemd[1]: Reached target Multi-User System. Feb 21 17:33:51 musickochen systemd[1]: Reached target Graphical Interface. Feb 21 17:33:51 musickochen systemd[1]: Starting Update UTMP about System Runlevel Changes... Feb 21 17:33:51 musickochen volumio[915]: error: MPD error: The expression evaluated to a falsy value: Feb 21 17:33:51 musickochen volumio[915]: assert.ok(self.idling) Feb 21 17:33:51 musickochen volumio[915]: error: The expression evaluated to a falsy value: Feb 21 17:33:51 musickochen volumio[915]: assert.ok(self.idling) Feb 21 17:33:51 musickochen volumio[915]: info: MPD running with PID1210 Feb 21 17:33:51 musickochen volumio[915]: ,establishing connection Feb 21 17:33:51 musickochen volumio[915]: error: updateQueue error: null Feb 21 17:33:51 musickochen volumio[915]: error: updateQueue error: null Feb 21 17:33:51 musickochen volumio[915]: info: Discovery: A device disappeared from network Feb 21 17:33:51 musickochen volumio[915]: info: Discovery: Device musickochen disappeared from network Feb 21 17:33:51 musickochen systemd[1]: systemd-update-utmp-runlevel.service: Succeeded. Feb 21 17:33:51 musickochen systemd[1]: Started Update UTMP about System Runlevel Changes. Feb 21 17:33:51 musickochen volumio[915]: info: Volumio Network Manager: Network status updated: 2 Feb 21 17:33:51 musickochen volumio[915]: info: Discovery: adding 50998496-38d5-4cdf-8e66-eb7d1278baeb Feb 21 17:33:51 musickochen wpa_supplicant[792]: RRM: Ignoring radio measurement request: Not RRM network Feb 21 17:33:51 musickochen volumio[915]: info: Discovery: Found device musickochen Feb 21 17:33:51 musickochen volumio[915]: info: CoreCommandRouter::volumioGetState Feb 21 17:33:51 musickochen volumio[915]: info: CorePlayQueue::getTrack 0 Feb 21 17:33:51 musickochen sudo[1277]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Feb 21 17:33:51 musickochen sudo[1277]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 17:33:51 musickochen sudo[1279]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Feb 21 17:33:51 musickochen sudo[1279]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 17:33:51 musickochen sudo[1279]: pam_unix(sudo:session): session closed for user root Feb 21 17:33:51 musickochen sudo[1277]: pam_unix(sudo:session): session closed for user root Feb 21 17:33:51 musickochen sudo[1286]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start upmpdcli.service Feb 21 17:33:51 musickochen sudo[1286]: pam_unix(sudo:session): session opened for user root by (uid=0) Feb 21 17:33:51 musickochen systemd[1]: Started UPnP Renderer front-end to MPD. Feb 21 17:33:51 musickochen sudo[1286]: pam_unix(sudo:session): session closed for user root Feb 21 17:33:51 musickochen volumio[915]: info: Upmpdcli Daemon Started Feb 21 17:33:51 musickochen volumio[1289]: Generating RSA private key, 4096 bit long modulus (2 primes) Feb 21 17:33:52 musickochen volumio[915]: info: go-librespot daemon successfully initialized Feb 21 17:33:52 musickochen go-librespot[1214]: time="2025-02-21T17:33:52+01:00" level=debug msg="obtained new client token: AAA5spAuM9PPxSlgOCf9zWE+6EZ+Wovny5sIDFctlxjEl6XCvz0HRwDRgh4zakvrMwJmPV71+GVKhF1wo7qr/rkN/kFZeIa0djJGo9T64WhKm2CColQRtYBH9ore1kRvuSE+ixQyEQ35D+xioiNc98vd6I1JsC3xvOiYzTJMLR8SxV3NkjuK7/oo47vwNPHWgCFd+km4rndBdMZvNQaHmGKbUDJrYI5U3dpy8YtS1YpNzVnFZQ0GsrICJw==" Feb 21 17:33:52 musickochen go-librespot[1214]: time="2025-02-21T17:33:52+01:00" level=error msg="failed creating new session for 31uesqqrdginwum74ywkibj5inxm from Tab A9+ von Fabian" error="failed initializing accesspoint: failed dialing accesspoint: dial tcp 34.158.1.133:4070: connect: connection refused" Feb 21 17:33:52 musickochen go-librespot[1214]: time="2025-02-21T17:33:52+01:00" level=info msg="refused zeroconf user 31uesqqrdginwum74ywkibj5inxm from Tab A9+ von Fabian" Feb 21 17:33:54 musickochen volumio-remote-updater[495]: [2025-02-21 17:33:54] [connect] Successful connection Feb 21 17:33:54 musickochen volumio-remote-updater[495]: [2025-02-21 17:33:54] [connect] WebSocket Connection 127.0.0.1:3000 v-2 "WebSocket++/0.8.2" /socket.io/?EIO=4&transport=websocket&t=1740155634 101 Feb 21 17:33:54 musickochen volumio[915]: 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: 4 Feb 21 17:33:54 musickochen systemd[1]: apt-daily.service: Succeeded. Feb 21 17:33:54 musickochen systemd[1]: Started Daily apt download activities. Feb 21 17:33:54 musickochen systemd[1]: Starting Daily apt upgrade and clean activities... Feb 21 17:33:54 musickochen volumio[1289]: ........................++++ Feb 21 17:33:55 musickochen volumio[915]: info: Initializing connection to go-librespot Websocket Feb 21 17:33:55 musickochen go-librespot[1214]: time="2025-02-21T17:33:55+01:00" level=debug msg="new websocket client" Feb 21 17:33:55 musickochen volumio[915]: info: Connection to go-librespot Websocket established Feb 21 17:33:55 musickochen go-librespot[1214]: time="2025-02-21T17:33:55+01:00" level=debug msg="obtained new client token: AACBgUWxbKKwjSqOQs931HxPAtHZQvP2Nw9i7cmcmnPTF/0eZV1VpfBWc4xyx73nZFi+1AX8oowaSPN5Ct4MS20kRmt/1cMp/TX7ZauXvrL2/Lp3pOz2niYXeFp6uX35N2iCP48W/1o4BFVa78OTuHJaEASGX/LSyJIMiC2lrKvY+yu3AhHqY1AKq4rSJ7Ei3LEQZcTnqJJNQmedvxD79mxQzJ7pqTGo5Q5tUv0t0IZF91yiC+MlTdPvUQ==" Feb 21 17:33:55 musickochen go-librespot[1214]: time="2025-02-21T17:33:55+01:00" level=debug msg="completed keyexchange" Feb 21 17:33:55 musickochen go-librespot[1214]: time="2025-02-21T17:33:55+01:00" level=debug msg="completed challenge" Feb 21 17:33:55 musickochen go-librespot[1214]: time="2025-02-21T17:33:55+01:00" level=debug msg="authenticated as 31uesqqrdginwum74ywkibj5inxm" Feb 21 17:33:56 musickochen volumio[915]: error: Failed LSINFO: Error: [50@0] {lsinfo} No such directory Feb 21 17:33:56 musickochen go-librespot[1214]: time="2025-02-21T17:33:56+01:00" level=debug msg="authenticated as 31uesqqrdginwum74ywkibj5inxm" Feb 21 17:33:56 musickochen systemd[1]: apt-daily-upgrade.service: Succeeded. Feb 21 17:33:56 musickochen systemd[1]: Started Daily apt upgrade and clean activities. Feb 21 17:33:56 musickochen systemd[1]: Startup finished in 12.890s (kernel) + 44.352s (userspace) = 57.242s. Feb 21 17:33:56 musickochen go-librespot[1214]: time="2025-02-21T17:33:56+01:00" level=debug msg="dealer connection opened" Feb 21 17:33:56 musickochen go-librespot[1214]: time="2025-02-21T17:33:56+01:00" level=info msg="accepted zeroconf user 31uesqqrdginwum74ywkibj5inxm from Tab A9+ von Fabian" Feb 21 17:33:56 musickochen go-librespot[1214]: time="2025-02-21T17:33:56+01:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Feb 21 17:33:56 musickochen go-librespot[1214]: time="2025-02-21T17:33:56+01:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Feb 21 17:33:56 musickochen go-librespot[1214]: time="2025-02-21T17:33:56+01:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Feb 21 17:33:56 musickochen go-librespot[1214]: time="2025-02-21T17:33:56+01:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Feb 21 17:33:56 musickochen go-librespot[1214]: time="2025-02-21T17:33:56+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Feb 21 17:33:56 musickochen go-librespot[1214]: time="2025-02-21T17:33:56+01:00" level=debug msg="received connection id: NDBlYzQ5MzYtNDkxYy00YTcyLWJlNmYtNzk4ZTdmYWM0MGE1K2RlYWxlcit0Y3A6Ly8wYWNhNWEwYi5pcC5nZXc0LnNwb3RpZnkubmV0OjU3MDArMDcwODAxQTM3NTVBQzM5RkQ2REY0QjA2NTU5NzFGM0ZCQ0Y1QUQ0MTFCMkRDMjgzQUNDRUFFQTY1QTc0OEU3QQ==" Feb 21 17:33:56 musickochen go-librespot[1214]: time="2025-02-21T17:33:56+01:00" level=debug msg="put connect state because NEW_DEVICE" Feb 21 17:33:56 musickochen wpa_supplicant[792]: RRM: Ignoring radio measurement request: Not RRM network Feb 21 17:33:56 musickochen go-librespot[1214]: time="2025-02-21T17:33:56+01:00" level=debug msg="handling transfer player command from bf123185cf598c4b9f17d9a044b08f7e2e116ab8" Feb 21 17:33:56 musickochen go-librespot[1214]: time="2025-02-21T17:33:56+01:00" level=trace msg="fetched new page 0 with 503 items (list: 503)" Feb 21 17:33:56 musickochen go-librespot[1214]: time="2025-02-21T17:33:56+01:00" level=debug msg="loading track spotify:track:2W5KX7mTaZ3fDGOW07wrsN (paused: false, position: 24405ms)" Feb 21 17:33:56 musickochen go-librespot[1214]: time="2025-02-21T17:33:56+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Feb 21 17:33:56 musickochen go-librespot[1214]: time="2025-02-21T17:33:56+01:00" level=trace msg="emitting websocket event: will_play" Feb 21 17:33:56 musickochen volumio[915]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:2W5KX7mTaZ3fDGOW07wrsN","play_origin":"playlist"}} Feb 21 17:33:56 musickochen go-librespot[1214]: time="2025-02-21T17:33:56+01:00" level=debug msg="selected format OGG_VORBIS_320 for spotify:track:2W5KX7mTaZ3fDGOW07wrsN" Feb 21 17:33:56 musickochen go-librespot[1214]: time="2025-02-21T17:33:56+01:00" level=debug msg="requested aes key for file 00ae0396862e4b8f9cc2449273ddabeab0fae3fa, gid: 2W5KX7mTaZ3fDGOW07wrsN" Feb 21 17:33:56 musickochen go-librespot[1214]: time="2025-02-21T17:33:56+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 345" Feb 21 17:33:56 musickochen go-librespot[1214]: time="2025-02-21T17:33:56+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1372" Feb 21 17:33:56 musickochen go-librespot[1214]: time="2025-02-21T17:33:56+01:00" level=debug msg="fetched first chunk of 23, total size is 11684948 bytes" Feb 21 17:33:57 musickochen go-librespot[1214]: time="2025-02-21T17:33:57+01:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1132" Feb 21 17:33:57 musickochen go-librespot[1214]: time="2025-02-21T17:33:57+01:00" level=debug msg="fetched chunk 2/22, size: 524288" Feb 21 17:33:57 musickochen go-librespot[1214]: time="2025-02-21T17:33:57+01:00" level=debug msg="fetched chunk 1/22, size: 524288" Feb 21 17:33:57 musickochen go-librespot[1214]: time="2025-02-21T17:33:57+01:00" level=trace msg="seek to 24405ms (diff: 120ms, samples: 1076260, bytes: 1034316)" Feb 21 17:33:57 musickochen go-librespot[1214]: time="2025-02-21T17:33:57+01:00" level=debug msg="fetched chunk 3/22, size: 524288" Feb 21 17:33:57 musickochen go-librespot[1214]: time="2025-02-21T17:33:57+01:00" level=debug msg="fetched chunk 4/22, size: 524288" Feb 21 17:33:57 musickochen go-librespot[1214]: time="2025-02-21T17:33:57+01:00" level=info msg="loaded track \"Bravo, bravissimo! - Intro\" (uri: spotify:track:2W5KX7mTaZ3fDGOW07wrsN, paused: false, position: 24405ms, duration: 264626ms)" Feb 21 17:33:57 musickochen go-librespot[1214]: time="2025-02-21T17:33:57+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Feb 21 17:33:57 musickochen go-librespot[1214]: time="2025-02-21T17:33:57+01:00" level=trace msg="emitting websocket event: metadata" Feb 21 17:33:57 musickochen go-librespot[1214]: time="2025-02-21T17:33:57+01:00" level=trace msg="emitting websocket event: active" Feb 21 17:33:57 musickochen go-librespot[1214]: time="2025-02-21T17:33:57+01:00" level=debug msg="sending successful reply for delaer request" Feb 21 17:33:57 musickochen go-librespot[1214]: time="2025-02-21T17:33:57+01:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Feb 21 17:33:57 musickochen go-librespot[1214]: time="2025-02-21T17:33:57+01:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Feb 21 17:33:57 musickochen go-librespot[1214]: time="2025-02-21T17:33:57+01:00" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Feb 21 17:33:57 musickochen volumio[915]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:2W5KX7mTaZ3fDGOW07wrsN","name":"Bravo, bravissimo! - Intro","artist_names":["Die Schule der magischen Tiere"],"album_name":"13: Bravo, bravissimo!","album_cover_url":"https://i.scdn.co/image/ab67616d00001e029f9bd8c86708c3e392fe59a9","position":24405,"duration":264626,"release_date":"year:2022 month:11 day:4","track_number":1,"disc_number":1}} Feb 21 17:33:57 musickochen volumio[915]: SPOTIFY: received: {"type":"active","data":null} Feb 21 17:33:57 musickochen volumio[915]: info: Aligning Spotify Volume to Volumio Volume Feb 21 17:33:57 musickochen volumio[915]: info: CoreCommandRouter::volumioGetState Feb 21 17:33:57 musickochen volumio[915]: info: CorePlayQueue::getTrack 0 Feb 21 17:33:57 musickochen go-librespot[1214]: time="2025-02-21T17:33:57+01:00" level=debug msg="fetched chunk 5/22, size: 524288" Feb 21 17:33:57 musickochen go-librespot[1214]: time="2025-02-21T17:33:57+01:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Feb 21 17:33:57 musickochen go-librespot[1214]: time="2025-02-21T17:33:57+01:00" level=trace msg="emitting websocket event: playing" Feb 21 17:33:57 musickochen volumio[915]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:2W5KX7mTaZ3fDGOW07wrsN","play_origin":"playlist"}} Feb 21 17:33:57 musickochen volumio[915]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 21 17:33:57 musickochen volumio[915]: TypeError: Cannot read property 'service' of undefined Feb 21 17:33:57 musickochen volumio[915]: at ControllerSpotify.identifyPlaybackMode (/data/plugins/music_service/spop/index.js:336:50) Feb 21 17:33:57 musickochen volumio[915]: at ControllerSpotify.parseEventState (/data/plugins/music_service/spop/index.js:262:18) Feb 21 17:33:57 musickochen volumio[915]: at WebSocket.message (/data/plugins/music_service/spop/index.js:189:14) Feb 21 17:33:57 musickochen volumio[915]: at WebSocket.emit (events.js:315:20) Feb 21 17:33:57 musickochen volumio[915]: at Receiver.receiverOnMessage (/data/plugins/music_service/spop/node_modules/ws/lib/websocket.js:1203:20) Feb 21 17:33:57 musickochen volumio[915]: at Receiver.emit (events.js:315:20) Feb 21 17:33:57 musickochen volumio[915]: at /data/plugins/music_service/spop/node_modules/ws/lib/receiver.js:608:16 Feb 21 17:33:57 musickochen volumio[915]: at internal/process/task_queues.js:149:7 Feb 21 17:33:57 musickochen volumio[915]: at AsyncResource.runInAsyncScope (async_hooks.js:197:9) Feb 21 17:33:57 musickochen volumio[915]: at AsyncResource.runMicrotask (internal/process/task_queues.js:146:8) Feb 21 17:33:57 musickochen volumio[915]: at processTicksAndRejections (internal/process/task_queues.js:93:5) Feb 21 17:33:57 musickochen volumio[915]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Feb 21 17:33:58 musickochen sudo[1405]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-02-21 17:32 Feb 21 17:33:58 musickochen sudo[1405]: 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="f6610a1100d2380eef33bd3004af43153c786f96" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="1c0e5daee99fe3a72cc38b0d1fe6cd78d7f001fe" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Mon 16 Dec 2024 09:30:04 AM CET" VOLUMIO_VERSION="3.785" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="fe0ac4b79aed19ccde4b5bd83d468193"