-- Logs begin at Tue 2026-04-21 16:51:35 CEST, end at Mon 2026-10-12 15:59:07 CEST. -- Oct 12 15:58:00 salavrx volumio[712]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 12 15:58:00 salavrx volumio[712]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 12 15:58:00 salavrx volumio[712]: info: Discovery: Getting this device information Oct 12 15:58:00 salavrx volumio[712]: info: CoreCommandRouter::volumioGetState Oct 12 15:58:00 salavrx volumio[712]: info: CorePlayQueue::getTrack 0 Oct 12 15:58:00 salavrx volumio[712]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 12 15:58:00 salavrx volumio[712]: verbose: New Socket.io Connection to 192.168.178.29:3000 from 192.168.178.85 UA: Dart/3.12 (dart:io) Engine version: 3 Transport: websocket Total Clients: 9 Oct 12 15:58:00 salavrx volumio[712]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Oct 12 15:58:00 salavrx volumio[712]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Oct 12 15:58:01 salavrx volumio[712]: verbose: New Socket.io Connection to 192.168.178.29:3000 from 192.168.178.85 UA: Dart/3.12 (dart:io) Engine version: 3 Transport: websocket Total Clients: 9 Oct 12 15:58:01 salavrx volumio[712]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 12 15:58:01 salavrx volumio[712]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 12 15:58:01 salavrx volumio[712]: info: Discovery: Getting this device information Oct 12 15:58:01 salavrx volumio[712]: info: CoreCommandRouter::volumioGetState Oct 12 15:58:01 salavrx volumio[712]: info: CorePlayQueue::getTrack 0 Oct 12 15:58:01 salavrx volumio[712]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 12 15:58:01 salavrx volumio[712]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 12 15:58:01 salavrx volumio[712]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 12 15:58:01 salavrx volumio[712]: info: Discovery: Getting this device information Oct 12 15:58:01 salavrx volumio[712]: info: CoreCommandRouter::volumioGetState Oct 12 15:58:01 salavrx volumio[712]: info: CorePlayQueue::getTrack 0 Oct 12 15:58:01 salavrx volumio[712]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 12 15:58:01 salavrx volumio[712]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Oct 12 15:58:01 salavrx volumio[712]: info: CoreCommandRouter::executeOnPlugin: appearance , getAvailableLanguages Oct 12 15:58:01 salavrx volumio[712]: info: CoreCommandRouter::executeOnPlugin: system , getCurrentTimezone Oct 12 15:58:01 salavrx volumio[712]: info: CoreCommandRouter::executeOnPlugin: network , getInfoNetwork Oct 12 15:58:01 salavrx sudo[2105]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ethtool eth0 Oct 12 15:58:01 salavrx sudo[2105]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 12 15:58:01 salavrx sudo[2105]: pam_unix(sudo:session): session closed for user root Oct 12 15:58:01 salavrx sudo[2110]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Oct 12 15:58:01 salavrx sudo[2110]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 12 15:58:01 salavrx sudo[2118]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Oct 12 15:58:01 salavrx sudo[2118]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 12 15:58:01 salavrx sudo[2110]: pam_unix(sudo:session): session closed for user root Oct 12 15:58:01 salavrx sudo[2125]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Oct 12 15:58:01 salavrx sudo[2125]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 12 15:58:01 salavrx sudo[2135]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 12 15:58:01 salavrx sudo[2135]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 12 15:58:01 salavrx sudo[2118]: pam_unix(sudo:session): session closed for user root Oct 12 15:58:01 salavrx sudo[2135]: pam_unix(sudo:session): session closed for user root Oct 12 15:58:01 salavrx sudo[2144]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 12 15:58:01 salavrx sudo[2125]: pam_unix(sudo:session): session closed for user root Oct 12 15:58:01 salavrx sudo[2144]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 12 15:58:01 salavrx sudo[2144]: pam_unix(sudo:session): session closed for user root Oct 12 15:58:01 salavrx volumio[712]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Oct 12 15:58:01 salavrx volumio[712]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Oct 12 15:58:01 salavrx volumio[712]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 12 15:58:01 salavrx volumio[712]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 12 15:58:01 salavrx volumio[712]: info: Discovery: Getting this device information Oct 12 15:58:01 salavrx volumio[712]: info: CoreCommandRouter::volumioGetState Oct 12 15:58:01 salavrx volumio[712]: info: CorePlayQueue::getTrack 0 Oct 12 15:58:01 salavrx volumio[712]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 12 15:58:01 salavrx volumio[712]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 12 15:58:01 salavrx volumio[712]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 12 15:58:01 salavrx volumio[712]: info: Discovery: Getting this device information Oct 12 15:58:01 salavrx volumio[712]: info: CoreCommandRouter::volumioGetState Oct 12 15:58:01 salavrx volumio[712]: info: CorePlayQueue::getTrack 0 Oct 12 15:58:01 salavrx volumio[712]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 12 15:58:01 salavrx volumio[712]: info: CoreCommandRouter::volumioGetState Oct 12 15:58:01 salavrx volumio[712]: info: CorePlayQueue::getTrack 0 Oct 12 15:58:01 salavrx volumio[712]: verbose: New Socket.io Connection to 192.168.178.29:3000 from 192.168.178.85 UA: Dart/3.12 (dart:io) Engine version: 3 Transport: websocket Total Clients: 10 Oct 12 15:58:01 salavrx volumio[712]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Oct 12 15:58:01 salavrx volumio[712]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Oct 12 15:58:03 salavrx volumio[712]: verbose: New Socket.io Connection to 192.168.178.29 from 192.168.178.85 UA: Mozilla/5.0 (Linux; Android 16; SM-A556B Build/BP4A.251205.006; wv) AppleWebKit/537.36 (KHTML, like Gecko) Version/4.0 Chrome/153.0.8010.36 Mobile Safari/537.36 VolumioApp/6.260930.0 Engine version: 3 Transport: polling Total Clients: 10 Oct 12 15:58:03 salavrx volumio[712]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getAutoUpdateCheckEnabled Oct 12 15:58:03 salavrx volumio[712]: info: CoreCommandRouter::volumioGetVisibleSources Oct 12 15:58:03 salavrx volumio[712]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Oct 12 15:58:03 salavrx volumio[712]: info: CoreCommandRouter::volumioGetState Oct 12 15:58:03 salavrx volumio[712]: info: CorePlayQueue::getTrack 0 Oct 12 15:58:03 salavrx volumio[712]: info: CoreCommandRouter::executeOnPlugin: metavolumio , getInfinityPlayback Oct 12 15:58:03 salavrx volumio[712]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Oct 12 15:58:03 salavrx volumio[712]: info: CoreCommandRouter::executeOnPlugin: inputs , handleBrowseUri Oct 12 15:58:03 salavrx volumio[712]: info: Received Get System Info Oct 12 15:58:03 salavrx volumio[712]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 12 15:58:03 salavrx volumio[712]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 12 15:58:03 salavrx volumio[712]: info: Discovery: Getting this device information Oct 12 15:58:03 salavrx volumio[712]: info: CoreCommandRouter::volumioGetState Oct 12 15:58:03 salavrx volumio[712]: info: CorePlayQueue::getTrack 0 Oct 12 15:58:03 salavrx volumio[712]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 12 15:58:03 salavrx volumio[712]: info: CoreCommandRouter::volumioGetState Oct 12 15:58:03 salavrx volumio[712]: info: CorePlayQueue::getTrack 0 Oct 12 15:58:03 salavrx volumio[712]: info: Listing playlists Oct 12 15:58:03 salavrx volumio[712]: info: CoreCommandRouter::volumioGetQueue Oct 12 15:58:03 salavrx volumio[712]: info: CoreStateMachine::getQueue Oct 12 15:58:03 salavrx volumio[712]: info: CorePlayQueue::getQueue Oct 12 15:58:03 salavrx volumio[712]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Oct 12 15:58:04 salavrx go-librespot[1210]: time="2026-10-12T15:58:04+02:00" level=debug msg="obtained new client token: AAFRXRWTCypFHtIuWpxYfTfG/rjgQwGNuFgkH0t815EoLifN35SIR8OnGZIieUqkEcf54IwNda8KuN1zv+SpSUpZEwBRF4QZBlvD5y6PLVyvmDq+VXPMAyNVFl+cE3DS5A5MSfckuFNKWQkNkFhUzaojYWWddXzd15S7LjUDnMjqFyD+klbezIu+XuFj0UQ6+8YEkfF1fnorFHd2Vohum0OX9cdNirxeeEM1LcGFjLIWcyD88DE9zgEb" Oct 12 15:58:04 salavrx go-librespot[1210]: time="2026-10-12T15:58:04+02:00" level=debug msg="connected to ap-gew4.spotify.com:4070" Oct 12 15:58:04 salavrx go-librespot[1210]: time="2026-10-12T15:58:04+02:00" level=debug msg="completed keyexchange" Oct 12 15:58:04 salavrx go-librespot[1210]: time="2026-10-12T15:58:04+02:00" level=debug msg="completed challenge" Oct 12 15:58:04 salavrx go-librespot[1210]: time="2026-10-12T15:58:04+02:00" level=info msg="authenticated AP" username="31************************ta" Oct 12 15:58:04 salavrx go-librespot[1210]: time="2026-10-12T15:58:04+02:00" level=info msg="authenticated Login5" username="31************************ta" Oct 12 15:58:04 salavrx go-librespot[1210]: time="2026-10-12T15:58:04+02:00" level=info msg="accepted zeroconf from SM-A556B" username="31************************ta" Oct 12 15:58:05 salavrx go-librespot[1210]: time="2026-10-12T15:58:05+02:00" level=debug msg="dealer connection opened" Oct 12 15:58:05 salavrx go-librespot[1210]: time="2026-10-12T15:58:05+02:00" level=trace msg="starting accesspoint recv loop" Oct 12 15:58:05 salavrx go-librespot[1210]: time="2026-10-12T15:58:05+02:00" level=trace msg="starting dealer recv loop" Oct 12 15:58:05 salavrx go-librespot[1210]: time="2026-10-12T15:58:05+02:00" level=trace msg="received accesspoint ping" Oct 12 15:58:05 salavrx go-librespot[1210]: time="2026-10-12T15:58:05+02:00" level=debug msg="skipping packet PacketTypeSecretBlock, len: 336" Oct 12 15:58:05 salavrx go-librespot[1210]: time="2026-10-12T15:58:05+02:00" level=debug msg="skipping packet PacketTypeLicenseVersion, len: 2" Oct 12 15:58:05 salavrx go-librespot[1210]: time="2026-10-12T15:58:05+02:00" level=debug msg="skipping packet PacketTypeUnknown1f, len: 17" Oct 12 15:58:05 salavrx go-librespot[1210]: time="2026-10-12T15:58:05+02:00" level=debug msg="skipping packet PacketTypeLegacyWelcome, len: 0" Oct 12 15:58:05 salavrx go-librespot[1210]: time="2026-10-12T15:58:05+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 481" Oct 12 15:58:05 salavrx go-librespot[1210]: time="2026-10-12T15:58:05+02:00" level=debug msg="received connection id: ZmYwMzRkNDUtNTk1...NzYxMDI1RUQ3RQ==" Oct 12 15:58:05 salavrx go-librespot[1210]: time="2026-10-12T15:58:05+02:00" level=trace msg="received accesspoint pong ack" Oct 12 15:58:05 salavrx go-librespot[1210]: time="2026-10-12T15:58:05+02:00" level=debug msg="put connect state because NEW_DEVICE" Oct 12 15:58:05 salavrx go-librespot[1210]: time="2026-10-12T15:58:05+02:00" level=debug msg="update volume requested to 60292/65535" Oct 12 15:58:05 salavrx go-librespot[1210]: time="2026-10-12T15:58:05+02:00" level=debug msg="put connect state because VOLUME_CHANGED" Oct 12 15:58:05 salavrx go-librespot[1210]: time="2026-10-12T15:58:05+02:00" level=trace msg="emitting websocket event: volume" Oct 12 15:58:05 salavrx volumio[712]: info: Setting Volumio Volume from Spotify: 92 Oct 12 15:58:05 salavrx volumio[712]: info: CoreCommandRouter::executeOnPlugin: inputs , setVolume Oct 12 15:58:05 salavrx volumio[712]: info: CoreStateMachine::pushState Oct 12 15:58:05 salavrx volumio[712]: info: CorePlayQueue::getTrack 0 Oct 12 15:58:05 salavrx volumio[712]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 12 15:58:05 salavrx volumio[712]: info: CoreCommandRouter::volumioPushState Oct 12 15:58:05 salavrx volumio[712]: info: CoreCommandRouter::volumioGetState Oct 12 15:58:05 salavrx volumio[712]: info: CorePlayQueue::getTrack 0 Oct 12 15:58:05 salavrx go-librespot[1210]: time="2026-10-12T15:58:05+02:00" level=debug msg="handling transfer player command from 78034bf1cab168d2452bf885b787157961c4f73f" Oct 12 15:58:05 salavrx go-librespot[1210]: time="2026-10-12T15:58:05+02:00" level=debug msg="resolved context of track" uri="spotify:playlist:4nCML7cOgIsamsRdvebFtE" Oct 12 15:58:05 salavrx go-librespot[1210]: time="2026-10-12T15:58:05+02:00" level=trace msg="fetched new page 0 with 101 items (list: 101)" uri="spotify:playlist:4nCML7cOgIsamsRdvebFtE" Oct 12 15:58:05 salavrx go-librespot[1210]: time="2026-10-12T15:58:05+02:00" level=debug msg="loading track (paused: true, position: 28380ms)" uri="spotify:track:1uQcwOAGGYIGUH6rdhP05R" Oct 12 15:58:05 salavrx go-librespot[1210]: time="2026-10-12T15:58:05+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 12 15:58:05 salavrx go-librespot[1210]: time="2026-10-12T15:58:05+02:00" level=trace msg="emitting websocket event: will_play" Oct 12 15:58:05 salavrx go-librespot[1210]: time="2026-10-12T15:58:05+02:00" level=debug msg="skipping packet PacketTypeMercuryEvent, len: 435" Oct 12 15:58:05 salavrx go-librespot[1210]: time="2026-10-12T15:58:05+02:00" level=debug msg="selected format OGG_VORBIS_320 (c3cf191235baaf4ce35d37db19826c7e6e1f7a51)" uri="spotify:track:1uQcwOAGGYIGUH6rdhP05R" Oct 12 15:58:05 salavrx go-librespot[1210]: time="2026-10-12T15:58:05+02:00" level=debug msg="requested aes key for file c3cf191235baaf4ce35d37db19826c7e6e1f7a51, gid: 1uQcwOAGGYIGUH6rdhP05R" Oct 12 15:58:05 salavrx go-librespot[1210]: time="2026-10-12T15:58:05+02:00" level=trace msg="found 2 cdn urls" uri="spotify:track:1uQcwOAGGYIGUH6rdhP05R" Oct 12 15:58:06 salavrx go-librespot[1210]: time="2026-10-12T15:58:06+02:00" level=debug msg="fetched first chunk of 23, total size is 11798100 bytes" uri="spotify:track:1uQcwOAGGYIGUH6rdhP05R" Oct 12 15:58:06 salavrx go-librespot[1210]: time="2026-10-12T15:58:06+02:00" level=debug msg="fetched chunk 2/22, size: 524288" uri="spotify:track:1uQcwOAGGYIGUH6rdhP05R" Oct 12 15:58:06 salavrx go-librespot[1210]: time="2026-10-12T15:58:06+02:00" level=debug msg="fetched chunk 1/22, size: 524288" uri="spotify:track:1uQcwOAGGYIGUH6rdhP05R" Oct 12 15:58:06 salavrx go-librespot[1210]: time="2026-10-12T15:58:06+02:00" level=trace msg="seek to 28380ms (diff: 74ms, samples: 1251558, bytes: 991546)" uri="spotify:track:1uQcwOAGGYIGUH6rdhP05R" Oct 12 15:58:06 salavrx go-librespot[1210]: time="2026-10-12T15:58:06+02:00" level=debug msg="created new output device" Oct 12 15:58:06 salavrx go-librespot[1210]: time="2026-10-12T15:58:06+02:00" level=info msg="loaded track \"Positive Mood\" (paused: true, position: 28380ms, duration: 328059ms, prefetched: false)" uri="spotify:track:1uQcwOAGGYIGUH6rdhP05R" Oct 12 15:58:06 salavrx go-librespot[1210]: time="2026-10-12T15:58:06+02:00" level=debug msg="fetched chunk 3/22, size: 524288" uri="spotify:track:1uQcwOAGGYIGUH6rdhP05R" Oct 12 15:58:06 salavrx go-librespot[1210]: time="2026-10-12T15:58:06+02:00" level=debug msg="fetched chunk 4/22, size: 524288" uri="spotify:track:1uQcwOAGGYIGUH6rdhP05R" Oct 12 15:58:06 salavrx go-librespot[1210]: time="2026-10-12T15:58:06+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 12 15:58:06 salavrx go-librespot[1210]: time="2026-10-12T15:58:06+02:00" level=trace msg="emitting websocket event: metadata" Oct 12 15:58:06 salavrx go-librespot[1210]: time="2026-10-12T15:58:06+02:00" level=trace msg="emitting websocket event: active" Oct 12 15:58:06 salavrx go-librespot[1210]: time="2026-10-12T15:58:06+02:00" level=debug msg="sending successful reply for dealer request" Oct 12 15:58:06 salavrx go-librespot[1210]: time="2026-10-12T15:58:06+02:00" level=debug msg="skipping dealer message" uri=social-connect/v2/broadcast_status_update Oct 12 15:58:06 salavrx volumio[712]: info: Aligning Spotify Volume to Volumio Volume Oct 12 15:58:06 salavrx volumio[712]: info: CoreCommandRouter::volumioGetState Oct 12 15:58:06 salavrx volumio[712]: info: CorePlayQueue::getTrack 0 Oct 12 15:58:06 salavrx volumio[712]: info: Setting Spotify Volume from Volumio: 92 Oct 12 15:58:06 salavrx go-librespot[1210]: time="2026-10-12T15:58:06+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 12 15:58:06 salavrx go-librespot[1210]: time="2026-10-12T15:58:06+02:00" level=trace msg="emitting websocket event: paused" Oct 12 15:58:06 salavrx go-librespot[1210]: time="2026-10-12T15:58:06+02:00" level=debug msg="handling resume player command from 78034bf1cab168d2452bf885b787157961c4f73f" Oct 12 15:58:06 salavrx go-librespot[1210]: time="2026-10-12T15:58:06+02:00" level=trace msg="seek to 28380ms (diff: 74ms, samples: 1251558, bytes: 991546)" uri="spotify:track:1uQcwOAGGYIGUH6rdhP05R" Oct 12 15:58:06 salavrx volumio[712]: info: Spotify is playing in volatile mode Oct 12 15:58:06 salavrx volumio[712]: info: CoreStateMachine::setConsumeUpdateService undefined Oct 12 15:58:06 salavrx volumio[712]: info: CoreCommandRouter::servicePushState Oct 12 15:58:06 salavrx volumio[712]: info: CoreStateMachine::pushState Oct 12 15:58:06 salavrx volumio[712]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 12 15:58:06 salavrx volumio[712]: info: CoreCommandRouter::volumioPushState Oct 12 15:58:06 salavrx volumio[712]: info: CoreCommandRouter::volumioGetState Oct 12 15:58:06 salavrx go-librespot[1210]: time="2026-10-12T15:58:06+02:00" level=debug msg="alsa driver configured, rate = 44100 bps, period time = 23219 us, period size = 1024 frames, buffer time = 92879 us, buffer size = 4096 frames, periods per buffer = 4 frames, PCM format = FLOAT_LE" Oct 12 15:58:06 salavrx go-librespot[1210]: time="2026-10-12T15:58:06+02:00" level=debug msg="resume track at 28260ms" Oct 12 15:58:06 salavrx go-librespot[1210]: time="2026-10-12T15:58:06+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 12 15:58:06 salavrx go-librespot[1210]: time="2026-10-12T15:58:06+02:00" level=trace msg="scheduling prefetch in 270s" Oct 12 15:58:06 salavrx go-librespot[1210]: time="2026-10-12T15:58:06+02:00" level=debug msg="sending successful reply for dealer request" Oct 12 15:58:06 salavrx go-librespot[1210]: time="2026-10-12T15:58:06+02:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Oct 12 15:58:06 salavrx go-librespot[1210]: time="2026-10-12T15:58:06+02:00" level=trace msg="emitting websocket event: playing" Oct 12 15:58:06 salavrx volumio[712]: info: CoreCommandRouter::servicePushState Oct 12 15:58:06 salavrx volumio[712]: info: CoreStateMachine::pushState Oct 12 15:58:06 salavrx volumio[712]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 12 15:58:06 salavrx volumio[712]: info: CoreCommandRouter::volumioPushState Oct 12 15:58:06 salavrx volumio[712]: info: CoreCommandRouter::volumioGetState Oct 12 15:58:07 salavrx volumio[712]: info: CoreCommandRouter::servicePushState Oct 12 15:58:07 salavrx volumio[712]: info: CoreStateMachine::pushState Oct 12 15:58:07 salavrx volumio[712]: info: CoreCommandRouter::volumioPushState Oct 12 15:58:07 salavrx volumio[712]: info: CoreCommandRouter::volumioGetState Oct 12 15:58:08 salavrx go-librespot[1210]: time="2026-10-12T15:58:08+02:00" level=debug msg="fetched chunk 5/22, size: 524288" uri="spotify:track:1uQcwOAGGYIGUH6rdhP05R" Oct 12 15:58:08 salavrx volumio[712]: info: Sending Spotify command with payload to local API: /player/volume Oct 12 15:58:08 salavrx go-librespot[1210]: time="2026-10-12T15:58:08+02:00" level=debug msg="update volume requested to 60292/65535" Oct 12 15:58:08 salavrx go-librespot[1210]: time="2026-10-12T15:58:08+02:00" level=debug msg="put connect state because VOLUME_CHANGED" Oct 12 15:58:08 salavrx go-librespot[1210]: time="2026-10-12T15:58:08+02:00" level=trace msg="emitting websocket event: volume" Oct 12 15:58:09 salavrx volumio[712]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 12 15:58:09 salavrx volumio[712]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 12 15:58:09 salavrx volumio[712]: info: Discovery: Getting this device information Oct 12 15:58:09 salavrx volumio[712]: info: CoreCommandRouter::volumioGetState Oct 12 15:58:09 salavrx volumio[712]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 12 15:58:09 salavrx volumio[712]: verbose: New Socket.io Connection to 192.168.178.29:3000 from 192.168.178.85 UA: Dart/3.12 (dart:io) Engine version: 3 Transport: websocket Total Clients: 9 Oct 12 15:58:09 salavrx volumio[712]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Oct 12 15:58:09 salavrx volumio[712]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Oct 12 15:58:19 salavrx volumio[712]: info: CoreStateMachine::pushState Oct 12 15:58:19 salavrx volumio[712]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 12 15:58:19 salavrx volumio[712]: info: CoreCommandRouter::volumioPushState Oct 12 15:58:19 salavrx volumio[712]: info: CoreCommandRouter::volumioGetState Oct 12 15:58:19 salavrx volumio[712]: info: CoreCommandRouter::executeOnPlugin: raat , updateRoonVolume Oct 12 15:58:20 salavrx volumio[712]: info: CoreStateMachine::pushState Oct 12 15:58:20 salavrx volumio[712]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 12 15:58:20 salavrx volumio[712]: info: CoreCommandRouter::volumioPushState Oct 12 15:58:20 salavrx volumio[712]: info: CoreCommandRouter::volumioGetState Oct 12 15:58:20 salavrx volumio[712]: info: CoreCommandRouter::executeOnPlugin: raat , updateRoonVolume Oct 12 15:58:20 salavrx volumio[712]: info: CoreStateMachine::pushState Oct 12 15:58:20 salavrx volumio[712]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 12 15:58:20 salavrx volumio[712]: info: CoreCommandRouter::volumioPushState Oct 12 15:58:20 salavrx volumio[712]: info: CoreCommandRouter::volumioGetState Oct 12 15:58:20 salavrx volumio[712]: info: CoreCommandRouter::executeOnPlugin: raat , updateRoonVolume Oct 12 15:58:20 salavrx volumio[712]: info: Setting Spotify Volume from Volumio: 94 Oct 12 15:58:20 salavrx volumio[712]: info: CoreStateMachine::pushState Oct 12 15:58:20 salavrx volumio[712]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 12 15:58:20 salavrx volumio[712]: info: CoreCommandRouter::volumioPushState Oct 12 15:58:21 salavrx volumio[712]: info: CoreCommandRouter::volumioGetState Oct 12 15:58:21 salavrx volumio[712]: info: CoreCommandRouter::executeOnPlugin: raat , updateRoonVolume Oct 12 15:58:21 salavrx volumio[712]: info: CoreStateMachine::pushState Oct 12 15:58:21 salavrx volumio[712]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 12 15:58:21 salavrx volumio[712]: info: CoreCommandRouter::volumioPushState Oct 12 15:58:21 salavrx volumio[712]: info: CoreCommandRouter::volumioGetState Oct 12 15:58:21 salavrx volumio[712]: info: CoreCommandRouter::executeOnPlugin: raat , updateRoonVolume Oct 12 15:58:21 salavrx volumio[712]: info: CoreStateMachine::pushState Oct 12 15:58:21 salavrx volumio[712]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 12 15:58:21 salavrx volumio[712]: info: CoreCommandRouter::volumioPushState Oct 12 15:58:21 salavrx volumio[712]: info: CoreCommandRouter::volumioGetState Oct 12 15:58:21 salavrx volumio[712]: info: CoreCommandRouter::executeOnPlugin: raat , updateRoonVolume Oct 12 15:58:21 salavrx volumio[712]: info: Setting Spotify Volume from Volumio: 96 Oct 12 15:58:22 salavrx go-librespot[1210]: time="2026-10-12T15:58:22+02:00" level=debug msg="fetched chunk 6/22, size: 524288" uri="spotify:track:1uQcwOAGGYIGUH6rdhP05R" Oct 12 15:58:22 salavrx volumio[712]: info: CoreStateMachine::pushState Oct 12 15:58:22 salavrx volumio[712]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 12 15:58:22 salavrx volumio[712]: info: CoreCommandRouter::volumioPushState Oct 12 15:58:22 salavrx volumio[712]: info: CoreCommandRouter::volumioGetState Oct 12 15:58:22 salavrx volumio[712]: info: CoreCommandRouter::executeOnPlugin: raat , updateRoonVolume Oct 12 15:58:23 salavrx volumio[712]: info: Sending Spotify command with payload to local API: /player/volume Oct 12 15:58:23 salavrx go-librespot[1210]: time="2026-10-12T15:58:23+02:00" level=debug msg="update volume requested to 62913/65535" Oct 12 15:58:23 salavrx go-librespot[1210]: time="2026-10-12T15:58:23+02:00" level=debug msg="put connect state because VOLUME_CHANGED" Oct 12 15:58:23 salavrx go-librespot[1210]: time="2026-10-12T15:58:23+02:00" level=trace msg="emitting websocket event: volume" Oct 12 15:58:23 salavrx volumio[712]: info: CoreStateMachine::pushState Oct 12 15:58:23 salavrx volumio[712]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 12 15:58:23 salavrx volumio[712]: info: CoreCommandRouter::volumioPushState Oct 12 15:58:23 salavrx volumio[712]: info: CoreCommandRouter::volumioGetState Oct 12 15:58:23 salavrx volumio[712]: info: CoreCommandRouter::executeOnPlugin: raat , updateRoonVolume Oct 12 15:58:23 salavrx volumio[712]: info: Setting Spotify Volume from Volumio: 98 Oct 12 15:58:24 salavrx volumio[712]: info: CoreStateMachine::pushState Oct 12 15:58:24 salavrx volumio[712]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 12 15:58:24 salavrx volumio[712]: info: CoreCommandRouter::volumioPushState Oct 12 15:58:24 salavrx volumio[712]: info: CoreCommandRouter::volumioGetState Oct 12 15:58:24 salavrx volumio[712]: info: CoreCommandRouter::executeOnPlugin: raat , updateRoonVolume Oct 12 15:58:24 salavrx volumio[712]: info: CoreStateMachine::pushState Oct 12 15:58:24 salavrx volumio[712]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 12 15:58:24 salavrx volumio[712]: info: CoreCommandRouter::volumioPushState Oct 12 15:58:24 salavrx volumio[712]: info: CoreCommandRouter::volumioGetState Oct 12 15:58:24 salavrx volumio[712]: info: CoreCommandRouter::executeOnPlugin: raat , updateRoonVolume Oct 12 15:58:24 salavrx volumio[712]: info: Setting Spotify Volume from Volumio: 96 Oct 12 15:58:25 salavrx volumio[712]: info: CoreStateMachine::pushState Oct 12 15:58:25 salavrx volumio[712]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Oct 12 15:58:25 salavrx volumio[712]: info: CoreCommandRouter::volumioPushState Oct 12 15:58:25 salavrx volumio[712]: info: CoreCommandRouter::volumioGetState Oct 12 15:58:25 salavrx volumio[712]: info: CoreCommandRouter::executeOnPlugin: raat , updateRoonVolume Oct 12 15:58:26 salavrx volumio[712]: info: Sending Spotify command with payload to local API: /player/volume Oct 12 15:58:26 salavrx go-librespot[1210]: time="2026-10-12T15:58:26+02:00" level=debug msg="update volume requested to 62913/65535" Oct 12 15:58:26 salavrx go-librespot[1210]: time="2026-10-12T15:58:26+02:00" level=debug msg="put connect state because VOLUME_CHANGED" Oct 12 15:58:26 salavrx go-librespot[1210]: time="2026-10-12T15:58:26+02:00" level=trace msg="emitting websocket event: volume" Oct 12 15:58:35 salavrx go-librespot[1210]: time="2026-10-12T15:58:35+02:00" level=trace msg="sent dealer ping" Oct 12 15:58:35 salavrx go-librespot[1210]: time="2026-10-12T15:58:35+02:00" level=trace msg="received dealer pong" Oct 12 15:58:35 salavrx go-librespot[1210]: time="2026-10-12T15:58:35+02:00" level=debug msg="fetched chunk 7/22, size: 524288" uri="spotify:track:1uQcwOAGGYIGUH6rdhP05R" Oct 12 15:58:50 salavrx go-librespot[1210]: time="2026-10-12T15:58:50+02:00" level=debug msg="fetched chunk 8/22, size: 524288" uri="spotify:track:1uQcwOAGGYIGUH6rdhP05R" Oct 12 15:58:56 salavrx volumio[712]: verbose: New Socket.io Connection to 192.168.178.29:3000 from 192.168.178.85 UA: Dart/3.12 (dart:io) Engine version: 3 Transport: websocket Total Clients: 8 Oct 12 15:58:56 salavrx volumio[712]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 12 15:58:56 salavrx volumio[712]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 12 15:58:56 salavrx volumio[712]: info: Discovery: Getting this device information Oct 12 15:58:56 salavrx volumio[712]: info: CoreCommandRouter::volumioGetState Oct 12 15:58:56 salavrx volumio[712]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 12 15:58:56 salavrx volumio[712]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 12 15:58:56 salavrx volumio[712]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 12 15:58:56 salavrx volumio[712]: info: Discovery: Getting this device information Oct 12 15:58:56 salavrx volumio[712]: info: CoreCommandRouter::volumioGetState Oct 12 15:58:56 salavrx volumio[712]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 12 15:58:56 salavrx volumio[712]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Oct 12 15:58:56 salavrx volumio[712]: info: CoreCommandRouter::executeOnPlugin: appearance , getAvailableLanguages Oct 12 15:58:56 salavrx volumio[712]: info: CoreCommandRouter::executeOnPlugin: system , getCurrentTimezone Oct 12 15:58:56 salavrx volumio[712]: info: CoreCommandRouter::executeOnPlugin: network , getInfoNetwork Oct 12 15:58:56 salavrx sudo[2266]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ethtool eth0 Oct 12 15:58:56 salavrx sudo[2266]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 12 15:58:56 salavrx sudo[2266]: pam_unix(sudo:session): session closed for user root Oct 12 15:58:56 salavrx sudo[2271]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Oct 12 15:58:56 salavrx sudo[2271]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 12 15:58:56 salavrx sudo[2279]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Oct 12 15:58:56 salavrx sudo[2279]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 12 15:58:56 salavrx sudo[2271]: pam_unix(sudo:session): session closed for user root Oct 12 15:58:56 salavrx sudo[2290]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/iwconfig wlan0 Oct 12 15:58:56 salavrx sudo[2290]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 12 15:58:56 salavrx sudo[2297]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Oct 12 15:58:56 salavrx sudo[2279]: pam_unix(sudo:session): session closed for user root Oct 12 15:58:56 salavrx sudo[2297]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 12 15:58:56 salavrx sudo[2297]: pam_unix(sudo:session): session closed for user root Oct 12 15:58:56 salavrx sudo[2305]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Oct 12 15:58:56 salavrx sudo[2290]: pam_unix(sudo:session): session closed for user root Oct 12 15:58:56 salavrx sudo[2305]: pam_unix(sudo:session): session opened for user root by (uid=0) Oct 12 15:58:56 salavrx sudo[2305]: pam_unix(sudo:session): session closed for user root Oct 12 15:58:57 salavrx volumio[712]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Oct 12 15:58:57 salavrx volumio[712]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Oct 12 15:58:57 salavrx volumio[712]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Oct 12 15:58:57 salavrx volumio[712]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Oct 12 15:58:57 salavrx volumio[712]: info: Discovery: Getting this device information Oct 12 15:58:57 salavrx volumio[712]: info: CoreCommandRouter::volumioGetState Oct 12 15:58:57 salavrx volumio[712]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Oct 12 15:58:57 salavrx volumio[712]: info: CoreCommandRouter::volumioGetState Oct 12 15:59:05 salavrx go-librespot[1210]: time="2026-10-12T15:59:05+02:00" level=debug msg="fetched chunk 9/22, size: 524288" uri="spotify:track:1uQcwOAGGYIGUH6rdhP05R" Oct 12 15:59:05 salavrx go-librespot[1210]: time="2026-10-12T15:59:05+02:00" level=trace msg="sent dealer ping" Oct 12 15:59:05 salavrx go-librespot[1210]: time="2026-10-12T15:59:05+02:00" level=trace msg="received dealer pong" Oct 12 15:59:06 salavrx volumio[712]: info: CorePlayQueue::getTrack 0 Oct 12 15:59:06 salavrx volumio[712]: info: CorePlayQueue::getTrack 1 Oct 12 15:59:06 salavrx volumio[712]: info: Prefetching next song Oct 12 15:59:06 salavrx volumio[712]: info: [1791813546671] ControllerTidal::prefetch Oct 12 15:59:06 salavrx volumio[712]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 12 15:59:06 salavrx volumio[712]: TypeError: Cannot read property 'highestSoundQuality' of undefined Oct 12 15:59:06 salavrx volumio[712]: at ControllerTidal.getProperSoundQuality (/volumio/app/plugins/music_service/tidal/tidal_real:1:19583) Oct 12 15:59:06 salavrx volumio[712]: at ControllerTidal.prefetch (/volumio/app/plugins/music_service/tidal/tidal_real:1:20287) Oct 12 15:59:06 salavrx volumio[712]: at CoreStateMachine.increasePlaybackTimer (/volumio/app/statemachine.js:464:18) Oct 12 15:59:06 salavrx volumio[712]: at listOnTimeout (internal/timers.js:557:17) Oct 12 15:59:06 salavrx volumio[712]: at processTimers (internal/timers.js:500:7) Oct 12 15:59:06 salavrx volumio[712]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Oct 12 15:59:07 salavrx sudo[2335]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2026-10-12 15:58 Oct 12 15:59:07 salavrx sudo[2335]: pam_unix(sudo:session): session opened for user root by (uid=0) PRETTY_NAME="Debian GNU/Linux 10 (buster)" NAME="Debian GNU/Linux" VERSION_ID="10" VERSION="10 (buster)" VERSION_CODENAME=buster ID=debian HOME_URL="https://www.debian.org/" SUPPORT_URL="https://www.debian.org/support" BUG_REPORT_URL="https://bugs.debian.org/" VOLUMIO_BUILD_VERSION="3dada8b1e619a5feb94867e0865ace17474d7bce" VOLUMIO_FE_VERSION="35f8f4439f0076a62fefa72fd80b70701b3d6cbd" VOLUMIO_FE3_VERSION="bcca17b6b6b26edfb999e6fd7da1b222a88a61d2" VOLUMIO_BE_VERSION="30045b259d1a704a832ca7c1460c1fdfa4b723f9" VOLUMIO_ARCH="armv7" VOLUMIO_VARIANT="minidspshd" VOLUMIO_TEST="FALSE" VOLUMIO_BUILD_DATE="Thu 05 Mar 2026 11:08:05 AM CET" VOLUMIO_VERSION="3.912" VOLUMIO_HARDWARE="nanopineo3" VOLUMIO_DEVICENAME="Nanopi Neo3" VOLUMIO_VENDOR="miniDSP" VOLUMIO_MODEL="SHD" VOLUMIO_VENDOR_MODEL="miniDSP SHD" VOLUMIO_HASH="2435172a9e07e22ce77410ca4817b0fa"