-- Logs begin at Sun 2024-08-25 14:26:30 ACST, end at Sat 2024-08-31 22:45:14 ACST. -- Aug 31 22:44:08 volumio go-librespot[1182]: time="2024-08-31T22:44:08+09:30" level=debug msg="obtained new client token: AAAmPDRPPA8Ln6nJ0vVZBQX+CgKE4LxDcnDcYpk4dSRYokfKA7FeTBsj73mdJaV0smltg+6uGvNg/8DDrWUyMDESzV42iJc9YwHGNXKSW62wd+FaHHGwIeM8Xs77+z9ymfFVoOp07qL3sp6CGI0HNSYwJs4c4jG8tJOakPs3THxUwRnMlyC9WNRvQWo3eRTFqht/QLMpoyOlh66zDadHe7OsKpI8xOrNYkRmQhK9FE0DK3AUA0lQwlONAdhd/7c=" Aug 31 22:44:08 volumio go-librespot[1182]: time="2024-08-31T22:44:08+09:30" level=debug msg="completed keyexchange" Aug 31 22:44:09 volumio go-librespot[1182]: time="2024-08-31T22:44:09+09:30" level=debug msg="completed challenge" Aug 31 22:44:09 volumio go-librespot[1182]: time="2024-08-31T22:44:09+09:30" level=debug msg="authenticated as 223cwvpvlzftq5jvvkpvvrnqq" Aug 31 22:44:09 volumio go-librespot[1182]: time="2024-08-31T22:44:09+09:30" level=debug msg="authenticated as 223cwvpvlzftq5jvvkpvvrnqq" Aug 31 22:44:10 volumio go-librespot[1182]: time="2024-08-31T22:44:10+09:30" level=debug msg="dealer connection opened" Aug 31 22:44:10 volumio go-librespot[1182]: time="2024-08-31T22:44:10+09:30" level=info msg="accepted zeroconf user 223cwvpvlzftq5jvvkpvvrnqq from Derek's S23 Ultra" Aug 31 22:44:10 volumio go-librespot[1182]: time="2024-08-31T22:44:10+09:30" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Aug 31 22:44:10 volumio go-librespot[1182]: time="2024-08-31T22:44:10+09:30" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Aug 31 22:44:10 volumio go-librespot[1182]: time="2024-08-31T22:44:10+09:30" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Aug 31 22:44:10 volumio go-librespot[1182]: time="2024-08-31T22:44:10+09:30" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Aug 31 22:44:10 volumio go-librespot[1182]: time="2024-08-31T22:44:10+09:30" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 513" Aug 31 22:44:10 volumio go-librespot[1182]: time="2024-08-31T22:44:10+09:30" level=debug msg="received connection id: ZTE3ODY2ZGItN2VjZC00NjU3LTg5ZDctMjE4ZWIwMWU4M2Y5K2RlYWxlcit0Y3A6Ly8wYWM5NDkwMS5pcC5nYWUyLnNwb3RpZnkubmV0OjU3MDArREE4RTA5OTZFNDE3RkM1MjhFNEM3NjRFNDc3MUI0QzY1MEJFOTk0N0ZENkE0RTIzNDVGREU2MjE1NUFFRUIyQw==" Aug 31 22:44:10 volumio go-librespot[1182]: time="2024-08-31T22:44:10+09:30" level=debug msg="put connect state because NEW_DEVICE" Aug 31 22:44:10 volumio go-librespot[1182]: time="2024-08-31T22:44:10+09:30" level=debug msg="handling transfer player command from f80df98ffc0e23d08eac21d05ab533ec36d57bb0" Aug 31 22:44:10 volumio go-librespot[1182]: time="2024-08-31T22:44:10+09:30" level=trace msg="fetched new page 0 with 412 items (list: 412)" Aug 31 22:44:10 volumio go-librespot[1182]: time="2024-08-31T22:44:10+09:30" level=debug msg="shuffled context with seed 7551593859078892339 (len: 412, keep: 382)" Aug 31 22:44:10 volumio go-librespot[1182]: time="2024-08-31T22:44:10+09:30" level=debug msg="loading track spotify:track:5PzWVmfzu7rePAuFkxPQf0 (paused: true, position: 48924ms)" Aug 31 22:44:10 volumio go-librespot[1182]: time="2024-08-31T22:44:10+09:30" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Aug 31 22:44:10 volumio go-librespot[1182]: time="2024-08-31T22:44:10+09:30" level=trace msg="emitting websocket event: will_play" Aug 31 22:44:10 volumio volumio[1006]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:5PzWVmfzu7rePAuFkxPQf0","play_origin":"collection-songs"}} Aug 31 22:44:11 volumio go-librespot[1182]: time="2024-08-31T22:44:11+09:30" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 241" Aug 31 22:44:11 volumio go-librespot[1182]: time="2024-08-31T22:44:11+09:30" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 2046" Aug 31 22:44:11 volumio go-librespot[1182]: time="2024-08-31T22:44:11+09:30" level=debug msg="selected format OGG_VORBIS_320 for spotify:track:5PzWVmfzu7rePAuFkxPQf0" Aug 31 22:44:11 volumio go-librespot[1182]: time="2024-08-31T22:44:11+09:30" level=debug msg="requested aes key for file 634b786d09fe241934622a01185b506f46f6e0c6, gid: 5PzWVmfzu7rePAuFkxPQf0" Aug 31 22:44:11 volumio go-librespot[1182]: time="2024-08-31T22:44:11+09:30" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 1477" Aug 31 22:44:11 volumio go-librespot[1182]: time="2024-08-31T22:44:11+09:30" level=debug msg="fetched first chunk of 15, total size is 7845428 bytes" Aug 31 22:44:11 volumio go-librespot[1182]: time="2024-08-31T22:44:11+09:30" level=debug msg="fetched chunk 2/14, size: 524288" Aug 31 22:44:11 volumio go-librespot[1182]: time="2024-08-31T22:44:11+09:30" level=trace msg="seek to 48924ms (diff: 158ms, samples: 2157548, bytes: 1494028)" Aug 31 22:44:11 volumio go-librespot[1182]: time="2024-08-31T22:44:11+09:30" level=info msg="loaded track \"Repeat Until Death\" (uri: spotify:track:5PzWVmfzu7rePAuFkxPQf0, paused: true, position: 48924ms, duration: 234080ms)" Aug 31 22:44:12 volumio go-librespot[1182]: time="2024-08-31T22:44:12+09:30" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Aug 31 22:44:12 volumio go-librespot[1182]: time="2024-08-31T22:44:12+09:30" level=trace msg="emitting websocket event: metadata" Aug 31 22:44:12 volumio go-librespot[1182]: time="2024-08-31T22:44:12+09:30" level=trace msg="emitting websocket event: active" Aug 31 22:44:12 volumio go-librespot[1182]: time="2024-08-31T22:44:12+09:30" level=debug msg="sending successful reply for delaer request" Aug 31 22:44:12 volumio volumio[1006]: SPOTIFY: received: {"type":"metadata","data":{"uri":"spotify:track:5PzWVmfzu7rePAuFkxPQf0","name":"Repeat Until Death","artist_names":["Novo Amor"],"album_name":"Birthplace","album_cover_url":"https://i.scdn.co/image/ab67616d00001e02bb7f4860ea8f7f6515756252","position":48924,"duration":234080,"release_date":"year:2018 month:10 day:19","track_number":9,"disc_number":1}} Aug 31 22:44:12 volumio go-librespot[1182]: time="2024-08-31T22:44:12+09:30" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Aug 31 22:44:12 volumio volumio[1006]: SPOTIFY: received: {"type":"active","data":null} Aug 31 22:44:12 volumio volumio[1006]: info: Aligning Spotify Volume to Volumio Volume Aug 31 22:44:12 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState Aug 31 22:44:12 volumio volumio[1006]: info: CorePlayQueue::getTrack 0 Aug 31 22:44:12 volumio volumio[1006]: info: Setting Spotify Volume from Volumio: 84 Aug 31 22:44:12 volumio go-librespot[1182]: time="2024-08-31T22:44:12+09:30" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Aug 31 22:44:12 volumio go-librespot[1182]: time="2024-08-31T22:44:12+09:30" level=debug msg="skipping dealer message" uri=social-connect/v2/session_update Aug 31 22:44:12 volumio go-librespot[1182]: time="2024-08-31T22:44:12+09:30" level=debug msg="fetched chunk 4/14, size: 524288" Aug 31 22:44:12 volumio go-librespot[1182]: time="2024-08-31T22:44:12+09:30" level=debug msg="fetched chunk 3/14, size: 524288" Aug 31 22:44:12 volumio go-librespot[1182]: time="2024-08-31T22:44:12+09:30" level=debug msg="fetched chunk 1/14, size: 524288" Aug 31 22:44:12 volumio go-librespot[1182]: time="2024-08-31T22:44:12+09:30" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Aug 31 22:44:12 volumio go-librespot[1182]: time="2024-08-31T22:44:12+09:30" level=trace msg="emitting websocket event: paused" Aug 31 22:44:12 volumio volumio[1006]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:5PzWVmfzu7rePAuFkxPQf0","play_origin":"collection-songs"}} Aug 31 22:44:12 volumio volumio[1006]: info: Spotify is playing in volatile mode Aug 31 22:44:12 volumio volumio[1006]: info: CoreStateMachine::setConsumeUpdateService undefined Aug 31 22:44:12 volumio volumio[1006]: SPOTIFY: UNSET VOLATILE Aug 31 22:44:12 volumio volumio[1006]: SPOTIFY: {"status":"play","position":0,"title":"Temple of the Dog - Pushin' Forward Back","artist":"90s90s Grunge","album":"","albumart":"https://is2-ssl.mzstatic.com/image/thumb/Music128/v4/f9/be/88/f9be889e-af9c-7a36-3a67-7fbb11baaecd/source/600x600bb.jpg","uri":"http://streams.90s90s.de/grunge/mp3-192/volumio","trackType":"80s80s Radio","seek":29484,"duration":"220","samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2,"random":null,"repeat":null,"repeatSingle":false,"consume":false,"volume":84,"dbVolume":null,"disableVolumeControl":false,"mute":false,"stream":"80s80s Radio","volatile":false,"service":"80s80s"} Aug 31 22:44:12 volumio volumio[1006]: info: Setting Spotify stop after unset volatile call Aug 31 22:44:12 volumio volumio[1006]: SPOTIFY: PUSH STATE SPOTIFY Aug 31 22:44:12 volumio volumio[1006]: SPOTIFY: {"status":"pause","service":"spop","title":"Repeat Until Death","artist":"Novo Amor","album":"Birthplace","albumart":"https://i.scdn.co/image/ab67616d00001e02bb7f4860ea8f7f6515756252","uri":"spotify:track:5PzWVmfzu7rePAuFkxPQf0","trackType":"spotify","seek":48924,"duration":234,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null} Aug 31 22:44:12 volumio volumio[1006]: info: CoreCommandRouter::servicePushState Aug 31 22:44:12 volumio volumio[1006]: info: CoreStateMachine::pushState Aug 31 22:44:12 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 31 22:44:12 volumio volumio[1006]: info: CoreCommandRouter::volumioPushState Aug 31 22:44:12 volumio volumio[1006]: SPOTIFY: RECEIVED VOLUMIO VOLUME 84 Aug 31 22:44:12 volumio go-librespot[1182]: time="2024-08-31T22:44:12+09:30" level=debug msg="fetched chunk 5/14, size: 524288" Aug 31 22:44:12 volumio volumio[1006]: info: Spotify Stop Aug 31 22:44:12 volumio volumio[1006]: SPOTIFY: SPOTIFY STOP Aug 31 22:44:12 volumio volumio[1006]: SPOTIFY: {"status":"pause","title":"Repeat Until Death","artist":"Novo Amor","album":"Birthplace","albumart":"https://i.scdn.co/image/ab67616d00001e02bb7f4860ea8f7f6515756252","uri":"spotify:track:5PzWVmfzu7rePAuFkxPQf0","trackType":"spotify","codec":"ogg","seek":48924,"duration":234,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2,"random":null,"repeat":null,"repeatSingle":null,"consume":false,"volume":84,"dbVolume":null,"mute":false,"disableVolumeControl":false,"stream":false,"volatile":true,"service":"spop"} Aug 31 22:44:12 volumio go-librespot[1182]: time="2024-08-31T22:44:12+09:30" level=debug msg="handling resume player command from f80df98ffc0e23d08eac21d05ab533ec36d57bb0" Aug 31 22:44:12 volumio go-librespot[1182]: time="2024-08-31T22:44:12+09:30" level=trace msg="seek to 48924ms (diff: 158ms, samples: 2157548, bytes: 1494028)" Aug 31 22:44:12 volumio go-librespot[1182]: time="2024-08-31T22:44:12+09:30" level=debug msg="resume track at 48397ms" Aug 31 22:44:13 volumio go-librespot[1182]: time="2024-08-31T22:44:13+09:30" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Aug 31 22:44:13 volumio go-librespot[1182]: time="2024-08-31T22:44:13+09:30" level=debug msg="sending successful reply for delaer request" Aug 31 22:44:13 volumio go-librespot[1182]: time="2024-08-31T22:44:13+09:30" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Aug 31 22:44:13 volumio go-librespot[1182]: time="2024-08-31T22:44:13+09:30" level=trace msg="emitting websocket event: playing" Aug 31 22:44:13 volumio volumio[1006]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:5PzWVmfzu7rePAuFkxPQf0","play_origin":"collection-songs"}} Aug 31 22:44:13 volumio volumio[1006]: SPOTIFY: PUSH STATE SPOTIFY Aug 31 22:44:13 volumio volumio[1006]: SPOTIFY: {"status":"play","service":"spop","title":"Repeat Until Death","artist":"Novo Amor","album":"Birthplace","albumart":"https://i.scdn.co/image/ab67616d00001e02bb7f4860ea8f7f6515756252","uri":"spotify:track:5PzWVmfzu7rePAuFkxPQf0","trackType":"spotify","seek":48924,"duration":234,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Aug 31 22:44:13 volumio volumio[1006]: info: CoreCommandRouter::servicePushState Aug 31 22:44:13 volumio volumio[1006]: info: CoreStateMachine::pushState Aug 31 22:44:13 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 31 22:44:13 volumio volumio[1006]: info: CoreCommandRouter::volumioPushState Aug 31 22:44:13 volumio volumio[1006]: SPOTIFY: RECEIVED VOLUMIO VOLUME 84 Aug 31 22:44:13 volumio volumio[1006]: SPOTIFY: PUSH STATE SPOTIFY Aug 31 22:44:13 volumio volumio[1006]: SPOTIFY: {"status":"play","service":"spop","title":"Repeat Until Death","artist":"Novo Amor","album":"Birthplace","albumart":"https://i.scdn.co/image/ab67616d00001e02bb7f4860ea8f7f6515756252","uri":"spotify:track:5PzWVmfzu7rePAuFkxPQf0","trackType":"spotify","seek":48924,"duration":234,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Aug 31 22:44:13 volumio volumio[1006]: info: CoreCommandRouter::servicePushState Aug 31 22:44:13 volumio volumio[1006]: info: CoreStateMachine::pushState Aug 31 22:44:13 volumio volumio[1006]: info: CoreCommandRouter::volumioPushState Aug 31 22:44:13 volumio volumio[1006]: SPOTIFY: RECEIVED VOLUMIO VOLUME 84 Aug 31 22:44:13 volumio volumio[1006]: SPOTIFY: SETTING SPOTIFY VOLUME 84 Aug 31 22:44:13 volumio volumio[1006]: info: Sending Spotify command with payload to local API: /player/volume Aug 31 22:44:13 volumio go-librespot[1182]: time="2024-08-31T22:44:13+09:30" level=debug msg="update volume to 55049/65535" Aug 31 22:44:13 volumio go-librespot[1182]: time="2024-08-31T22:44:13+09:30" level=debug msg="put connect state because VOLUME_CHANGED" Aug 31 22:44:13 volumio go-librespot[1182]: time="2024-08-31T22:44:13+09:30" level=trace msg="emitting websocket event: volume" Aug 31 22:44:13 volumio volumio[1006]: SPOTIFY: received: {"type":"volume","data":{"value":84,"max":100}} Aug 31 22:44:13 volumio volumio[1006]: SPOTIFY: RECEIVED SPOTIFY VOLUME 84 Aug 31 22:44:15 volumio go-librespot[1182]: time="2024-08-31T22:44:15+09:30" level=debug msg="fetched chunk 6/14, size: 524288" Aug 31 22:44:31 volumio go-librespot[1182]: time="2024-08-31T22:44:31+09:30" level=debug msg="fetched chunk 7/14, size: 524288" Aug 31 22:44:40 volumio go-librespot[1182]: time="2024-08-31T22:44:40+09:30" level=debug msg="handling pause player command from f80df98ffc0e23d08eac21d05ab533ec36d57bb0" Aug 31 22:44:40 volumio go-librespot[1182]: time="2024-08-31T22:44:40+09:30" level=debug msg="pause track at 76277ms" Aug 31 22:44:41 volumio go-librespot[1182]: time="2024-08-31T22:44:41+09:30" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Aug 31 22:44:41 volumio go-librespot[1182]: time="2024-08-31T22:44:41+09:30" level=debug msg="sending successful reply for delaer request" Aug 31 22:44:41 volumio go-librespot[1182]: time="2024-08-31T22:44:41+09:30" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Aug 31 22:44:41 volumio go-librespot[1182]: time="2024-08-31T22:44:41+09:30" level=trace msg="emitting websocket event: paused" Aug 31 22:44:41 volumio volumio[1006]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:5PzWVmfzu7rePAuFkxPQf0","play_origin":"collection-songs"}} Aug 31 22:44:41 volumio volumio[1006]: SPOTIFY: PUSH STATE SPOTIFY Aug 31 22:44:41 volumio volumio[1006]: SPOTIFY: {"status":"pause","service":"spop","title":"Repeat Until Death","artist":"Novo Amor","album":"Birthplace","albumart":"https://i.scdn.co/image/ab67616d00001e02bb7f4860ea8f7f6515756252","uri":"spotify:track:5PzWVmfzu7rePAuFkxPQf0","trackType":"spotify","seek":75924,"duration":234,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Aug 31 22:44:41 volumio volumio[1006]: info: CoreCommandRouter::servicePushState Aug 31 22:44:41 volumio volumio[1006]: info: CoreStateMachine::pushState Aug 31 22:44:41 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 31 22:44:41 volumio volumio[1006]: info: CoreCommandRouter::volumioPushState Aug 31 22:44:41 volumio volumio[1006]: SPOTIFY: RECEIVED VOLUMIO VOLUME 84 Aug 31 22:44:47 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 31 22:44:47 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 31 22:44:47 volumio volumio[1006]: info: Discovery: Getting this device information Aug 31 22:44:47 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState Aug 31 22:44:47 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 31 22:44:47 volumio volumio[1006]: verbose: New Socket.io Connection to 192.168.1.114:3000 from 192.168.1.107 UA: Dart/3.4 (dart:io) Engine version: 3 Transport: websocket Total Clients: 5 Aug 31 22:44:47 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState Aug 31 22:44:47 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Aug 31 22:44:47 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Aug 31 22:44:48 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 31 22:44:48 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 31 22:44:48 volumio volumio[1006]: info: Discovery: Getting this device information Aug 31 22:44:48 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState Aug 31 22:44:48 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 31 22:44:50 volumio sudo[2375]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 31 22:44:50 volumio sudo[2375]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 22:44:50 volumio sudo[2375]: pam_unix(sudo:session): session closed for user root Aug 31 22:44:50 volumio sudo[2377]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 31 22:44:50 volumio sudo[2377]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 22:44:50 volumio sudo[2377]: pam_unix(sudo:session): session closed for user root Aug 31 22:44:50 volumio volumio[1006]: verbose: New Socket.io Connection to 192.168.1.114 from 192.168.1.107 UA: Mozilla/5.0 (Linux; Android 14; SM-S918B Build/UP1A.231005.007; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/127.0.6533.105 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 6 Aug 31 22:44:51 volumio sudo[2383]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Aug 31 22:44:51 volumio sudo[2383]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 22:44:51 volumio sudo[2383]: pam_unix(sudo:session): session closed for user root Aug 31 22:44:51 volumio sudo[2386]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Aug 31 22:44:51 volumio sudo[2386]: pam_unix(sudo:session): session opened for user root by (uid=0) Aug 31 22:44:51 volumio sudo[2386]: pam_unix(sudo:session): session closed for user root Aug 31 22:44:51 volumio volumio[1006]: verbose: New Socket.io Connection to 192.168.1.114 from 192.168.1.107 UA: Mozilla/5.0 (Linux; Android 14; SM-S918B Build/UP1A.231005.007; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/127.0.6533.105 Mobile Safari/537.36 Engine version: 3 Transport: polling Total Clients: 7 Aug 31 22:44:51 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Aug 31 22:44:52 volumio volumio[1006]: info: CoreCommandRouter::volumioGetVisibleSources Aug 31 22:44:52 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Aug 31 22:44:52 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState Aug 31 22:44:52 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Aug 31 22:44:52 volumio volumio[1006]: info: CoreCommandRouter::volumioGetQueue Aug 31 22:44:52 volumio volumio[1006]: info: CoreStateMachine::getQueue Aug 31 22:44:52 volumio volumio[1006]: info: CorePlayQueue::getQueue Aug 31 22:44:52 volumio volumio[1006]: info: Listing playlists Aug 31 22:44:52 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Aug 31 22:44:52 volumio volumio[1006]: info: Received Get System Info Aug 31 22:44:52 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 31 22:44:52 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 31 22:44:52 volumio volumio[1006]: info: Discovery: Getting this device information Aug 31 22:44:52 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState Aug 31 22:44:52 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 31 22:44:52 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState Aug 31 22:44:52 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Aug 31 22:44:52 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Aug 31 22:44:52 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Aug 31 22:44:53 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 31 22:44:53 volumio volumio[1006]: info: Received Get System Info Aug 31 22:44:53 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 31 22:44:53 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 31 22:44:53 volumio volumio[1006]: info: Discovery: Getting this device information Aug 31 22:44:53 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState Aug 31 22:44:53 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 31 22:44:53 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: wizard , getOnboardingWizard Aug 31 22:44:53 volumio volumio[1006]: info: CoreCommandRouter::volumioVolatilePlay Aug 31 22:44:53 volumio volumio[1006]: info: CoreStateMachine::volatilePlay Aug 31 22:44:53 volumio volumio[1006]: info: Spotify Play Aug 31 22:44:53 volumio volumio[1006]: info: Sending Spotify command to local API: /player/resume Aug 31 22:44:53 volumio go-librespot[1182]: time="2024-08-31T22:44:53+09:30" level=trace msg="seek to 76277ms (diff: 74ms, samples: 3363815, bytes: 2372029)" Aug 31 22:44:53 volumio go-librespot[1182]: time="2024-08-31T22:44:53+09:30" level=debug msg="resume track at 75834ms" Aug 31 22:44:54 volumio go-librespot[1182]: time="2024-08-31T22:44:54+09:30" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Aug 31 22:44:54 volumio go-librespot[1182]: time="2024-08-31T22:44:54+09:30" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Aug 31 22:44:54 volumio go-librespot[1182]: time="2024-08-31T22:44:54+09:30" level=trace msg="emitting websocket event: playing" Aug 31 22:44:54 volumio volumio[1006]: SPOTIFY: received: {"type":"playing","data":{"uri":"spotify:track:5PzWVmfzu7rePAuFkxPQf0","play_origin":"collection-songs"}} Aug 31 22:44:54 volumio volumio[1006]: SPOTIFY: PUSH STATE SPOTIFY Aug 31 22:44:54 volumio volumio[1006]: SPOTIFY: {"status":"play","service":"spop","title":"Repeat Until Death","artist":"Novo Amor","album":"Birthplace","albumart":"https://i.scdn.co/image/ab67616d00001e02bb7f4860ea8f7f6515756252","uri":"spotify:track:5PzWVmfzu7rePAuFkxPQf0","trackType":"spotify","seek":75924,"duration":234,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Aug 31 22:44:54 volumio volumio[1006]: info: CoreCommandRouter::servicePushState Aug 31 22:44:54 volumio volumio[1006]: info: CoreStateMachine::pushState Aug 31 22:44:54 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 31 22:44:54 volumio volumio[1006]: info: CoreCommandRouter::volumioPushState Aug 31 22:44:54 volumio volumio[1006]: SPOTIFY: RECEIVED VOLUMIO VOLUME 84 Aug 31 22:44:54 volumio volumio[1006]: SPOTIFY: PUSH STATE SPOTIFY Aug 31 22:44:54 volumio volumio[1006]: SPOTIFY: {"status":"play","service":"spop","title":"Repeat Until Death","artist":"Novo Amor","album":"Birthplace","albumart":"https://i.scdn.co/image/ab67616d00001e02bb7f4860ea8f7f6515756252","uri":"spotify:track:5PzWVmfzu7rePAuFkxPQf0","trackType":"spotify","seek":75924,"duration":234,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Aug 31 22:44:54 volumio volumio[1006]: info: CoreCommandRouter::servicePushState Aug 31 22:44:54 volumio volumio[1006]: info: CoreStateMachine::pushState Aug 31 22:44:54 volumio volumio[1006]: info: CoreCommandRouter::volumioPushState Aug 31 22:44:54 volumio volumio[1006]: SPOTIFY: RECEIVED VOLUMIO VOLUME 84 Aug 31 22:44:54 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Aug 31 22:44:54 volumio volumio[1006]: info: Received Get System Info Aug 31 22:44:54 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 31 22:44:54 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 31 22:44:54 volumio volumio[1006]: info: Discovery: Getting this device information Aug 31 22:44:54 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState Aug 31 22:44:54 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 31 22:44:58 volumio volumio[1006]: info: CoreCommandRouter::volumioPause Aug 31 22:44:58 volumio volumio[1006]: info: CoreStateMachine::pause Aug 31 22:44:58 volumio volumio[1006]: info: CoreStateMachine::stPlaybackTimer Aug 31 22:44:58 volumio volumio[1006]: info: CoreStateMachine::servicePause Aug 31 22:44:58 volumio volumio[1006]: info: CoreCommandRouter::servicePause Aug 31 22:44:58 volumio volumio[1006]: info: Spotify Received pause Aug 31 22:44:58 volumio volumio[1006]: SPOTIFY: SPOTIFY PAUSE Aug 31 22:44:58 volumio volumio[1006]: SPOTIFY: {"status":"play","title":"Repeat Until Death","artist":"Novo Amor","album":"Birthplace","albumart":"https://i.scdn.co/image/ab67616d00001e02bb7f4860ea8f7f6515756252","uri":"spotify:track:5PzWVmfzu7rePAuFkxPQf0","trackType":"spotify","codec":"ogg","seek":75924,"duration":234,"samplerate":"44.1 KHz","bitdepth":"16 bit","channels":2,"random":null,"repeat":null,"repeatSingle":null,"consume":false,"volume":84,"dbVolume":null,"mute":false,"disableVolumeControl":false,"stream":false,"volatile":true,"service":"spop"} Aug 31 22:44:58 volumio volumio[1006]: info: Sending Spotify command to local API: /player/pause Aug 31 22:44:58 volumio go-librespot[1182]: time="2024-08-31T22:44:58+09:30" level=debug msg="pause track at 80432ms" Aug 31 22:44:58 volumio go-librespot[1182]: time="2024-08-31T22:44:58+09:30" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Aug 31 22:44:58 volumio go-librespot[1182]: time="2024-08-31T22:44:58+09:30" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Aug 31 22:44:58 volumio go-librespot[1182]: time="2024-08-31T22:44:58+09:30" level=trace msg="emitting websocket event: paused" Aug 31 22:44:58 volumio volumio[1006]: SPOTIFY: received: {"type":"paused","data":{"uri":"spotify:track:5PzWVmfzu7rePAuFkxPQf0","play_origin":"collection-songs"}} Aug 31 22:44:58 volumio volumio[1006]: SPOTIFY: PUSH STATE SPOTIFY Aug 31 22:44:58 volumio volumio[1006]: SPOTIFY: {"status":"pause","service":"spop","title":"Repeat Until Death","artist":"Novo Amor","album":"Birthplace","albumart":"https://i.scdn.co/image/ab67616d00001e02bb7f4860ea8f7f6515756252","uri":"spotify:track:5PzWVmfzu7rePAuFkxPQf0","trackType":"spotify","seek":79924,"duration":234,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Aug 31 22:44:58 volumio volumio[1006]: info: CoreCommandRouter::servicePushState Aug 31 22:44:58 volumio volumio[1006]: info: CoreStateMachine::pushState Aug 31 22:44:58 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 31 22:44:58 volumio volumio[1006]: info: CoreCommandRouter::volumioPushState Aug 31 22:44:58 volumio volumio[1006]: SPOTIFY: RECEIVED VOLUMIO VOLUME 84 Aug 31 22:45:01 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: appearance , isLatestTOSAccepted Aug 31 22:45:04 volumio volumio[1006]: info: CoreCommandRouter::volumioSeek Aug 31 22:45:04 volumio volumio[1006]: info: CoreStateMachine::seek Aug 31 22:45:04 volumio volumio[1006]: info: Spotify seek to: 2000 Aug 31 22:45:04 volumio volumio[1006]: info: Sending Spotify command with payload to local API: /player/seek Aug 31 22:45:04 volumio volumio[1006]: info: CoreStateMachine::startPlaybackTimer Aug 31 22:45:04 volumio volumio[1006]: info: CorePlayQueue::getTrack 0 Aug 31 22:45:04 volumio volumio[1006]: info: CoreStateMachine::pushState Aug 31 22:45:04 volumio volumio[1006]: info: CoreCommandRouter::volumioPushState Aug 31 22:45:04 volumio volumio[1006]: SPOTIFY: RECEIVED VOLUMIO VOLUME 84 Aug 31 22:45:04 volumio go-librespot[1182]: time="2024-08-31T22:45:04+09:30" level=debug msg="seek track to 2000ms" Aug 31 22:45:04 volumio go-librespot[1182]: time="2024-08-31T22:45:04+09:30" level=trace msg="seek to 2000ms (diff: 107ms, samples: 88200, bytes: 51084)" Aug 31 22:45:04 volumio go-librespot[1182]: time="2024-08-31T22:45:04+09:30" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Aug 31 22:45:04 volumio go-librespot[1182]: time="2024-08-31T22:45:04+09:30" level=trace msg="emitting websocket event: seek" Aug 31 22:45:04 volumio volumio[1006]: SPOTIFY: received: {"type":"seek","data":{"uri":"spotify:track:5PzWVmfzu7rePAuFkxPQf0","position":2000,"duration":234080,"play_origin":"collection-songs"}} Aug 31 22:45:04 volumio volumio[1006]: SPOTIFY: PUSH STATE SPOTIFY Aug 31 22:45:04 volumio volumio[1006]: SPOTIFY: {"status":"pause","service":"spop","title":"Repeat Until Death","artist":"Novo Amor","album":"Birthplace","albumart":"https://i.scdn.co/image/ab67616d00001e02bb7f4860ea8f7f6515756252","uri":"spotify:track:5PzWVmfzu7rePAuFkxPQf0","trackType":"spotify","seek":2000,"duration":234,"samplerate":"44.1 KHz","bitdepth":"16 bit","bitrate":"320 kbps","codec":"ogg","channels":2,"random":null,"repeat":null,"repeatSingle":null,"stream":false,"repeatMode":"all"} Aug 31 22:45:04 volumio volumio[1006]: info: CoreCommandRouter::servicePushState Aug 31 22:45:04 volumio volumio[1006]: info: CoreStateMachine::pushState Aug 31 22:45:04 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Aug 31 22:45:04 volumio volumio[1006]: info: CoreCommandRouter::volumioPushState Aug 31 22:45:04 volumio volumio[1006]: SPOTIFY: RECEIVED VOLUMIO VOLUME 84 Aug 31 22:45:10 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Aug 31 22:45:10 volumio volumio[1006]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Aug 31 22:45:10 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Aug 31 22:45:10 volumio volumio[1006]: info: Received Get System Version Aug 31 22:45:10 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Aug 31 22:45:10 volumio volumio[1006]: info: Received Get System Info Aug 31 22:45:10 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Aug 31 22:45:10 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Aug 31 22:45:10 volumio volumio[1006]: info: Discovery: Getting this device information Aug 31 22:45:10 volumio volumio[1006]: info: CoreCommandRouter::volumioGetState Aug 31 22:45:10 volumio volumio[1006]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Aug 31 22:45:13 volumio volumio[1006]: info: [1725110113473] [80s80s] Pushing the next song state Temple of the Dog - Pushin' Forward Back and getting next track. Aug 31 22:45:13 volumio volumio[1006]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 31 22:45:13 volumio volumio[1006]: TypeError: Cannot set property 'name' of undefined Aug 31 22:45:13 volumio volumio[1006]: at Controller80s80s.pushSongState (/data/plugins/music_service/80s80s/index.js:565:20) Aug 31 22:45:13 volumio volumio[1006]: at Controller80s80s.playNextTrack (/data/plugins/music_service/80s80s/index.js:665:34) Aug 31 22:45:13 volumio volumio[1006]: at NanoTimer.setTimeout (/data/plugins/music_service/80s80s/node_modules/nanotimer/lib/nanotimer.js:343:9) Aug 31 22:45:13 volumio volumio[1006]: at Immediate. (/data/plugins/music_service/80s80s/node_modules/nanotimer/lib/nanotimer.js:327:66) Aug 31 22:45:13 volumio volumio[1006]: at processImmediate (internal/timers.js:461:21) Aug 31 22:45:13 volumio volumio[1006]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Aug 31 22:45:14 volumio sudo[2440]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2024-08-31 22:44 Aug 31 22:45:14 volumio sudo[2440]: 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="5fd3886148e72a9cecd88a772d1f6079fb64d11a" VOLUMIO_FE_VERSION="e7cae168f9927391640a091813b8a9656b6909b6" VOLUMIO_FE3_VERSION="df82a8f23c90a3617c15c55572c8aaea90d8b32a" VOLUMIO_BE_VERSION="8bb23b009e91ae4c7ecd678f193e7d3b281fca0c" VOLUMIO_ARCH="arm" VOLUMIO_VARIANT="volumio" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Mon 22 Jul 2024 07:17:01 PM CEST" VOLUMIO_VERSION="3.742" VOLUMIO_HARDWARE="pi" VOLUMIO_DEVICENAME="Raspberry Pi" VOLUMIO_HASH="2782e52360f70dfab079c82951ebbbb1"