-- Logs begin at Thu 2019-02-14 16:11:59 +06, end at Tue 2025-03-04 10:50:20 +06. -- Mar 04 10:49:00 volumio volumio[1015]: 0+0 records in Mar 04 10:49:00 volumio volumio[1015]: 0+0 records out Mar 04 10:49:00 volumio volumio[1015]: 0 bytes copied, 0.000122808 s, 0.0 kB/s Mar 04 10:49:00 volumio volumio[1015]: info: camilladsp spawned new process with pid 4694, instance 1, run: true Mar 04 10:49:01 volumio volumio[1015]: 0+0 records in Mar 04 10:49:01 volumio volumio[1015]: 0+0 records out Mar 04 10:49:01 volumio volumio[1015]: 0 bytes copied, 0.000119996 s, 0.0 kB/s Mar 04 10:49:01 volumio volumio[1015]: info: camilladsp spawned new process with pid 4699, instance 1, run: true Mar 04 10:49:01 volumio volumio[1015]: info: CALLMETHOD: miscellanea appearance setVolumio3UI [object Object] Mar 04 10:49:01 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: appearance , setVolumio3UI Mar 04 10:49:01 volumio volumio[1015]: info: Setting active UI to: {"uiPrettyName":"Contemporary","uiName":"contemporary","uiPath":"/volumio/http/www3"} Mar 04 10:49:02 volumio volumio[1015]: 0+0 records in Mar 04 10:49:02 volumio volumio[1015]: 0+0 records out Mar 04 10:49:02 volumio volumio[1015]: 0 bytes copied, 0.00013838 s, 0.0 kB/s Mar 04 10:49:02 volumio volumio[1015]: info: camilladsp spawned new process with pid 4704, instance 1, run: true Mar 04 10:49:02 volumio volumio[1015]: info: CoreCommandRouter::Reload Ui Mar 04 10:49:03 volumio volumio[1015]: 0+0 records in Mar 04 10:49:03 volumio volumio[1015]: 0+0 records out Mar 04 10:49:03 volumio volumio[1015]: 0 bytes copied, 0.000121871 s, 0.0 kB/s Mar 04 10:49:03 volumio volumio[1015]: info: camilladsp spawned new process with pid 4709, instance 1, run: true Mar 04 10:49:03 volumio sudo[4713]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig eth0 Mar 04 10:49:03 volumio sudo[4713]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 04 10:49:03 volumio sudo[4713]: pam_unix(sudo:session): session closed for user root Mar 04 10:49:03 volumio sudo[4716]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ifconfig wlan0 Mar 04 10:49:03 volumio sudo[4716]: pam_unix(sudo:session): session opened for user root by (uid=0) Mar 04 10:49:03 volumio sudo[4716]: pam_unix(sudo:session): session closed for user root Mar 04 10:49:03 volumio volumio[1015]: verbose: New Socket.io Connection to 192.168.3.107 from 192.168.3.45 UA: Mozilla/5.0 (Windows NT 10.0; Win64; x64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/133.0.0.0 Safari/537.36 Engine version: 3 Transport: polling Total Clients: 11 Mar 04 10:49:03 volumio volumio[1015]: info: CoreCommandRouter::getUIConfigOnPlugin Mar 04 10:49:03 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Mar 04 10:49:03 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom Mar 04 10:49:03 volumio volumio[1015]: info: Error : CoreCommandRouter::executeOnPlugin: No method [getMultiroom] in plugin multiroom Mar 04 10:49:03 volumio volumio[1015]: info: CoreCommandRouter::volumioGetState Mar 04 10:49:03 volumio volumio[1015]: info: CorePlayQueue::getTrack 5 Mar 04 10:49:03 volumio volumio[1015]: info: CoreCommandRouter::volumioGetVisibleSources Mar 04 10:49:03 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources Mar 04 10:49:03 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings Mar 04 10:49:03 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard Mar 04 10:49:03 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: system , getShowWizard Mar 04 10:49:03 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Mar 04 10:49:04 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Mar 04 10:49:04 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: appearance , getConfigParam Mar 04 10:49:04 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: appearance , getAvailableUIs Mar 04 10:49:04 volumio volumio[1015]: 0+0 records in Mar 04 10:49:04 volumio volumio[1015]: 0+0 records out Mar 04 10:49:04 volumio volumio[1015]: 0 bytes copied, 0.000122027 s, 0.0 kB/s Mar 04 10:49:04 volumio volumio[1015]: info: camilladsp spawned new process with pid 4734, instance 1, run: true Mar 04 10:49:04 volumio volumio[1015]: info: Received Get System Version Mar 04 10:49:04 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 04 10:49:04 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: appearance , getBackgrounds Mar 04 10:49:05 volumio volumio[1015]: 0+0 records in Mar 04 10:49:05 volumio volumio[1015]: 0+0 records out Mar 04 10:49:05 volumio volumio[1015]: 0 bytes copied, 0.000148901 s, 0.0 kB/s Mar 04 10:49:05 volumio volumio[1015]: info: camilladsp spawned new process with pid 4755, instance 1, run: true Mar 04 10:49:06 volumio volumio[1015]: 0+0 records in Mar 04 10:49:06 volumio volumio[1015]: 0+0 records out Mar 04 10:49:06 volumio volumio[1015]: 0 bytes copied, 0.000182493 s, 0.0 kB/s Mar 04 10:49:06 volumio volumio[1015]: info: camilladsp spawned new process with pid 4761, instance 1, run: true Mar 04 10:49:06 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 04 10:49:06 volumio volumio[1015]: info: Received Get System Info Mar 04 10:49:06 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 04 10:49:06 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 04 10:49:06 volumio volumio[1015]: info: Discovery: Getting this device information Mar 04 10:49:06 volumio volumio[1015]: info: CoreCommandRouter::volumioGetState Mar 04 10:49:06 volumio volumio[1015]: info: CorePlayQueue::getTrack 5 Mar 04 10:49:06 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 04 10:49:07 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: my_volumio , getMyVolumioStatus Mar 04 10:49:07 volumio volumio[1015]: info: Received Get System Info Mar 04 10:49:07 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 04 10:49:07 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 04 10:49:07 volumio volumio[1015]: info: Discovery: Getting this device information Mar 04 10:49:07 volumio volumio[1015]: info: CoreCommandRouter::volumioGetState Mar 04 10:49:07 volumio volumio[1015]: info: CorePlayQueue::getTrack 5 Mar 04 10:49:07 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 04 10:49:07 volumio volumio[1015]: 0+0 records in Mar 04 10:49:07 volumio volumio[1015]: 0+0 records out Mar 04 10:49:07 volumio volumio[1015]: 0 bytes copied, 0.000122444 s, 0.0 kB/s Mar 04 10:49:07 volumio volumio[1015]: info: camilladsp spawned new process with pid 4767, instance 1, run: true Mar 04 10:49:08 volumio volumio[1015]: 0+0 records in Mar 04 10:49:08 volumio volumio[1015]: 0+0 records out Mar 04 10:49:08 volumio volumio[1015]: 0 bytes copied, 0.000128277 s, 0.0 kB/s Mar 04 10:49:09 volumio volumio[1015]: info: camilladsp spawned new process with pid 4772, instance 1, run: true Mar 04 10:49:10 volumio volumio[1015]: 0+0 records in Mar 04 10:49:10 volumio volumio[1015]: 0+0 records out Mar 04 10:49:10 volumio volumio[1015]: 0 bytes copied, 0.00011911 s, 0.0 kB/s Mar 04 10:49:10 volumio volumio[1015]: info: camilladsp spawned new process with pid 4777, instance 1, run: true Mar 04 10:49:11 volumio volumio[1015]: 0+0 records in Mar 04 10:49:11 volumio volumio[1015]: 0+0 records out Mar 04 10:49:11 volumio volumio[1015]: 0 bytes copied, 0.000125256 s, 0.0 kB/s Mar 04 10:49:11 volumio volumio[1015]: info: camilladsp spawned new process with pid 4782, instance 1, run: true Mar 04 10:49:12 volumio volumio[1015]: 0+0 records in Mar 04 10:49:12 volumio volumio[1015]: 0+0 records out Mar 04 10:49:12 volumio volumio[1015]: 0 bytes copied, 0.000124214 s, 0.0 kB/s Mar 04 10:49:12 volumio volumio[1015]: info: camilladsp spawned new process with pid 4787, instance 1, run: true Mar 04 10:49:12 volumio volumio[1015]: info: CoreCommandRouter::volumioPlay Mar 04 10:49:12 volumio volumio[1015]: info: CoreStateMachine::play index undefined Mar 04 10:49:12 volumio volumio[1015]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 04 10:49:12 volumio volumio[1015]: info: CorePlayQueue::getTrack 5 Mar 04 10:49:12 volumio volumio[1015]: info: CoreStateMachine::startPlaybackTimer Mar 04 10:49:12 volumio volumio[1015]: info: CorePlayQueue::getTrack 5 Mar 04 10:49:12 volumio volumio[1015]: info: [1741063752899] ControllerSpotify::clearAddPlayTrack Mar 04 10:49:12 volumio volumio[1015]: info: Sending Spotify command with payload to local API: /player/play Mar 04 10:49:13 volumio volumio[1015]: 0+0 records in Mar 04 10:49:13 volumio volumio[1015]: 0+0 records out Mar 04 10:49:13 volumio volumio[1015]: 0 bytes copied, 0.000185722 s, 0.0 kB/s Mar 04 10:49:13 volumio volumio[1015]: info: camilladsp spawned new process with pid 4792, instance 1, run: true Mar 04 10:49:13 volumio go-librespot[24674]: time="2025-03-04T10:49:13+06:00" level=debug msg="resolved context of track" uri="spotify:track:43jExF2HeZ6cJIGrWF0ie4" Mar 04 10:49:13 volumio go-librespot[24674]: time="2025-03-04T10:49:13+06:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:43jExF2HeZ6cJIGrWF0ie4" Mar 04 10:49:13 volumio go-librespot[24674]: time="2025-03-04T10:49:13+06:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:43jExF2HeZ6cJIGrWF0ie4" Mar 04 10:49:13 volumio go-librespot[24674]: time="2025-03-04T10:49:13+06:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Mar 04 10:49:13 volumio go-librespot[24674]: time="2025-03-04T10:49:13+06:00" level=trace msg="emitting websocket event: will_play" Mar 04 10:49:13 volumio volumio[1015]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:43jExF2HeZ6cJIGrWF0ie4","play_origin":"go-librespot"}} Mar 04 10:49:13 volumio volumio[1015]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:43jExF2HeZ6cJIGrWF0ie4","play_origin":"go-librespot"}} Mar 04 10:49:14 volumio go-librespot[24674]: time="2025-03-04T10:49:14+06:00" level=debug msg="selected format OGG_VORBIS_320 (44adeb2a46a76b524d6d9d7930da9669c4a03dff)" uri="spotify:track:43jExF2HeZ6cJIGrWF0ie4" Mar 04 10:49:14 volumio go-librespot[24674]: time="2025-03-04T10:49:14+06:00" level=debug msg="requested aes key for file 44adeb2a46a76b524d6d9d7930da9669c4a03dff, gid: 43jExF2HeZ6cJIGrWF0ie4" Mar 04 10:49:14 volumio volumio[1015]: 0+0 records in Mar 04 10:49:14 volumio volumio[1015]: 0+0 records out Mar 04 10:49:14 volumio volumio[1015]: 0 bytes copied, 0.000122704 s, 0.0 kB/s Mar 04 10:49:14 volumio volumio[1015]: info: camilladsp spawned new process with pid 4797, instance 1, run: true Mar 04 10:49:14 volumio go-librespot[24674]: time="2025-03-04T10:49:14+06:00" level=error msg="failed handling request play" error="failed loading context: failed loading current track (load context): failed creating stream for spotify:track:43jExF2HeZ6cJIGrWF0ie4: failed retrieving audio key: failed retrieving aes key with code 1" Mar 04 10:49:14 volumio volumio[1015]: error: Failed to send command to Spotify local API: /player/play: Error: Internal Server Error Mar 04 10:49:15 volumio volumio[1015]: 0+0 records in Mar 04 10:49:15 volumio volumio[1015]: 0+0 records out Mar 04 10:49:15 volumio volumio[1015]: 0 bytes copied, 0.00012359 s, 0.0 kB/s Mar 04 10:49:15 volumio volumio[1015]: info: camilladsp spawned new process with pid 4802, instance 1, run: true Mar 04 10:49:16 volumio volumio[1015]: 0+0 records in Mar 04 10:49:16 volumio volumio[1015]: 0+0 records out Mar 04 10:49:16 volumio volumio[1015]: 0 bytes copied, 0.000127183 s, 0.0 kB/s Mar 04 10:49:16 volumio volumio[1015]: info: camilladsp spawned new process with pid 4824, instance 1, run: true Mar 04 10:49:17 volumio volumio[1015]: 0+0 records in Mar 04 10:49:17 volumio volumio[1015]: 0+0 records out Mar 04 10:49:17 volumio volumio[1015]: 0 bytes copied, 0.000124371 s, 0.0 kB/s Mar 04 10:49:17 volumio volumio[1015]: info: camilladsp spawned new process with pid 4830, instance 1, run: true Mar 04 10:49:18 volumio volumio[1015]: 0+0 records in Mar 04 10:49:18 volumio volumio[1015]: 0+0 records out Mar 04 10:49:18 volumio volumio[1015]: 0 bytes copied, 0.000123381 s, 0.0 kB/s Mar 04 10:49:18 volumio volumio[1015]: info: camilladsp spawned new process with pid 4835, instance 1, run: true Mar 04 10:49:19 volumio volumio[1015]: 0+0 records in Mar 04 10:49:19 volumio volumio[1015]: 0+0 records out Mar 04 10:49:19 volumio volumio[1015]: 0 bytes copied, 0.000141297 s, 0.0 kB/s Mar 04 10:49:19 volumio volumio[1015]: info: camilladsp spawned new process with pid 4840, instance 1, run: true Mar 04 10:49:20 volumio volumio[1015]: 0+0 records in Mar 04 10:49:20 volumio volumio[1015]: 0+0 records out Mar 04 10:49:20 volumio volumio[1015]: 0 bytes copied, 0.000121975 s, 0.0 kB/s Mar 04 10:49:20 volumio volumio[1015]: info: camilladsp spawned new process with pid 4845, instance 1, run: true Mar 04 10:49:21 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Mar 04 10:49:21 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Mar 04 10:49:21 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: updater_comm , getUpdateMessageCache Mar 04 10:49:21 volumio volumio[1015]: 0+0 records in Mar 04 10:49:21 volumio volumio[1015]: 0+0 records out Mar 04 10:49:21 volumio volumio[1015]: 0 bytes copied, 0.00012109 s, 0.0 kB/s Mar 04 10:49:21 volumio volumio[1015]: info: camilladsp spawned new process with pid 4850, instance 1, run: true Mar 04 10:49:21 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings Mar 04 10:49:21 volumio volumio[1015]: info: CALLMETHOD: system_controller my_volumio retreiveBackendEventStates undefined Mar 04 10:49:21 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: my_volumio , retreiveBackendEventStates Mar 04 10:49:21 volumio volumio[1015]: info: Received Get System Version Mar 04 10:49:21 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: system , getSystemVersion Mar 04 10:49:21 volumio volumio[1015]: info: Received Get System Info Mar 04 10:49:21 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: system , getSystemInfo Mar 04 10:49:21 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , getThisDevice Mar 04 10:49:21 volumio volumio[1015]: info: Discovery: Getting this device information Mar 04 10:49:21 volumio volumio[1015]: info: CoreCommandRouter::volumioGetState Mar 04 10:49:21 volumio volumio[1015]: info: CorePlayQueue::getTrack 5 Mar 04 10:49:21 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: network , getCachedIPAddresses Mar 04 10:49:22 volumio volumio[1015]: 0+0 records in Mar 04 10:49:22 volumio volumio[1015]: 0+0 records out Mar 04 10:49:22 volumio volumio[1015]: 0 bytes copied, 0.000123537 s, 0.0 kB/s Mar 04 10:49:22 volumio volumio[1015]: info: camilladsp spawned new process with pid 4855, instance 1, run: true Mar 04 10:49:23 volumio volumio[1015]: info: Listing playlists Mar 04 10:49:23 volumio volumio[1015]: 0+0 records in Mar 04 10:49:23 volumio volumio[1015]: 0+0 records out Mar 04 10:49:23 volumio volumio[1015]: 0 bytes copied, 0.0001226 s, 0.0 kB/s Mar 04 10:49:23 volumio volumio[1015]: info: camilladsp spawned new process with pid 4860, instance 1, run: true Mar 04 10:49:24 volumio volumio[1015]: info: VolumeController::SetAlsaVolume0 Mar 04 10:49:24 volumio volumio[1015]: info: CoreStateMachine::pushState Mar 04 10:49:24 volumio volumio[1015]: info: CorePlayQueue::getTrack 5 Mar 04 10:49:24 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 04 10:49:24 volumio volumio[1015]: info: CoreCommandRouter::volumioPushState Mar 04 10:49:24 volumio volumio[1015]: info: MRS: Pushing multiroomSync output update for this device Mar 04 10:49:24 volumio volumio[1015]: info: MRS: Pushing multiroomSync output Mar 04 10:49:24 volumio volumio[1015]: info: [ASDebug] CurState: stop PrevState: stop Mar 04 10:49:24 volumio volumio[1015]: info: [GPIO_Control] Status changed: stop Mar 04 10:49:24 volumio volumio[1015]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: Invalid card number. Mar 04 10:49:24 volumio volumio[1015]: 0+0 records in Mar 04 10:49:24 volumio volumio[1015]: 0+0 records out Mar 04 10:49:24 volumio volumio[1015]: 0 bytes copied, 0.000120152 s, 0.0 kB/s Mar 04 10:49:24 volumio volumio[1015]: info: camilladsp spawned new process with pid 4866, instance 1, run: true Mar 04 10:49:26 volumio volumio[1015]: 0+0 records in Mar 04 10:49:26 volumio volumio[1015]: 0+0 records out Mar 04 10:49:26 volumio volumio[1015]: 0 bytes copied, 0.000123277 s, 0.0 kB/s Mar 04 10:49:26 volumio volumio[1015]: info: camilladsp spawned new process with pid 4888, instance 1, run: true Mar 04 10:49:27 volumio volumio[1015]: 0+0 records in Mar 04 10:49:27 volumio volumio[1015]: 0+0 records out Mar 04 10:49:27 volumio volumio[1015]: 0 bytes copied, 0.000122913 s, 0.0 kB/s Mar 04 10:49:27 volumio volumio[1015]: info: camilladsp spawned new process with pid 4893, instance 1, run: true Mar 04 10:49:28 volumio volumio[1015]: 0+0 records in Mar 04 10:49:28 volumio volumio[1015]: 0+0 records out Mar 04 10:49:28 volumio volumio[1015]: 0 bytes copied, 0.000125412 s, 0.0 kB/s Mar 04 10:49:28 volumio volumio[1015]: info: camilladsp spawned new process with pid 4898, instance 1, run: true Mar 04 10:49:29 volumio volumio[1015]: 0+0 records in Mar 04 10:49:29 volumio volumio[1015]: 0+0 records out Mar 04 10:49:29 volumio volumio[1015]: 0 bytes copied, 0.000121194 s, 0.0 kB/s Mar 04 10:49:29 volumio volumio[1015]: info: camilladsp spawned new process with pid 4903, instance 1, run: true Mar 04 10:49:29 volumio go-librespot[24674]: time="2025-03-04T10:49:29+06:00" level=trace msg="sent dealer ping" Mar 04 10:49:29 volumio go-librespot[24674]: time="2025-03-04T10:49:29+06:00" level=trace msg="received dealer pong" Mar 04 10:49:30 volumio volumio[1015]: 0+0 records in Mar 04 10:49:30 volumio volumio[1015]: 0+0 records out Mar 04 10:49:30 volumio volumio[1015]: 0 bytes copied, 0.000141505 s, 0.0 kB/s Mar 04 10:49:30 volumio volumio[1015]: info: camilladsp spawned new process with pid 4908, instance 1, run: true Mar 04 10:49:31 volumio ntpd[807]: Soliciting pool server 2001:ac8:81:65:0:2:0:3 Mar 04 10:49:31 volumio volumio[1015]: 0+0 records in Mar 04 10:49:31 volumio volumio[1015]: 0+0 records out Mar 04 10:49:31 volumio volumio[1015]: 0 bytes copied, 0.000123381 s, 0.0 kB/s Mar 04 10:49:31 volumio volumio[1015]: info: camilladsp spawned new process with pid 4913, instance 1, run: true Mar 04 10:49:32 volumio volumio[1015]: 0+0 records in Mar 04 10:49:32 volumio volumio[1015]: 0+0 records out Mar 04 10:49:32 volumio volumio[1015]: 0 bytes copied, 0.000122651 s, 0.0 kB/s Mar 04 10:49:32 volumio volumio[1015]: info: camilladsp spawned new process with pid 4918, instance 1, run: true Mar 04 10:49:33 volumio volumio[1015]: 0+0 records in Mar 04 10:49:33 volumio volumio[1015]: 0+0 records out Mar 04 10:49:33 volumio volumio[1015]: 0 bytes copied, 0.00012536 s, 0.0 kB/s Mar 04 10:49:33 volumio volumio[1015]: info: camilladsp spawned new process with pid 4923, instance 1, run: true Mar 04 10:49:34 volumio volumio[1015]: 0+0 records in Mar 04 10:49:34 volumio volumio[1015]: 0+0 records out Mar 04 10:49:34 volumio volumio[1015]: 0 bytes copied, 0.000124058 s, 0.0 kB/s Mar 04 10:49:34 volumio volumio[1015]: info: camilladsp spawned new process with pid 4928, instance 1, run: true Mar 04 10:49:35 volumio volumio[1015]: 0+0 records in Mar 04 10:49:35 volumio volumio[1015]: 0+0 records out Mar 04 10:49:35 volumio volumio[1015]: 0 bytes copied, 0.00012286 s, 0.0 kB/s Mar 04 10:49:35 volumio volumio[1015]: info: camilladsp spawned new process with pid 4971, instance 1, run: true Mar 04 10:49:36 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , setRemoteDeviceVolume Mar 04 10:49:36 volumio volumio[1015]: info: Setting Remote Device Volume: http://192.168.3.107 Mar 04 10:49:36 volumio volumio[1015]: 0+0 records in Mar 04 10:49:36 volumio volumio[1015]: 0+0 records out Mar 04 10:49:36 volumio volumio[1015]: 0 bytes copied, 0.000122339 s, 0.0 kB/s Mar 04 10:49:36 volumio volumio[1015]: info: camilladsp spawned new process with pid 4993, instance 1, run: true Mar 04 10:49:36 volumio volumio[1015]: info: Mar 04 10:49:36 volumio volumio[1015]: ---------------------------- Client requests Volume 3 Mar 04 10:49:36 volumio volumio[1015]: info: VolumeController::SetAlsaVolume3 Mar 04 10:49:36 volumio volumio[1015]: info: CoreStateMachine::pushState Mar 04 10:49:36 volumio volumio[1015]: info: CorePlayQueue::getTrack 5 Mar 04 10:49:36 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 04 10:49:36 volumio volumio[1015]: info: CoreCommandRouter::volumioPushState Mar 04 10:49:36 volumio volumio[1015]: info: MRS: Pushing multiroomSync output update for this device Mar 04 10:49:36 volumio volumio[1015]: info: MRS: Pushing multiroomSync output Mar 04 10:49:36 volumio volumio[1015]: info: [ASDebug] CurState: stop PrevState: stop Mar 04 10:49:36 volumio volumio[1015]: info: [GPIO_Control] Status changed: stop Mar 04 10:49:36 volumio volumio[1015]: SPOTIFY: RECEIVED VOLUMIO VOLUME 3 Mar 04 10:49:36 volumio volumio[1015]: SPOTIFY: SPOTIFY VOLUME 100 Mar 04 10:49:36 volumio volumio[1015]: SPOTIFY: VOLUMIO VOLUME 3 Mar 04 10:49:36 volumio volumio[1015]: SPOTIFY: DELTA VOLUME ENOUGH: true Mar 04 10:49:36 volumio volumio[1015]: info: Setting Spotify Volume from Volumio: 3 Mar 04 10:49:36 volumio volumio[1015]: info: Done setting volume on: Mar 04 10:49:36 volumio volumio[1015]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: Invalid card number. Mar 04 10:49:36 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , setRemoteDeviceVolume Mar 04 10:49:36 volumio volumio[1015]: info: Setting Remote Device Volume: http://192.168.3.107 Mar 04 10:49:36 volumio volumio[1015]: info: Mar 04 10:49:36 volumio volumio[1015]: ---------------------------- Client requests Volume 4 Mar 04 10:49:36 volumio volumio[1015]: info: VolumeController::SetAlsaVolume4 Mar 04 10:49:36 volumio volumio[1015]: info: CoreStateMachine::pushState Mar 04 10:49:36 volumio volumio[1015]: info: CorePlayQueue::getTrack 5 Mar 04 10:49:36 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 04 10:49:36 volumio volumio[1015]: info: CoreCommandRouter::volumioPushState Mar 04 10:49:36 volumio volumio[1015]: info: MRS: Pushing multiroomSync output update for this device Mar 04 10:49:36 volumio volumio[1015]: info: MRS: Pushing multiroomSync output Mar 04 10:49:36 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , setRemoteDeviceVolume Mar 04 10:49:36 volumio volumio[1015]: info: Setting Remote Device Volume: http://192.168.3.107 Mar 04 10:49:36 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , setRemoteDeviceVolume Mar 04 10:49:36 volumio volumio[1015]: info: Setting Remote Device Volume: http://192.168.3.107 Mar 04 10:49:36 volumio volumio[1015]: info: [ASDebug] CurState: stop PrevState: stop Mar 04 10:49:36 volumio volumio[1015]: info: [GPIO_Control] Status changed: stop Mar 04 10:49:36 volumio volumio[1015]: SPOTIFY: RECEIVED VOLUMIO VOLUME 4 Mar 04 10:49:36 volumio volumio[1015]: SPOTIFY: SPOTIFY VOLUME 3 Mar 04 10:49:36 volumio volumio[1015]: SPOTIFY: VOLUMIO VOLUME 4 Mar 04 10:49:36 volumio volumio[1015]: SPOTIFY: DELTA VOLUME ENOUGH: false Mar 04 10:49:36 volumio volumio[1015]: info: Done setting volume on: Mar 04 10:49:36 volumio volumio[1015]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: Invalid card number. Mar 04 10:49:36 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , setRemoteDeviceVolume Mar 04 10:49:36 volumio volumio[1015]: info: Setting Remote Device Volume: http://192.168.3.107 Mar 04 10:49:36 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , setRemoteDeviceVolume Mar 04 10:49:36 volumio volumio[1015]: info: Setting Remote Device Volume: http://192.168.3.107 Mar 04 10:49:36 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , setRemoteDeviceVolume Mar 04 10:49:36 volumio volumio[1015]: info: Setting Remote Device Volume: http://192.168.3.107 Mar 04 10:49:36 volumio volumio[1015]: info: Mar 04 10:49:36 volumio volumio[1015]: ---------------------------- Client requests Volume 6 Mar 04 10:49:36 volumio volumio[1015]: info: VolumeController::SetAlsaVolume6 Mar 04 10:49:36 volumio volumio[1015]: info: CoreStateMachine::pushState Mar 04 10:49:36 volumio volumio[1015]: info: CorePlayQueue::getTrack 5 Mar 04 10:49:36 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 04 10:49:36 volumio volumio[1015]: info: CoreCommandRouter::volumioPushState Mar 04 10:49:36 volumio volumio[1015]: info: MRS: Pushing multiroomSync output update for this device Mar 04 10:49:36 volumio volumio[1015]: info: MRS: Pushing multiroomSync output Mar 04 10:49:36 volumio volumio[1015]: info: Mar 04 10:49:36 volumio volumio[1015]: ---------------------------- Client requests Volume 7 Mar 04 10:49:36 volumio volumio[1015]: info: VolumeController::SetAlsaVolume7 Mar 04 10:49:36 volumio volumio[1015]: info: CoreStateMachine::pushState Mar 04 10:49:36 volumio volumio[1015]: info: CorePlayQueue::getTrack 5 Mar 04 10:49:36 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 04 10:49:36 volumio volumio[1015]: info: CoreCommandRouter::volumioPushState Mar 04 10:49:36 volumio volumio[1015]: info: MRS: Pushing multiroomSync output update for this device Mar 04 10:49:36 volumio volumio[1015]: info: MRS: Pushing multiroomSync output Mar 04 10:49:37 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , setRemoteDeviceVolume Mar 04 10:49:37 volumio volumio[1015]: info: Setting Remote Device Volume: http://192.168.3.107 Mar 04 10:49:37 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , setRemoteDeviceVolume Mar 04 10:49:37 volumio volumio[1015]: info: Setting Remote Device Volume: http://192.168.3.107 Mar 04 10:49:37 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , setRemoteDeviceVolume Mar 04 10:49:37 volumio volumio[1015]: info: Setting Remote Device Volume: http://192.168.3.107 Mar 04 10:49:37 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , setRemoteDeviceVolume Mar 04 10:49:37 volumio volumio[1015]: info: Setting Remote Device Volume: http://192.168.3.107 Mar 04 10:49:37 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , setRemoteDeviceVolume Mar 04 10:49:37 volumio volumio[1015]: info: Setting Remote Device Volume: http://192.168.3.107 Mar 04 10:49:37 volumio volumio[1015]: info: Mar 04 10:49:37 volumio volumio[1015]: ---------------------------- Client requests Volume 8 Mar 04 10:49:37 volumio volumio[1015]: info: VolumeController::SetAlsaVolume8 Mar 04 10:49:37 volumio volumio[1015]: info: CoreStateMachine::pushState Mar 04 10:49:37 volumio volumio[1015]: info: CorePlayQueue::getTrack 5 Mar 04 10:49:37 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 04 10:49:37 volumio volumio[1015]: info: CoreCommandRouter::volumioPushState Mar 04 10:49:37 volumio volumio[1015]: info: MRS: Pushing multiroomSync output update for this device Mar 04 10:49:37 volumio volumio[1015]: info: MRS: Pushing multiroomSync output Mar 04 10:49:37 volumio volumio[1015]: info: Mar 04 10:49:37 volumio volumio[1015]: ---------------------------- Client requests Volume 10 Mar 04 10:49:37 volumio volumio[1015]: info: VolumeController::SetAlsaVolume10 Mar 04 10:49:37 volumio volumio[1015]: info: CoreStateMachine::pushState Mar 04 10:49:37 volumio volumio[1015]: info: CorePlayQueue::getTrack 5 Mar 04 10:49:37 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 04 10:49:37 volumio volumio[1015]: info: CoreCommandRouter::volumioPushState Mar 04 10:49:37 volumio volumio[1015]: info: MRS: Pushing multiroomSync output update for this device Mar 04 10:49:37 volumio volumio[1015]: info: MRS: Pushing multiroomSync output Mar 04 10:49:37 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , setRemoteDeviceVolume Mar 04 10:49:37 volumio volumio[1015]: info: Setting Remote Device Volume: http://192.168.3.107 Mar 04 10:49:37 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , setRemoteDeviceVolume Mar 04 10:49:37 volumio volumio[1015]: info: Setting Remote Device Volume: http://192.168.3.107 Mar 04 10:49:37 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , setRemoteDeviceVolume Mar 04 10:49:37 volumio volumio[1015]: info: Setting Remote Device Volume: http://192.168.3.107 Mar 04 10:49:37 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , setRemoteDeviceVolume Mar 04 10:49:37 volumio volumio[1015]: info: Setting Remote Device Volume: http://192.168.3.107 Mar 04 10:49:37 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , setRemoteDeviceVolume Mar 04 10:49:37 volumio volumio[1015]: info: Setting Remote Device Volume: http://192.168.3.107 Mar 04 10:49:37 volumio volumio[1015]: info: [ASDebug] CurState: stop PrevState: stop Mar 04 10:49:37 volumio volumio[1015]: info: [ASDebug] CurState: stop PrevState: stop Mar 04 10:49:37 volumio volumio[1015]: info: [ASDebug] CurState: stop PrevState: stop Mar 04 10:49:37 volumio volumio[1015]: info: [ASDebug] CurState: stop PrevState: stop Mar 04 10:49:37 volumio volumio[1015]: info: [GPIO_Control] Status changed: stop Mar 04 10:49:37 volumio volumio[1015]: info: [GPIO_Control] Status changed: stop Mar 04 10:49:37 volumio volumio[1015]: info: [GPIO_Control] Status changed: stop Mar 04 10:49:37 volumio volumio[1015]: info: [GPIO_Control] Status changed: stop Mar 04 10:49:37 volumio volumio[1015]: SPOTIFY: RECEIVED VOLUMIO VOLUME 6 Mar 04 10:49:37 volumio volumio[1015]: SPOTIFY: SPOTIFY VOLUME 3 Mar 04 10:49:37 volumio volumio[1015]: SPOTIFY: VOLUMIO VOLUME 6 Mar 04 10:49:37 volumio volumio[1015]: SPOTIFY: DELTA VOLUME ENOUGH: true Mar 04 10:49:37 volumio volumio[1015]: info: Setting Spotify Volume from Volumio: 6 Mar 04 10:49:37 volumio volumio[1015]: SPOTIFY: RECEIVED VOLUMIO VOLUME 7 Mar 04 10:49:37 volumio volumio[1015]: SPOTIFY: SPOTIFY VOLUME 6 Mar 04 10:49:37 volumio volumio[1015]: SPOTIFY: VOLUMIO VOLUME 7 Mar 04 10:49:37 volumio volumio[1015]: SPOTIFY: DELTA VOLUME ENOUGH: false Mar 04 10:49:37 volumio volumio[1015]: SPOTIFY: RECEIVED VOLUMIO VOLUME 8 Mar 04 10:49:37 volumio volumio[1015]: SPOTIFY: SPOTIFY VOLUME 6 Mar 04 10:49:37 volumio volumio[1015]: SPOTIFY: VOLUMIO VOLUME 8 Mar 04 10:49:37 volumio volumio[1015]: SPOTIFY: DELTA VOLUME ENOUGH: true Mar 04 10:49:37 volumio volumio[1015]: info: Setting Spotify Volume from Volumio: 8 Mar 04 10:49:37 volumio volumio[1015]: SPOTIFY: RECEIVED VOLUMIO VOLUME 10 Mar 04 10:49:37 volumio volumio[1015]: SPOTIFY: SPOTIFY VOLUME 8 Mar 04 10:49:37 volumio volumio[1015]: SPOTIFY: VOLUMIO VOLUME 10 Mar 04 10:49:37 volumio volumio[1015]: SPOTIFY: DELTA VOLUME ENOUGH: true Mar 04 10:49:37 volumio volumio[1015]: info: Setting Spotify Volume from Volumio: 10 Mar 04 10:49:37 volumio volumio[1015]: info: Done setting volume on: Mar 04 10:49:37 volumio volumio[1015]: info: Done setting volume on: Mar 04 10:49:37 volumio volumio[1015]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: Invalid card number. Mar 04 10:49:37 volumio volumio[1015]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: Invalid card number. Mar 04 10:49:37 volumio volumio[1015]: info: Mar 04 10:49:37 volumio volumio[1015]: ---------------------------- Client requests Volume 12 Mar 04 10:49:37 volumio volumio[1015]: info: VolumeController::SetAlsaVolume12 Mar 04 10:49:37 volumio volumio[1015]: info: CoreStateMachine::pushState Mar 04 10:49:37 volumio volumio[1015]: info: CorePlayQueue::getTrack 5 Mar 04 10:49:37 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 04 10:49:37 volumio volumio[1015]: info: CoreCommandRouter::volumioPushState Mar 04 10:49:37 volumio volumio[1015]: info: MRS: Pushing multiroomSync output update for this device Mar 04 10:49:37 volumio volumio[1015]: info: MRS: Pushing multiroomSync output Mar 04 10:49:37 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , setRemoteDeviceVolume Mar 04 10:49:37 volumio volumio[1015]: info: Setting Remote Device Volume: http://192.168.3.107 Mar 04 10:49:37 volumio volumio[1015]: info: Done setting volume on: Mar 04 10:49:37 volumio volumio[1015]: info: Done setting volume on: Mar 04 10:49:37 volumio volumio[1015]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: Invalid card number. Mar 04 10:49:37 volumio volumio[1015]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: Invalid card number. Mar 04 10:49:37 volumio volumio[1015]: info: Mar 04 10:49:37 volumio volumio[1015]: ---------------------------- Client requests Volume 13 Mar 04 10:49:37 volumio volumio[1015]: info: VolumeController::SetAlsaVolume13 Mar 04 10:49:37 volumio volumio[1015]: info: CoreStateMachine::pushState Mar 04 10:49:37 volumio volumio[1015]: info: CorePlayQueue::getTrack 5 Mar 04 10:49:37 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 04 10:49:37 volumio volumio[1015]: info: CoreCommandRouter::volumioPushState Mar 04 10:49:37 volumio volumio[1015]: info: MRS: Pushing multiroomSync output update for this device Mar 04 10:49:37 volumio volumio[1015]: info: MRS: Pushing multiroomSync output Mar 04 10:49:37 volumio volumio[1015]: info: Mar 04 10:49:37 volumio volumio[1015]: ---------------------------- Client requests Volume 14 Mar 04 10:49:37 volumio volumio[1015]: info: VolumeController::SetAlsaVolume14 Mar 04 10:49:37 volumio volumio[1015]: info: CoreStateMachine::pushState Mar 04 10:49:37 volumio volumio[1015]: info: CorePlayQueue::getTrack 5 Mar 04 10:49:37 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 04 10:49:37 volumio volumio[1015]: info: CoreCommandRouter::volumioPushState Mar 04 10:49:37 volumio volumio[1015]: info: MRS: Pushing multiroomSync output update for this device Mar 04 10:49:37 volumio volumio[1015]: info: MRS: Pushing multiroomSync output Mar 04 10:49:37 volumio volumio[1015]: info: Mar 04 10:49:37 volumio volumio[1015]: ---------------------------- Client requests Volume 15 Mar 04 10:49:37 volumio volumio[1015]: info: VolumeController::SetAlsaVolume15 Mar 04 10:49:37 volumio volumio[1015]: info: CoreStateMachine::pushState Mar 04 10:49:37 volumio volumio[1015]: info: CorePlayQueue::getTrack 5 Mar 04 10:49:37 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 04 10:49:37 volumio volumio[1015]: info: CoreCommandRouter::volumioPushState Mar 04 10:49:37 volumio volumio[1015]: info: MRS: Pushing multiroomSync output update for this device Mar 04 10:49:37 volumio volumio[1015]: info: MRS: Pushing multiroomSync output Mar 04 10:49:37 volumio volumio[1015]: info: Mar 04 10:49:37 volumio volumio[1015]: ---------------------------- Client requests Volume 15 Mar 04 10:49:37 volumio volumio[1015]: info: VolumeController::SetAlsaVolume15 Mar 04 10:49:37 volumio volumio[1015]: info: CoreStateMachine::pushState Mar 04 10:49:37 volumio volumio[1015]: info: CorePlayQueue::getTrack 5 Mar 04 10:49:37 volumio volumio[1015]: info: CoreCommandRouter::volumioPushState Mar 04 10:49:37 volumio volumio[1015]: info: MRS: Pushing multiroomSync output update for this device Mar 04 10:49:37 volumio volumio[1015]: info: MRS: Pushing multiroomSync output Mar 04 10:49:37 volumio volumio[1015]: info: Mar 04 10:49:37 volumio volumio[1015]: ---------------------------- Client requests Volume 16 Mar 04 10:49:37 volumio volumio[1015]: info: VolumeController::SetAlsaVolume16 Mar 04 10:49:37 volumio volumio[1015]: info: CoreStateMachine::pushState Mar 04 10:49:37 volumio volumio[1015]: info: CorePlayQueue::getTrack 5 Mar 04 10:49:37 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 04 10:49:37 volumio volumio[1015]: info: CoreCommandRouter::volumioPushState Mar 04 10:49:37 volumio volumio[1015]: info: MRS: Pushing multiroomSync output update for this device Mar 04 10:49:37 volumio volumio[1015]: info: MRS: Pushing multiroomSync output Mar 04 10:49:37 volumio volumio[1015]: info: [ASDebug] CurState: stop PrevState: stop Mar 04 10:49:37 volumio volumio[1015]: info: [ASDebug] CurState: stop PrevState: stop Mar 04 10:49:37 volumio volumio[1015]: info: [ASDebug] CurState: stop PrevState: stop Mar 04 10:49:37 volumio volumio[1015]: info: [ASDebug] CurState: stop PrevState: stop Mar 04 10:49:37 volumio volumio[1015]: info: [ASDebug] CurState: stop PrevState: stop Mar 04 10:49:37 volumio volumio[1015]: info: [ASDebug] CurState: stop PrevState: stop Mar 04 10:49:37 volumio volumio[1015]: info: [GPIO_Control] Status changed: stop Mar 04 10:49:37 volumio volumio[1015]: info: [GPIO_Control] Status changed: stop Mar 04 10:49:37 volumio volumio[1015]: info: [GPIO_Control] Status changed: stop Mar 04 10:49:37 volumio volumio[1015]: info: [GPIO_Control] Status changed: stop Mar 04 10:49:37 volumio volumio[1015]: info: [GPIO_Control] Status changed: stop Mar 04 10:49:37 volumio volumio[1015]: info: [GPIO_Control] Status changed: stop Mar 04 10:49:37 volumio volumio[1015]: SPOTIFY: RECEIVED VOLUMIO VOLUME 12 Mar 04 10:49:37 volumio volumio[1015]: SPOTIFY: SPOTIFY VOLUME 10 Mar 04 10:49:37 volumio volumio[1015]: SPOTIFY: VOLUMIO VOLUME 12 Mar 04 10:49:37 volumio volumio[1015]: SPOTIFY: DELTA VOLUME ENOUGH: true Mar 04 10:49:37 volumio volumio[1015]: info: Setting Spotify Volume from Volumio: 12 Mar 04 10:49:37 volumio volumio[1015]: SPOTIFY: RECEIVED VOLUMIO VOLUME 13 Mar 04 10:49:37 volumio volumio[1015]: SPOTIFY: SPOTIFY VOLUME 12 Mar 04 10:49:37 volumio volumio[1015]: SPOTIFY: VOLUMIO VOLUME 13 Mar 04 10:49:37 volumio volumio[1015]: SPOTIFY: DELTA VOLUME ENOUGH: false Mar 04 10:49:37 volumio volumio[1015]: SPOTIFY: RECEIVED VOLUMIO VOLUME 14 Mar 04 10:49:37 volumio volumio[1015]: SPOTIFY: SPOTIFY VOLUME 12 Mar 04 10:49:37 volumio volumio[1015]: SPOTIFY: VOLUMIO VOLUME 14 Mar 04 10:49:37 volumio volumio[1015]: SPOTIFY: DELTA VOLUME ENOUGH: true Mar 04 10:49:37 volumio volumio[1015]: info: Setting Spotify Volume from Volumio: 14 Mar 04 10:49:37 volumio volumio[1015]: SPOTIFY: RECEIVED VOLUMIO VOLUME 15 Mar 04 10:49:37 volumio volumio[1015]: SPOTIFY: SPOTIFY VOLUME 14 Mar 04 10:49:37 volumio volumio[1015]: SPOTIFY: VOLUMIO VOLUME 15 Mar 04 10:49:37 volumio volumio[1015]: SPOTIFY: DELTA VOLUME ENOUGH: false Mar 04 10:49:37 volumio volumio[1015]: SPOTIFY: RECEIVED VOLUMIO VOLUME 15 Mar 04 10:49:37 volumio volumio[1015]: SPOTIFY: SPOTIFY VOLUME 14 Mar 04 10:49:37 volumio volumio[1015]: SPOTIFY: VOLUMIO VOLUME 15 Mar 04 10:49:37 volumio volumio[1015]: SPOTIFY: DELTA VOLUME ENOUGH: false Mar 04 10:49:37 volumio volumio[1015]: SPOTIFY: RECEIVED VOLUMIO VOLUME 16 Mar 04 10:49:37 volumio volumio[1015]: SPOTIFY: SPOTIFY VOLUME 14 Mar 04 10:49:37 volumio volumio[1015]: SPOTIFY: VOLUMIO VOLUME 16 Mar 04 10:49:37 volumio volumio[1015]: SPOTIFY: DELTA VOLUME ENOUGH: true Mar 04 10:49:37 volumio volumio[1015]: info: Setting Spotify Volume from Volumio: 16 Mar 04 10:49:37 volumio volumio[1015]: info: Done setting volume on: Mar 04 10:49:37 volumio volumio[1015]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: Invalid card number. Mar 04 10:49:37 volumio volumio[1015]: info: Mar 04 10:49:37 volumio volumio[1015]: ---------------------------- Client requests Volume 17 Mar 04 10:49:37 volumio volumio[1015]: info: VolumeController::SetAlsaVolume17 Mar 04 10:49:37 volumio volumio[1015]: info: CoreStateMachine::pushState Mar 04 10:49:37 volumio volumio[1015]: info: CorePlayQueue::getTrack 5 Mar 04 10:49:37 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 04 10:49:37 volumio volumio[1015]: info: CoreCommandRouter::volumioPushState Mar 04 10:49:37 volumio volumio[1015]: info: MRS: Pushing multiroomSync output update for this device Mar 04 10:49:37 volumio volumio[1015]: info: MRS: Pushing multiroomSync output Mar 04 10:49:37 volumio volumio[1015]: info: Mar 04 10:49:37 volumio volumio[1015]: ---------------------------- Client requests Volume 20 Mar 04 10:49:37 volumio volumio[1015]: info: VolumeController::SetAlsaVolume20 Mar 04 10:49:37 volumio volumio[1015]: info: CoreStateMachine::pushState Mar 04 10:49:37 volumio volumio[1015]: info: CorePlayQueue::getTrack 5 Mar 04 10:49:37 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 04 10:49:37 volumio volumio[1015]: info: CoreCommandRouter::volumioPushState Mar 04 10:49:37 volumio volumio[1015]: info: MRS: Pushing multiroomSync output update for this device Mar 04 10:49:37 volumio volumio[1015]: info: MRS: Pushing multiroomSync output Mar 04 10:49:37 volumio volumio[1015]: info: Mar 04 10:49:37 volumio volumio[1015]: ---------------------------- Client requests Volume 22 Mar 04 10:49:37 volumio volumio[1015]: info: VolumeController::SetAlsaVolume22 Mar 04 10:49:37 volumio volumio[1015]: info: CoreStateMachine::pushState Mar 04 10:49:37 volumio volumio[1015]: info: CorePlayQueue::getTrack 5 Mar 04 10:49:37 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 04 10:49:37 volumio volumio[1015]: info: CoreCommandRouter::volumioPushState Mar 04 10:49:37 volumio volumio[1015]: info: MRS: Pushing multiroomSync output update for this device Mar 04 10:49:37 volumio volumio[1015]: info: MRS: Pushing multiroomSync output Mar 04 10:49:37 volumio volumio[1015]: info: Mar 04 10:49:37 volumio volumio[1015]: ---------------------------- Client requests Volume 26 Mar 04 10:49:37 volumio volumio[1015]: info: VolumeController::SetAlsaVolume26 Mar 04 10:49:37 volumio volumio[1015]: info: CoreStateMachine::pushState Mar 04 10:49:37 volumio volumio[1015]: info: CorePlayQueue::getTrack 5 Mar 04 10:49:37 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 04 10:49:37 volumio volumio[1015]: info: CoreCommandRouter::volumioPushState Mar 04 10:49:37 volumio volumio[1015]: info: MRS: Pushing multiroomSync output update for this device Mar 04 10:49:37 volumio volumio[1015]: info: MRS: Pushing multiroomSync output Mar 04 10:49:37 volumio volumio[1015]: info: Mar 04 10:49:37 volumio volumio[1015]: ---------------------------- Client requests Volume 27 Mar 04 10:49:37 volumio volumio[1015]: info: VolumeController::SetAlsaVolume27 Mar 04 10:49:37 volumio volumio[1015]: info: CoreStateMachine::pushState Mar 04 10:49:37 volumio volumio[1015]: info: CorePlayQueue::getTrack 5 Mar 04 10:49:37 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 04 10:49:37 volumio volumio[1015]: info: CoreCommandRouter::volumioPushState Mar 04 10:49:37 volumio volumio[1015]: info: MRS: Pushing multiroomSync output update for this device Mar 04 10:49:37 volumio volumio[1015]: info: MRS: Pushing multiroomSync output Mar 04 10:49:37 volumio volumio[1015]: info: Done setting volume on: Mar 04 10:49:37 volumio volumio[1015]: info: Done setting volume on: Mar 04 10:49:37 volumio volumio[1015]: info: Done setting volume on: Mar 04 10:49:37 volumio volumio[1015]: info: Done setting volume on: Mar 04 10:49:37 volumio volumio[1015]: info: Done setting volume on: Mar 04 10:49:37 volumio volumio[1015]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: Invalid card number. Mar 04 10:49:37 volumio volumio[1015]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: Invalid card number. Mar 04 10:49:37 volumio volumio[1015]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: Invalid card number. Mar 04 10:49:37 volumio volumio[1015]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: Invalid card number. Mar 04 10:49:37 volumio volumio[1015]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: Invalid card number. Mar 04 10:49:37 volumio volumio[1015]: 0+0 records in Mar 04 10:49:37 volumio volumio[1015]: 0+0 records out Mar 04 10:49:37 volumio volumio[1015]: 0 bytes copied, 0.000125099 s, 0.0 kB/s Mar 04 10:49:37 volumio volumio[1015]: info: camilladsp spawned new process with pid 5016, instance 1, run: true Mar 04 10:49:37 volumio volumio[1015]: info: Mar 04 10:49:37 volumio volumio[1015]: ---------------------------- Client requests Volume 27 Mar 04 10:49:37 volumio volumio[1015]: info: VolumeController::SetAlsaVolume27 Mar 04 10:49:38 volumio volumio[1015]: info: CoreStateMachine::pushState Mar 04 10:49:38 volumio volumio[1015]: info: CorePlayQueue::getTrack 5 Mar 04 10:49:38 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 04 10:49:38 volumio volumio[1015]: info: CoreCommandRouter::volumioPushState Mar 04 10:49:38 volumio volumio[1015]: info: MRS: Pushing multiroomSync output update for this device Mar 04 10:49:38 volumio volumio[1015]: info: MRS: Pushing multiroomSync output Mar 04 10:49:38 volumio volumio[1015]: info: [ASDebug] CurState: stop PrevState: stop Mar 04 10:49:38 volumio volumio[1015]: info: [ASDebug] CurState: stop PrevState: stop Mar 04 10:49:38 volumio volumio[1015]: info: [ASDebug] CurState: stop PrevState: stop Mar 04 10:49:38 volumio volumio[1015]: info: [ASDebug] CurState: stop PrevState: stop Mar 04 10:49:38 volumio volumio[1015]: info: [ASDebug] CurState: stop PrevState: stop Mar 04 10:49:38 volumio volumio[1015]: info: [ASDebug] CurState: stop PrevState: stop Mar 04 10:49:38 volumio volumio[1015]: info: [GPIO_Control] Status changed: stop Mar 04 10:49:38 volumio volumio[1015]: info: [GPIO_Control] Status changed: stop Mar 04 10:49:38 volumio volumio[1015]: info: [GPIO_Control] Status changed: stop Mar 04 10:49:38 volumio volumio[1015]: info: [GPIO_Control] Status changed: stop Mar 04 10:49:38 volumio volumio[1015]: SPOTIFY: RECEIVED VOLUMIO VOLUME 17 Mar 04 10:49:38 volumio volumio[1015]: SPOTIFY: SPOTIFY VOLUME 16 Mar 04 10:49:38 volumio volumio[1015]: SPOTIFY: VOLUMIO VOLUME 17 Mar 04 10:49:38 volumio volumio[1015]: SPOTIFY: DELTA VOLUME ENOUGH: false Mar 04 10:49:38 volumio volumio[1015]: SPOTIFY: RECEIVED VOLUMIO VOLUME 20 Mar 04 10:49:38 volumio volumio[1015]: SPOTIFY: SPOTIFY VOLUME 16 Mar 04 10:49:38 volumio volumio[1015]: SPOTIFY: VOLUMIO VOLUME 20 Mar 04 10:49:38 volumio volumio[1015]: SPOTIFY: DELTA VOLUME ENOUGH: true Mar 04 10:49:38 volumio volumio[1015]: info: Setting Spotify Volume from Volumio: 20 Mar 04 10:49:38 volumio volumio[1015]: SPOTIFY: RECEIVED VOLUMIO VOLUME 22 Mar 04 10:49:38 volumio volumio[1015]: SPOTIFY: SPOTIFY VOLUME 20 Mar 04 10:49:38 volumio volumio[1015]: SPOTIFY: VOLUMIO VOLUME 22 Mar 04 10:49:38 volumio volumio[1015]: SPOTIFY: DELTA VOLUME ENOUGH: true Mar 04 10:49:38 volumio volumio[1015]: info: Setting Spotify Volume from Volumio: 22 Mar 04 10:49:38 volumio volumio[1015]: SPOTIFY: RECEIVED VOLUMIO VOLUME 26 Mar 04 10:49:38 volumio volumio[1015]: SPOTIFY: SPOTIFY VOLUME 22 Mar 04 10:49:38 volumio volumio[1015]: SPOTIFY: VOLUMIO VOLUME 26 Mar 04 10:49:38 volumio volumio[1015]: SPOTIFY: DELTA VOLUME ENOUGH: true Mar 04 10:49:38 volumio volumio[1015]: info: Setting Spotify Volume from Volumio: 26 Mar 04 10:49:38 volumio volumio[1015]: SPOTIFY: RECEIVED VOLUMIO VOLUME 27 Mar 04 10:49:38 volumio volumio[1015]: SPOTIFY: SPOTIFY VOLUME 26 Mar 04 10:49:38 volumio volumio[1015]: SPOTIFY: VOLUMIO VOLUME 27 Mar 04 10:49:38 volumio volumio[1015]: SPOTIFY: DELTA VOLUME ENOUGH: false Mar 04 10:49:38 volumio volumio[1015]: SPOTIFY: RECEIVED VOLUMIO VOLUME 27 Mar 04 10:49:38 volumio volumio[1015]: SPOTIFY: SPOTIFY VOLUME 26 Mar 04 10:49:38 volumio volumio[1015]: SPOTIFY: VOLUMIO VOLUME 27 Mar 04 10:49:38 volumio volumio[1015]: SPOTIFY: DELTA VOLUME ENOUGH: false Mar 04 10:49:38 volumio volumio[1015]: info: Done setting volume on: Mar 04 10:49:38 volumio volumio[1015]: info: Done setting volume on: Mar 04 10:49:38 volumio volumio[1015]: info: Done setting volume on: Mar 04 10:49:38 volumio volumio[1015]: info: Done setting volume on: Mar 04 10:49:38 volumio volumio[1015]: info: Done setting volume on: Mar 04 10:49:38 volumio volumio[1015]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: Invalid card number. Mar 04 10:49:38 volumio volumio[1015]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: Invalid card number. Mar 04 10:49:38 volumio volumio[1015]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: Invalid card number. Mar 04 10:49:38 volumio volumio[1015]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: Invalid card number. Mar 04 10:49:38 volumio volumio[1015]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: Invalid card number. Mar 04 10:49:38 volumio volumio[1015]: info: Done setting volume on: Mar 04 10:49:38 volumio volumio[1015]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: Invalid card number. Mar 04 10:49:38 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , setRemoteDeviceVolume Mar 04 10:49:38 volumio volumio[1015]: info: Setting Remote Device Volume: http://192.168.3.107 Mar 04 10:49:38 volumio volumio[1015]: info: Mar 04 10:49:38 volumio volumio[1015]: ---------------------------- Client requests Volume 29 Mar 04 10:49:38 volumio volumio[1015]: info: VolumeController::SetAlsaVolume29 Mar 04 10:49:38 volumio volumio[1015]: info: CoreStateMachine::pushState Mar 04 10:49:38 volumio volumio[1015]: info: CorePlayQueue::getTrack 5 Mar 04 10:49:38 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 04 10:49:38 volumio volumio[1015]: info: CoreCommandRouter::volumioPushState Mar 04 10:49:38 volumio volumio[1015]: info: MRS: Pushing multiroomSync output update for this device Mar 04 10:49:38 volumio volumio[1015]: info: MRS: Pushing multiroomSync output Mar 04 10:49:38 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , setRemoteDeviceVolume Mar 04 10:49:38 volumio volumio[1015]: info: Setting Remote Device Volume: http://192.168.3.107 Mar 04 10:49:38 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , setRemoteDeviceVolume Mar 04 10:49:38 volumio volumio[1015]: info: Setting Remote Device Volume: http://192.168.3.107 Mar 04 10:49:38 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , setRemoteDeviceVolume Mar 04 10:49:38 volumio volumio[1015]: info: Setting Remote Device Volume: http://192.168.3.107 Mar 04 10:49:38 volumio volumio[1015]: info: [ASDebug] CurState: stop PrevState: stop Mar 04 10:49:38 volumio volumio[1015]: info: [GPIO_Control] Status changed: stop Mar 04 10:49:38 volumio volumio[1015]: SPOTIFY: RECEIVED VOLUMIO VOLUME 29 Mar 04 10:49:38 volumio volumio[1015]: SPOTIFY: SPOTIFY VOLUME 26 Mar 04 10:49:38 volumio volumio[1015]: SPOTIFY: VOLUMIO VOLUME 29 Mar 04 10:49:38 volumio volumio[1015]: SPOTIFY: DELTA VOLUME ENOUGH: true Mar 04 10:49:38 volumio volumio[1015]: info: Setting Spotify Volume from Volumio: 29 Mar 04 10:49:38 volumio volumio[1015]: info: Done setting volume on: Mar 04 10:49:38 volumio volumio[1015]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: Invalid card number. Mar 04 10:49:38 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , setRemoteDeviceVolume Mar 04 10:49:38 volumio volumio[1015]: info: Setting Remote Device Volume: http://192.168.3.107 Mar 04 10:49:38 volumio volumio[1015]: info: Mar 04 10:49:38 volumio volumio[1015]: ---------------------------- Client requests Volume 30 Mar 04 10:49:38 volumio volumio[1015]: info: VolumeController::SetAlsaVolume30 Mar 04 10:49:38 volumio volumio[1015]: info: CoreStateMachine::pushState Mar 04 10:49:38 volumio volumio[1015]: info: CorePlayQueue::getTrack 5 Mar 04 10:49:38 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 04 10:49:38 volumio volumio[1015]: info: CoreCommandRouter::volumioPushState Mar 04 10:49:38 volumio volumio[1015]: info: MRS: Pushing multiroomSync output update for this device Mar 04 10:49:38 volumio volumio[1015]: info: MRS: Pushing multiroomSync output Mar 04 10:49:38 volumio volumio[1015]: info: Mar 04 10:49:38 volumio volumio[1015]: ---------------------------- Client requests Volume 31 Mar 04 10:49:38 volumio volumio[1015]: info: VolumeController::SetAlsaVolume31 Mar 04 10:49:38 volumio volumio[1015]: info: CoreStateMachine::pushState Mar 04 10:49:38 volumio volumio[1015]: info: CorePlayQueue::getTrack 5 Mar 04 10:49:38 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 04 10:49:38 volumio volumio[1015]: info: CoreCommandRouter::volumioPushState Mar 04 10:49:38 volumio volumio[1015]: info: MRS: Pushing multiroomSync output update for this device Mar 04 10:49:38 volumio volumio[1015]: info: MRS: Pushing multiroomSync output Mar 04 10:49:38 volumio volumio[1015]: info: Mar 04 10:49:38 volumio volumio[1015]: ---------------------------- Client requests Volume 32 Mar 04 10:49:38 volumio volumio[1015]: info: VolumeController::SetAlsaVolume32 Mar 04 10:49:39 volumio volumio[1015]: info: CoreStateMachine::pushState Mar 04 10:49:39 volumio volumio[1015]: info: CorePlayQueue::getTrack 5 Mar 04 10:49:39 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 04 10:49:39 volumio volumio[1015]: info: CoreCommandRouter::volumioPushState Mar 04 10:49:39 volumio volumio[1015]: info: MRS: Pushing multiroomSync output update for this device Mar 04 10:49:39 volumio volumio[1015]: info: MRS: Pushing multiroomSync output Mar 04 10:49:39 volumio volumio[1015]: info: [ASDebug] CurState: stop PrevState: stop Mar 04 10:49:39 volumio volumio[1015]: info: [ASDebug] CurState: stop PrevState: stop Mar 04 10:49:39 volumio volumio[1015]: info: [ASDebug] CurState: stop PrevState: stop Mar 04 10:49:39 volumio volumio[1015]: info: [GPIO_Control] Status changed: stop Mar 04 10:49:39 volumio volumio[1015]: info: [GPIO_Control] Status changed: stop Mar 04 10:49:39 volumio volumio[1015]: info: [GPIO_Control] Status changed: stop Mar 04 10:49:39 volumio volumio[1015]: SPOTIFY: RECEIVED VOLUMIO VOLUME 30 Mar 04 10:49:39 volumio volumio[1015]: SPOTIFY: SPOTIFY VOLUME 29 Mar 04 10:49:39 volumio volumio[1015]: SPOTIFY: VOLUMIO VOLUME 30 Mar 04 10:49:39 volumio volumio[1015]: SPOTIFY: DELTA VOLUME ENOUGH: false Mar 04 10:49:39 volumio volumio[1015]: SPOTIFY: RECEIVED VOLUMIO VOLUME 31 Mar 04 10:49:39 volumio volumio[1015]: SPOTIFY: SPOTIFY VOLUME 29 Mar 04 10:49:39 volumio volumio[1015]: SPOTIFY: VOLUMIO VOLUME 31 Mar 04 10:49:39 volumio volumio[1015]: SPOTIFY: DELTA VOLUME ENOUGH: true Mar 04 10:49:39 volumio volumio[1015]: info: Setting Spotify Volume from Volumio: 31 Mar 04 10:49:39 volumio volumio[1015]: SPOTIFY: RECEIVED VOLUMIO VOLUME 32 Mar 04 10:49:39 volumio volumio[1015]: SPOTIFY: SPOTIFY VOLUME 31 Mar 04 10:49:39 volumio volumio[1015]: SPOTIFY: VOLUMIO VOLUME 32 Mar 04 10:49:39 volumio volumio[1015]: SPOTIFY: DELTA VOLUME ENOUGH: false Mar 04 10:49:39 volumio volumio[1015]: info: Done setting volume on: Mar 04 10:49:39 volumio volumio[1015]: info: Done setting volume on: Mar 04 10:49:39 volumio volumio[1015]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: Invalid card number. Mar 04 10:49:39 volumio volumio[1015]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: Invalid card number. Mar 04 10:49:39 volumio volumio[1015]: info: Mar 04 10:49:39 volumio volumio[1015]: ---------------------------- Client requests Volume 33 Mar 04 10:49:39 volumio volumio[1015]: info: VolumeController::SetAlsaVolume33 Mar 04 10:49:39 volumio volumio[1015]: info: CoreStateMachine::pushState Mar 04 10:49:39 volumio volumio[1015]: info: CorePlayQueue::getTrack 5 Mar 04 10:49:39 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 04 10:49:39 volumio volumio[1015]: info: CoreCommandRouter::volumioPushState Mar 04 10:49:39 volumio volumio[1015]: info: MRS: Pushing multiroomSync output update for this device Mar 04 10:49:39 volumio volumio[1015]: info: MRS: Pushing multiroomSync output Mar 04 10:49:39 volumio volumio[1015]: info: Done setting volume on: Mar 04 10:49:39 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , setRemoteDeviceVolume Mar 04 10:49:39 volumio volumio[1015]: info: Setting Remote Device Volume: http://192.168.3.107 Mar 04 10:49:39 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , setRemoteDeviceVolume Mar 04 10:49:39 volumio volumio[1015]: info: Setting Remote Device Volume: http://192.168.3.107 Mar 04 10:49:39 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , setRemoteDeviceVolume Mar 04 10:49:39 volumio volumio[1015]: info: Setting Remote Device Volume: http://192.168.3.107 Mar 04 10:49:39 volumio volumio[1015]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: Invalid card number. Mar 04 10:49:39 volumio volumio[1015]: info: [ASDebug] CurState: stop PrevState: stop Mar 04 10:49:39 volumio volumio[1015]: info: [GPIO_Control] Status changed: stop Mar 04 10:49:39 volumio volumio[1015]: SPOTIFY: RECEIVED VOLUMIO VOLUME 33 Mar 04 10:49:39 volumio volumio[1015]: SPOTIFY: SPOTIFY VOLUME 31 Mar 04 10:49:39 volumio volumio[1015]: SPOTIFY: VOLUMIO VOLUME 33 Mar 04 10:49:39 volumio volumio[1015]: SPOTIFY: DELTA VOLUME ENOUGH: true Mar 04 10:49:39 volumio volumio[1015]: info: Setting Spotify Volume from Volumio: 33 Mar 04 10:49:39 volumio volumio[1015]: info: Done setting volume on: Mar 04 10:49:39 volumio volumio[1015]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: Invalid card number. Mar 04 10:49:39 volumio volumio[1015]: 0+0 records in Mar 04 10:49:39 volumio volumio[1015]: 0+0 records out Mar 04 10:49:39 volumio volumio[1015]: 0 bytes copied, 0.000134474 s, 0.0 kB/s Mar 04 10:49:39 volumio volumio[1015]: info: camilladsp spawned new process with pid 5027, instance 1, run: true Mar 04 10:49:39 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , setRemoteDeviceVolume Mar 04 10:49:39 volumio volumio[1015]: info: Setting Remote Device Volume: http://192.168.3.107 Mar 04 10:49:39 volumio volumio[1015]: info: Mar 04 10:49:39 volumio volumio[1015]: ---------------------------- Client requests Volume 33 Mar 04 10:49:39 volumio volumio[1015]: info: VolumeController::SetAlsaVolume33 Mar 04 10:49:39 volumio volumio[1015]: info: CoreStateMachine::pushState Mar 04 10:49:39 volumio volumio[1015]: info: CorePlayQueue::getTrack 5 Mar 04 10:49:39 volumio volumio[1015]: info: CoreCommandRouter::volumioPushState Mar 04 10:49:39 volumio volumio[1015]: info: MRS: Pushing multiroomSync output update for this device Mar 04 10:49:39 volumio volumio[1015]: info: MRS: Pushing multiroomSync output Mar 04 10:49:39 volumio volumio[1015]: info: Mar 04 10:49:39 volumio volumio[1015]: ---------------------------- Client requests Volume 33 Mar 04 10:49:39 volumio volumio[1015]: info: VolumeController::SetAlsaVolume33 Mar 04 10:49:39 volumio volumio[1015]: info: CoreStateMachine::pushState Mar 04 10:49:39 volumio volumio[1015]: info: CorePlayQueue::getTrack 5 Mar 04 10:49:39 volumio volumio[1015]: info: CoreCommandRouter::volumioPushState Mar 04 10:49:39 volumio volumio[1015]: info: MRS: Pushing multiroomSync output update for this device Mar 04 10:49:39 volumio volumio[1015]: info: MRS: Pushing multiroomSync output Mar 04 10:49:39 volumio volumio[1015]: info: Mar 04 10:49:39 volumio volumio[1015]: ---------------------------- Client requests Volume 34 Mar 04 10:49:39 volumio volumio[1015]: info: VolumeController::SetAlsaVolume34 Mar 04 10:49:39 volumio volumio[1015]: info: CoreStateMachine::pushState Mar 04 10:49:39 volumio volumio[1015]: info: CorePlayQueue::getTrack 5 Mar 04 10:49:39 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 04 10:49:39 volumio volumio[1015]: info: CoreCommandRouter::volumioPushState Mar 04 10:49:39 volumio volumio[1015]: info: MRS: Pushing multiroomSync output update for this device Mar 04 10:49:39 volumio volumio[1015]: info: MRS: Pushing multiroomSync output Mar 04 10:49:39 volumio volumio[1015]: info: [ASDebug] CurState: stop PrevState: stop Mar 04 10:49:39 volumio volumio[1015]: info: [ASDebug] CurState: stop PrevState: stop Mar 04 10:49:39 volumio volumio[1015]: info: [ASDebug] CurState: stop PrevState: stop Mar 04 10:49:39 volumio volumio[1015]: info: [GPIO_Control] Status changed: stop Mar 04 10:49:39 volumio volumio[1015]: info: [GPIO_Control] Status changed: stop Mar 04 10:49:39 volumio volumio[1015]: info: [GPIO_Control] Status changed: stop Mar 04 10:49:39 volumio volumio[1015]: SPOTIFY: RECEIVED VOLUMIO VOLUME 33 Mar 04 10:49:39 volumio volumio[1015]: SPOTIFY: RECEIVED VOLUMIO VOLUME 33 Mar 04 10:49:39 volumio volumio[1015]: SPOTIFY: RECEIVED VOLUMIO VOLUME 34 Mar 04 10:49:39 volumio volumio[1015]: SPOTIFY: SPOTIFY VOLUME 33 Mar 04 10:49:39 volumio volumio[1015]: SPOTIFY: VOLUMIO VOLUME 34 Mar 04 10:49:39 volumio volumio[1015]: SPOTIFY: DELTA VOLUME ENOUGH: false Mar 04 10:49:39 volumio volumio[1015]: info: Done setting volume on: Mar 04 10:49:39 volumio volumio[1015]: info: Done setting volume on: Mar 04 10:49:39 volumio volumio[1015]: info: Done setting volume on: Mar 04 10:49:39 volumio volumio[1015]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: Invalid card number. Mar 04 10:49:39 volumio volumio[1015]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: Invalid card number. Mar 04 10:49:39 volumio volumio[1015]: info: Mar 04 10:49:39 volumio volumio[1015]: ---------------------------- Client requests Volume 35 Mar 04 10:49:39 volumio volumio[1015]: info: VolumeController::SetAlsaVolume35 Mar 04 10:49:39 volumio volumio[1015]: info: CoreStateMachine::pushState Mar 04 10:49:39 volumio volumio[1015]: info: CorePlayQueue::getTrack 5 Mar 04 10:49:39 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 04 10:49:39 volumio volumio[1015]: info: CoreCommandRouter::volumioPushState Mar 04 10:49:39 volumio volumio[1015]: info: MRS: Pushing multiroomSync output update for this device Mar 04 10:49:39 volumio volumio[1015]: info: MRS: Pushing multiroomSync output Mar 04 10:49:39 volumio volumio[1015]: info: [ASDebug] CurState: stop PrevState: stop Mar 04 10:49:39 volumio volumio[1015]: info: [GPIO_Control] Status changed: stop Mar 04 10:49:39 volumio volumio[1015]: SPOTIFY: RECEIVED VOLUMIO VOLUME 35 Mar 04 10:49:39 volumio volumio[1015]: SPOTIFY: SPOTIFY VOLUME 33 Mar 04 10:49:39 volumio volumio[1015]: SPOTIFY: VOLUMIO VOLUME 35 Mar 04 10:49:39 volumio volumio[1015]: SPOTIFY: DELTA VOLUME ENOUGH: true Mar 04 10:49:39 volumio volumio[1015]: info: Setting Spotify Volume from Volumio: 35 Mar 04 10:49:39 volumio volumio[1015]: info: Done setting volume on: Mar 04 10:49:39 volumio volumio[1015]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: Invalid card number. Mar 04 10:49:40 volumio volumio[1015]: 0+0 records in Mar 04 10:49:40 volumio volumio[1015]: 0+0 records out Mar 04 10:49:40 volumio volumio[1015]: 0 bytes copied, 0.000125829 s, 0.0 kB/s Mar 04 10:49:40 volumio volumio[1015]: info: camilladsp spawned new process with pid 5036, instance 1, run: true Mar 04 10:49:40 volumio volumio[1015]: SPOTIFY: SETTING SPOTIFY VOLUME 35 Mar 04 10:49:40 volumio volumio[1015]: info: Sending Spotify command with payload to local API: /player/volume Mar 04 10:49:41 volumio go-librespot[24674]: time="2025-03-04T10:49:41+06:00" level=debug msg="update volume to 22937/65535" Mar 04 10:49:41 volumio volumio[1015]: 0+0 records in Mar 04 10:49:41 volumio volumio[1015]: 0+0 records out Mar 04 10:49:41 volumio volumio[1015]: 0 bytes copied, 0.000126975 s, 0.0 kB/s Mar 04 10:49:41 volumio volumio[1015]: info: camilladsp spawned new process with pid 5041, instance 1, run: true Mar 04 10:49:42 volumio go-librespot[24674]: time="2025-03-04T10:49:42+06:00" level=debug msg="put connect state because VOLUME_CHANGED" Mar 04 10:49:42 volumio go-librespot[24674]: time="2025-03-04T10:49:42+06:00" level=trace msg="emitting websocket event: volume" Mar 04 10:49:42 volumio volumio[1015]: SPOTIFY: received: {"type":"volume","data":{"value":35,"max":100}} Mar 04 10:49:42 volumio volumio[1015]: SPOTIFY: RECEIVED SPOTIFY VOLUME 35 Mar 04 10:49:42 volumio volumio[1015]: SPOTIFY: received: {"type":"volume","data":{"value":35,"max":100}} Mar 04 10:49:42 volumio volumio[1015]: SPOTIFY: RECEIVED SPOTIFY VOLUME 35 Mar 04 10:49:42 volumio volumio[1015]: 0+0 records in Mar 04 10:49:42 volumio volumio[1015]: 0+0 records out Mar 04 10:49:42 volumio volumio[1015]: 0 bytes copied, 0.000122287 s, 0.0 kB/s Mar 04 10:49:42 volumio volumio[1015]: info: camilladsp spawned new process with pid 5046, instance 1, run: true Mar 04 10:49:43 volumio volumio[1015]: 0+0 records in Mar 04 10:49:43 volumio volumio[1015]: 0+0 records out Mar 04 10:49:43 volumio volumio[1015]: 0 bytes copied, 0.000121923 s, 0.0 kB/s Mar 04 10:49:43 volumio volumio[1015]: info: camilladsp spawned new process with pid 5051, instance 1, run: true Mar 04 10:49:44 volumio volumio[1015]: 0+0 records in Mar 04 10:49:44 volumio volumio[1015]: 0+0 records out Mar 04 10:49:44 volumio volumio[1015]: 0 bytes copied, 0.000119475 s, 0.0 kB/s Mar 04 10:49:44 volumio volumio[1015]: info: camilladsp spawned new process with pid 5056, instance 1, run: true Mar 04 10:49:45 volumio volumio[1015]: 0+0 records in Mar 04 10:49:45 volumio volumio[1015]: 0+0 records out Mar 04 10:49:45 volumio volumio[1015]: 0 bytes copied, 0.000121037 s, 0.0 kB/s Mar 04 10:49:45 volumio volumio[1015]: info: camilladsp spawned new process with pid 5064, instance 1, run: true Mar 04 10:49:46 volumio volumio[1015]: 0+0 records in Mar 04 10:49:46 volumio volumio[1015]: 0+0 records out Mar 04 10:49:46 volumio volumio[1015]: 0 bytes copied, 0.000141089 s, 0.0 kB/s Mar 04 10:49:46 volumio volumio[1015]: info: camilladsp spawned new process with pid 5083, instance 1, run: true Mar 04 10:49:47 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: system , getHwuuid Mar 04 10:49:47 volumio volumio[1015]: info: Playing Remote Device: http://192.168.3.107 Mar 04 10:49:47 volumio volumio[1015]: info: Mar 04 10:49:47 volumio volumio[1015]: ---------------------------- Client requests Volumio play Mar 04 10:49:47 volumio volumio[1015]: info: CoreCommandRouter::volumioPlay Mar 04 10:49:47 volumio volumio[1015]: info: CoreStateMachine::play index undefined Mar 04 10:49:47 volumio volumio[1015]: info: CoreStateMachine::setConsumeUpdateService undefined Mar 04 10:49:47 volumio volumio[1015]: info: CorePlayQueue::getTrack 5 Mar 04 10:49:47 volumio volumio[1015]: info: CoreStateMachine::startPlaybackTimer Mar 04 10:49:47 volumio volumio[1015]: info: CorePlayQueue::getTrack 5 Mar 04 10:49:47 volumio volumio[1015]: info: [1741063787029] ControllerSpotify::clearAddPlayTrack Mar 04 10:49:47 volumio volumio[1015]: info: Sending Spotify command with payload to local API: /player/play Mar 04 10:49:47 volumio volumio[1015]: info: Done playing: Mar 04 10:49:47 volumio go-librespot[24674]: time="2025-03-04T10:49:47+06:00" level=debug msg="resolved context of track" uri="spotify:track:43jExF2HeZ6cJIGrWF0ie4" Mar 04 10:49:47 volumio go-librespot[24674]: time="2025-03-04T10:49:47+06:00" level=trace msg="fetched new page 0 with 1 items (list: 1)" uri="spotify:track:43jExF2HeZ6cJIGrWF0ie4" Mar 04 10:49:47 volumio go-librespot[24674]: time="2025-03-04T10:49:47+06:00" level=debug msg="loading track (paused: false, position: 0ms)" uri="spotify:track:43jExF2HeZ6cJIGrWF0ie4" Mar 04 10:49:47 volumio volumio[1015]: 0+0 records in Mar 04 10:49:47 volumio volumio[1015]: 0+0 records out Mar 04 10:49:47 volumio volumio[1015]: 0 bytes copied, 0.000122965 s, 0.0 kB/s Mar 04 10:49:47 volumio volumio[1015]: info: camilladsp spawned new process with pid 5088, instance 1, run: true Mar 04 10:49:47 volumio go-librespot[24674]: time="2025-03-04T10:49:47+06:00" level=debug msg="put connect state because PLAYER_STATE_CHANGED" Mar 04 10:49:47 volumio go-librespot[24674]: time="2025-03-04T10:49:47+06:00" level=trace msg="emitting websocket event: will_play" Mar 04 10:49:47 volumio volumio[1015]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:43jExF2HeZ6cJIGrWF0ie4","play_origin":"go-librespot"}} Mar 04 10:49:47 volumio volumio[1015]: SPOTIFY: received: {"type":"will_play","data":{"uri":"spotify:track:43jExF2HeZ6cJIGrWF0ie4","play_origin":"go-librespot"}} Mar 04 10:49:48 volumio go-librespot[24674]: time="2025-03-04T10:49:48+06:00" level=debug msg="selected format OGG_VORBIS_320 (44adeb2a46a76b524d6d9d7930da9669c4a03dff)" uri="spotify:track:43jExF2HeZ6cJIGrWF0ie4" Mar 04 10:49:48 volumio go-librespot[24674]: time="2025-03-04T10:49:48+06:00" level=debug msg="requested aes key for file 44adeb2a46a76b524d6d9d7930da9669c4a03dff, gid: 43jExF2HeZ6cJIGrWF0ie4" Mar 04 10:49:48 volumio go-librespot[24674]: time="2025-03-04T10:49:48+06:00" level=error msg="failed handling request play" error="failed loading context: failed loading current track (load context): failed creating stream for spotify:track:43jExF2HeZ6cJIGrWF0ie4: failed retrieving audio key: failed retrieving aes key with code 1" Mar 04 10:49:48 volumio volumio[1015]: error: Failed to send command to Spotify local API: /player/play: Error: Internal Server Error Mar 04 10:49:48 volumio volumio[1015]: 0+0 records in Mar 04 10:49:48 volumio volumio[1015]: 0+0 records out Mar 04 10:49:48 volumio volumio[1015]: 0 bytes copied, 0.000123016 s, 0.0 kB/s Mar 04 10:49:48 volumio volumio[1015]: info: camilladsp spawned new process with pid 5093, instance 1, run: true Mar 04 10:49:49 volumio volumio[1015]: 0+0 records in Mar 04 10:49:49 volumio volumio[1015]: 0+0 records out Mar 04 10:49:49 volumio volumio[1015]: 0 bytes copied, 0.000123328 s, 0.0 kB/s Mar 04 10:49:49 volumio volumio[1015]: info: camilladsp spawned new process with pid 5098, instance 1, run: true Mar 04 10:49:51 volumio volumio[1015]: 0+0 records in Mar 04 10:49:51 volumio volumio[1015]: 0+0 records out Mar 04 10:49:51 volumio volumio[1015]: 0 bytes copied, 0.000175514 s, 0.0 kB/s Mar 04 10:49:51 volumio volumio[1015]: info: camilladsp spawned new process with pid 5103, instance 1, run: true Mar 04 10:49:51 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , setRemoteDeviceVolume Mar 04 10:49:51 volumio volumio[1015]: info: Setting Remote Device Volume: http://192.168.3.107 Mar 04 10:49:51 volumio volumio[1015]: info: Mar 04 10:49:51 volumio volumio[1015]: ---------------------------- Client requests Volume 38 Mar 04 10:49:51 volumio volumio[1015]: info: VolumeController::SetAlsaVolume38 Mar 04 10:49:51 volumio volumio[1015]: info: CoreStateMachine::pushState Mar 04 10:49:51 volumio volumio[1015]: info: CorePlayQueue::getTrack 5 Mar 04 10:49:51 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 04 10:49:51 volumio volumio[1015]: info: CoreCommandRouter::volumioPushState Mar 04 10:49:51 volumio volumio[1015]: info: MRS: Pushing multiroomSync output update for this device Mar 04 10:49:51 volumio volumio[1015]: info: MRS: Pushing multiroomSync output Mar 04 10:49:51 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , setRemoteDeviceVolume Mar 04 10:49:51 volumio volumio[1015]: info: Setting Remote Device Volume: http://192.168.3.107 Mar 04 10:49:51 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , setRemoteDeviceVolume Mar 04 10:49:51 volumio volumio[1015]: info: Setting Remote Device Volume: http://192.168.3.107 Mar 04 10:49:51 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , setRemoteDeviceVolume Mar 04 10:49:51 volumio volumio[1015]: info: Setting Remote Device Volume: http://192.168.3.107 Mar 04 10:49:51 volumio volumio[1015]: info: [ASDebug] CurState: stop PrevState: stop Mar 04 10:49:51 volumio volumio[1015]: info: [GPIO_Control] Status changed: stop Mar 04 10:49:51 volumio volumio[1015]: SPOTIFY: RECEIVED VOLUMIO VOLUME 38 Mar 04 10:49:51 volumio volumio[1015]: SPOTIFY: SPOTIFY VOLUME 35 Mar 04 10:49:51 volumio volumio[1015]: SPOTIFY: VOLUMIO VOLUME 38 Mar 04 10:49:51 volumio volumio[1015]: SPOTIFY: DELTA VOLUME ENOUGH: true Mar 04 10:49:51 volumio volumio[1015]: info: Setting Spotify Volume from Volumio: 38 Mar 04 10:49:51 volumio volumio[1015]: info: Done setting volume on: Mar 04 10:49:51 volumio volumio[1015]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: Invalid card number. Mar 04 10:49:51 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , setRemoteDeviceVolume Mar 04 10:49:51 volumio volumio[1015]: info: Setting Remote Device Volume: http://192.168.3.107 Mar 04 10:49:51 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , setRemoteDeviceVolume Mar 04 10:49:51 volumio volumio[1015]: info: Setting Remote Device Volume: http://192.168.3.107 Mar 04 10:49:51 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , setRemoteDeviceVolume Mar 04 10:49:51 volumio volumio[1015]: info: Setting Remote Device Volume: http://192.168.3.107 Mar 04 10:49:51 volumio volumio[1015]: info: Mar 04 10:49:51 volumio volumio[1015]: ---------------------------- Client requests Volume 39 Mar 04 10:49:51 volumio volumio[1015]: info: VolumeController::SetAlsaVolume39 Mar 04 10:49:51 volumio volumio[1015]: info: CoreStateMachine::pushState Mar 04 10:49:51 volumio volumio[1015]: info: CorePlayQueue::getTrack 5 Mar 04 10:49:51 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 04 10:49:51 volumio volumio[1015]: info: CoreCommandRouter::volumioPushState Mar 04 10:49:51 volumio volumio[1015]: info: MRS: Pushing multiroomSync output update for this device Mar 04 10:49:51 volumio volumio[1015]: info: MRS: Pushing multiroomSync output Mar 04 10:49:51 volumio volumio[1015]: info: Mar 04 10:49:51 volumio volumio[1015]: ---------------------------- Client requests Volume 41 Mar 04 10:49:51 volumio volumio[1015]: info: VolumeController::SetAlsaVolume41 Mar 04 10:49:51 volumio volumio[1015]: info: CoreStateMachine::pushState Mar 04 10:49:51 volumio volumio[1015]: info: CorePlayQueue::getTrack 5 Mar 04 10:49:51 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 04 10:49:51 volumio volumio[1015]: info: CoreCommandRouter::volumioPushState Mar 04 10:49:51 volumio volumio[1015]: info: MRS: Pushing multiroomSync output update for this device Mar 04 10:49:51 volumio volumio[1015]: info: MRS: Pushing multiroomSync output Mar 04 10:49:51 volumio volumio[1015]: info: Mar 04 10:49:51 volumio volumio[1015]: ---------------------------- Client requests Volume 44 Mar 04 10:49:51 volumio volumio[1015]: info: VolumeController::SetAlsaVolume44 Mar 04 10:49:51 volumio volumio[1015]: info: CoreStateMachine::pushState Mar 04 10:49:51 volumio volumio[1015]: info: CorePlayQueue::getTrack 5 Mar 04 10:49:51 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 04 10:49:51 volumio volumio[1015]: info: CoreCommandRouter::volumioPushState Mar 04 10:49:51 volumio volumio[1015]: info: MRS: Pushing multiroomSync output update for this device Mar 04 10:49:51 volumio volumio[1015]: info: MRS: Pushing multiroomSync output Mar 04 10:49:51 volumio volumio[1015]: info: Mar 04 10:49:51 volumio volumio[1015]: ---------------------------- Client requests Volume 45 Mar 04 10:49:51 volumio volumio[1015]: info: VolumeController::SetAlsaVolume45 Mar 04 10:49:51 volumio volumio[1015]: info: CoreStateMachine::pushState Mar 04 10:49:51 volumio volumio[1015]: info: CorePlayQueue::getTrack 5 Mar 04 10:49:51 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 04 10:49:51 volumio volumio[1015]: info: CoreCommandRouter::volumioPushState Mar 04 10:49:51 volumio volumio[1015]: info: MRS: Pushing multiroomSync output update for this device Mar 04 10:49:51 volumio volumio[1015]: info: MRS: Pushing multiroomSync output Mar 04 10:49:51 volumio volumio[1015]: info: Mar 04 10:49:51 volumio volumio[1015]: ---------------------------- Client requests Volume 48 Mar 04 10:49:51 volumio volumio[1015]: info: VolumeController::SetAlsaVolume48 Mar 04 10:49:51 volumio volumio[1015]: info: CoreStateMachine::pushState Mar 04 10:49:51 volumio volumio[1015]: info: CorePlayQueue::getTrack 5 Mar 04 10:49:51 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 04 10:49:51 volumio volumio[1015]: info: CoreCommandRouter::volumioPushState Mar 04 10:49:51 volumio volumio[1015]: info: MRS: Pushing multiroomSync output update for this device Mar 04 10:49:51 volumio volumio[1015]: info: MRS: Pushing multiroomSync output Mar 04 10:49:51 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , setRemoteDeviceVolume Mar 04 10:49:51 volumio volumio[1015]: info: Setting Remote Device Volume: http://192.168.3.107 Mar 04 10:49:51 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , setRemoteDeviceVolume Mar 04 10:49:51 volumio volumio[1015]: info: Setting Remote Device Volume: http://192.168.3.107 Mar 04 10:49:51 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , setRemoteDeviceVolume Mar 04 10:49:51 volumio volumio[1015]: info: Setting Remote Device Volume: http://192.168.3.107 Mar 04 10:49:51 volumio volumio[1015]: info: [ASDebug] CurState: stop PrevState: stop Mar 04 10:49:51 volumio volumio[1015]: info: [ASDebug] CurState: stop PrevState: stop Mar 04 10:49:51 volumio volumio[1015]: info: [ASDebug] CurState: stop PrevState: stop Mar 04 10:49:51 volumio volumio[1015]: info: [ASDebug] CurState: stop PrevState: stop Mar 04 10:49:51 volumio volumio[1015]: info: [ASDebug] CurState: stop PrevState: stop Mar 04 10:49:51 volumio volumio[1015]: info: [GPIO_Control] Status changed: stop Mar 04 10:49:51 volumio volumio[1015]: info: [GPIO_Control] Status changed: stop Mar 04 10:49:51 volumio volumio[1015]: info: [GPIO_Control] Status changed: stop Mar 04 10:49:51 volumio volumio[1015]: info: [GPIO_Control] Status changed: stop Mar 04 10:49:51 volumio volumio[1015]: info: [GPIO_Control] Status changed: stop Mar 04 10:49:51 volumio volumio[1015]: SPOTIFY: RECEIVED VOLUMIO VOLUME 39 Mar 04 10:49:51 volumio volumio[1015]: SPOTIFY: SPOTIFY VOLUME 38 Mar 04 10:49:51 volumio volumio[1015]: SPOTIFY: VOLUMIO VOLUME 39 Mar 04 10:49:51 volumio volumio[1015]: SPOTIFY: DELTA VOLUME ENOUGH: false Mar 04 10:49:51 volumio volumio[1015]: SPOTIFY: RECEIVED VOLUMIO VOLUME 41 Mar 04 10:49:51 volumio volumio[1015]: SPOTIFY: SPOTIFY VOLUME 38 Mar 04 10:49:51 volumio volumio[1015]: SPOTIFY: VOLUMIO VOLUME 41 Mar 04 10:49:51 volumio volumio[1015]: SPOTIFY: DELTA VOLUME ENOUGH: true Mar 04 10:49:51 volumio volumio[1015]: info: Setting Spotify Volume from Volumio: 41 Mar 04 10:49:51 volumio volumio[1015]: SPOTIFY: RECEIVED VOLUMIO VOLUME 44 Mar 04 10:49:51 volumio volumio[1015]: SPOTIFY: SPOTIFY VOLUME 41 Mar 04 10:49:51 volumio volumio[1015]: SPOTIFY: VOLUMIO VOLUME 44 Mar 04 10:49:51 volumio volumio[1015]: SPOTIFY: DELTA VOLUME ENOUGH: true Mar 04 10:49:51 volumio volumio[1015]: info: Setting Spotify Volume from Volumio: 44 Mar 04 10:49:51 volumio volumio[1015]: SPOTIFY: RECEIVED VOLUMIO VOLUME 45 Mar 04 10:49:51 volumio volumio[1015]: SPOTIFY: SPOTIFY VOLUME 44 Mar 04 10:49:51 volumio volumio[1015]: SPOTIFY: VOLUMIO VOLUME 45 Mar 04 10:49:51 volumio volumio[1015]: SPOTIFY: DELTA VOLUME ENOUGH: false Mar 04 10:49:51 volumio volumio[1015]: SPOTIFY: RECEIVED VOLUMIO VOLUME 48 Mar 04 10:49:51 volumio volumio[1015]: SPOTIFY: SPOTIFY VOLUME 44 Mar 04 10:49:51 volumio volumio[1015]: SPOTIFY: VOLUMIO VOLUME 48 Mar 04 10:49:51 volumio volumio[1015]: SPOTIFY: DELTA VOLUME ENOUGH: true Mar 04 10:49:51 volumio volumio[1015]: info: Setting Spotify Volume from Volumio: 48 Mar 04 10:49:51 volumio volumio[1015]: info: Done setting volume on: Mar 04 10:49:51 volumio volumio[1015]: info: Done setting volume on: Mar 04 10:49:51 volumio volumio[1015]: info: Done setting volume on: Mar 04 10:49:51 volumio volumio[1015]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: Invalid card number. Mar 04 10:49:51 volumio volumio[1015]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: Invalid card number. Mar 04 10:49:51 volumio volumio[1015]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: Invalid card number. Mar 04 10:49:51 volumio volumio[1015]: info: Mar 04 10:49:51 volumio volumio[1015]: ---------------------------- Client requests Volume 50 Mar 04 10:49:51 volumio volumio[1015]: info: VolumeController::SetAlsaVolume50 Mar 04 10:49:51 volumio volumio[1015]: info: CoreStateMachine::pushState Mar 04 10:49:51 volumio volumio[1015]: info: CorePlayQueue::getTrack 5 Mar 04 10:49:51 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 04 10:49:51 volumio volumio[1015]: info: CoreCommandRouter::volumioPushState Mar 04 10:49:51 volumio volumio[1015]: info: MRS: Pushing multiroomSync output update for this device Mar 04 10:49:51 volumio volumio[1015]: info: MRS: Pushing multiroomSync output Mar 04 10:49:51 volumio volumio[1015]: info: Done setting volume on: Mar 04 10:49:51 volumio volumio[1015]: info: Done setting volume on: Mar 04 10:49:51 volumio volumio[1015]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: Invalid card number. Mar 04 10:49:51 volumio volumio[1015]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: Invalid card number. Mar 04 10:49:51 volumio volumio[1015]: info: [ASDebug] CurState: stop PrevState: stop Mar 04 10:49:51 volumio volumio[1015]: info: [GPIO_Control] Status changed: stop Mar 04 10:49:51 volumio volumio[1015]: SPOTIFY: RECEIVED VOLUMIO VOLUME 50 Mar 04 10:49:51 volumio volumio[1015]: SPOTIFY: SPOTIFY VOLUME 48 Mar 04 10:49:51 volumio volumio[1015]: SPOTIFY: VOLUMIO VOLUME 50 Mar 04 10:49:51 volumio volumio[1015]: SPOTIFY: DELTA VOLUME ENOUGH: true Mar 04 10:49:51 volumio volumio[1015]: info: Setting Spotify Volume from Volumio: 50 Mar 04 10:49:51 volumio volumio[1015]: info: Done setting volume on: Mar 04 10:49:51 volumio volumio[1015]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: Invalid card number. Mar 04 10:49:51 volumio volumio[1015]: info: Mar 04 10:49:51 volumio volumio[1015]: ---------------------------- Client requests Volume 52 Mar 04 10:49:51 volumio volumio[1015]: info: VolumeController::SetAlsaVolume52 Mar 04 10:49:52 volumio volumio[1015]: info: CoreStateMachine::pushState Mar 04 10:49:52 volumio volumio[1015]: info: CorePlayQueue::getTrack 5 Mar 04 10:49:52 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 04 10:49:52 volumio volumio[1015]: info: CoreCommandRouter::volumioPushState Mar 04 10:49:52 volumio volumio[1015]: info: MRS: Pushing multiroomSync output update for this device Mar 04 10:49:52 volumio volumio[1015]: info: MRS: Pushing multiroomSync output Mar 04 10:49:52 volumio volumio[1015]: info: Mar 04 10:49:52 volumio volumio[1015]: ---------------------------- Client requests Volume 53 Mar 04 10:49:52 volumio volumio[1015]: info: VolumeController::SetAlsaVolume53 Mar 04 10:49:52 volumio volumio[1015]: info: CoreStateMachine::pushState Mar 04 10:49:52 volumio volumio[1015]: info: CorePlayQueue::getTrack 5 Mar 04 10:49:52 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 04 10:49:52 volumio volumio[1015]: info: CoreCommandRouter::volumioPushState Mar 04 10:49:52 volumio volumio[1015]: info: MRS: Pushing multiroomSync output update for this device Mar 04 10:49:52 volumio volumio[1015]: info: MRS: Pushing multiroomSync output Mar 04 10:49:52 volumio volumio[1015]: info: Mar 04 10:49:52 volumio volumio[1015]: ---------------------------- Client requests Volume 54 Mar 04 10:49:52 volumio volumio[1015]: info: VolumeController::SetAlsaVolume54 Mar 04 10:49:52 volumio volumio[1015]: info: CoreStateMachine::pushState Mar 04 10:49:52 volumio volumio[1015]: info: CorePlayQueue::getTrack 5 Mar 04 10:49:52 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 04 10:49:52 volumio volumio[1015]: info: CoreCommandRouter::volumioPushState Mar 04 10:49:52 volumio volumio[1015]: info: MRS: Pushing multiroomSync output update for this device Mar 04 10:49:52 volumio volumio[1015]: info: MRS: Pushing multiroomSync output Mar 04 10:49:52 volumio volumio[1015]: 0+0 records in Mar 04 10:49:52 volumio volumio[1015]: 0+0 records out Mar 04 10:49:52 volumio volumio[1015]: 0 bytes copied, 0.000123173 s, 0.0 kB/s Mar 04 10:49:52 volumio volumio[1015]: info: camilladsp spawned new process with pid 5118, instance 1, run: true Mar 04 10:49:52 volumio volumio[1015]: info: [ASDebug] CurState: stop PrevState: stop Mar 04 10:49:52 volumio volumio[1015]: info: [ASDebug] CurState: stop PrevState: stop Mar 04 10:49:52 volumio volumio[1015]: info: [ASDebug] CurState: stop PrevState: stop Mar 04 10:49:52 volumio volumio[1015]: info: [GPIO_Control] Status changed: stop Mar 04 10:49:52 volumio volumio[1015]: info: [GPIO_Control] Status changed: stop Mar 04 10:49:52 volumio volumio[1015]: info: [GPIO_Control] Status changed: stop Mar 04 10:49:52 volumio volumio[1015]: SPOTIFY: RECEIVED VOLUMIO VOLUME 52 Mar 04 10:49:52 volumio volumio[1015]: SPOTIFY: SPOTIFY VOLUME 50 Mar 04 10:49:52 volumio volumio[1015]: SPOTIFY: VOLUMIO VOLUME 52 Mar 04 10:49:52 volumio volumio[1015]: SPOTIFY: DELTA VOLUME ENOUGH: true Mar 04 10:49:52 volumio volumio[1015]: info: Setting Spotify Volume from Volumio: 52 Mar 04 10:49:52 volumio volumio[1015]: SPOTIFY: RECEIVED VOLUMIO VOLUME 53 Mar 04 10:49:52 volumio volumio[1015]: SPOTIFY: SPOTIFY VOLUME 52 Mar 04 10:49:52 volumio volumio[1015]: SPOTIFY: VOLUMIO VOLUME 53 Mar 04 10:49:52 volumio volumio[1015]: SPOTIFY: DELTA VOLUME ENOUGH: false Mar 04 10:49:52 volumio volumio[1015]: SPOTIFY: RECEIVED VOLUMIO VOLUME 54 Mar 04 10:49:52 volumio volumio[1015]: SPOTIFY: SPOTIFY VOLUME 52 Mar 04 10:49:52 volumio volumio[1015]: SPOTIFY: VOLUMIO VOLUME 54 Mar 04 10:49:52 volumio volumio[1015]: SPOTIFY: DELTA VOLUME ENOUGH: true Mar 04 10:49:52 volumio volumio[1015]: info: Setting Spotify Volume from Volumio: 54 Mar 04 10:49:52 volumio volumio[1015]: info: Done setting volume on: Mar 04 10:49:52 volumio volumio[1015]: info: Done setting volume on: Mar 04 10:49:52 volumio volumio[1015]: info: Done setting volume on: Mar 04 10:49:52 volumio volumio[1015]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: Invalid card number. Mar 04 10:49:52 volumio volumio[1015]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: Invalid card number. Mar 04 10:49:52 volumio volumio[1015]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: Invalid card number. Mar 04 10:49:53 volumio volumio[1015]: 0+0 records in Mar 04 10:49:53 volumio volumio[1015]: 0+0 records out Mar 04 10:49:53 volumio volumio[1015]: 0 bytes copied, 0.000124162 s, 0.0 kB/s Mar 04 10:49:53 volumio volumio[1015]: info: camilladsp spawned new process with pid 5123, instance 1, run: true Mar 04 10:49:53 volumio volumio[1015]: SPOTIFY: SETTING SPOTIFY VOLUME 54 Mar 04 10:49:53 volumio volumio[1015]: info: Sending Spotify command with payload to local API: /player/volume Mar 04 10:49:53 volumio go-librespot[24674]: time="2025-03-04T10:49:53+06:00" level=debug msg="update volume to 35388/65535" Mar 04 10:49:54 volumio volumio[1015]: 0+0 records in Mar 04 10:49:54 volumio volumio[1015]: 0+0 records out Mar 04 10:49:54 volumio volumio[1015]: 0 bytes copied, 0.000141558 s, 0.0 kB/s Mar 04 10:49:54 volumio volumio[1015]: info: camilladsp spawned new process with pid 5128, instance 1, run: true Mar 04 10:49:55 volumio volumio[1015]: 0+0 records in Mar 04 10:49:55 volumio volumio[1015]: 0+0 records out Mar 04 10:49:55 volumio volumio[1015]: 0 bytes copied, 0.00012161 s, 0.0 kB/s Mar 04 10:49:55 volumio go-librespot[24674]: time="2025-03-04T10:49:55+06:00" level=debug msg="put connect state because VOLUME_CHANGED" Mar 04 10:49:55 volumio go-librespot[24674]: time="2025-03-04T10:49:55+06:00" level=trace msg="emitting websocket event: volume" Mar 04 10:49:55 volumio volumio[1015]: info: camilladsp spawned new process with pid 5133, instance 1, run: true Mar 04 10:49:55 volumio volumio[1015]: SPOTIFY: received: {"type":"volume","data":{"value":54,"max":100}} Mar 04 10:49:55 volumio volumio[1015]: SPOTIFY: RECEIVED SPOTIFY VOLUME 54 Mar 04 10:49:55 volumio volumio[1015]: SPOTIFY: received: {"type":"volume","data":{"value":54,"max":100}} Mar 04 10:49:55 volumio volumio[1015]: SPOTIFY: RECEIVED SPOTIFY VOLUME 54 Mar 04 10:49:56 volumio volumio[1015]: info: CoreCommandRouter::volumioGetQueue Mar 04 10:49:56 volumio volumio[1015]: info: CoreStateMachine::getQueue Mar 04 10:49:56 volumio volumio[1015]: info: CorePlayQueue::getQueue Mar 04 10:49:56 volumio volumio[1015]: 0+0 records in Mar 04 10:49:56 volumio volumio[1015]: 0+0 records out Mar 04 10:49:56 volumio volumio[1015]: 0 bytes copied, 0.000123433 s, 0.0 kB/s Mar 04 10:49:56 volumio volumio[1015]: info: camilladsp spawned new process with pid 5155, instance 1, run: true Mar 04 10:49:57 volumio volumio[1015]: 0+0 records in Mar 04 10:49:57 volumio volumio[1015]: 0+0 records out Mar 04 10:49:57 volumio volumio[1015]: 0 bytes copied, 0.000120725 s, 0.0 kB/s Mar 04 10:49:57 volumio volumio[1015]: info: camilladsp spawned new process with pid 5161, instance 1, run: true Mar 04 10:49:58 volumio go-librespot[24674]: time="2025-03-04T10:49:58+06:00" level=trace msg="received accesspoint ping" Mar 04 10:49:58 volumio volumio[1015]: 0+0 records in Mar 04 10:49:58 volumio volumio[1015]: 0+0 records out Mar 04 10:49:58 volumio volumio[1015]: 0 bytes copied, 0.000122235 s, 0.0 kB/s Mar 04 10:49:58 volumio volumio[1015]: info: camilladsp spawned new process with pid 5166, instance 1, run: true Mar 04 10:49:58 volumio go-librespot[24674]: time="2025-03-04T10:49:58+06:00" level=trace msg="received accesspoint pong ack" Mar 04 10:49:59 volumio go-librespot[24674]: time="2025-03-04T10:49:59+06:00" level=trace msg="sent dealer ping" Mar 04 10:49:59 volumio volumio[1015]: 0+0 records in Mar 04 10:49:59 volumio volumio[1015]: 0+0 records out Mar 04 10:49:59 volumio volumio[1015]: 0 bytes copied, 0.000140152 s, 0.0 kB/s Mar 04 10:49:59 volumio volumio[1015]: info: camilladsp spawned new process with pid 5171, instance 1, run: true Mar 04 10:49:59 volumio go-librespot[24674]: time="2025-03-04T10:49:59+06:00" level=trace msg="received dealer pong" Mar 04 10:50:00 volumio volumio[1015]: 0+0 records in Mar 04 10:50:00 volumio volumio[1015]: 0+0 records out Mar 04 10:50:00 volumio volumio[1015]: 0 bytes copied, 0.000122808 s, 0.0 kB/s Mar 04 10:50:00 volumio volumio[1015]: info: camilladsp spawned new process with pid 5176, instance 1, run: true Mar 04 10:50:01 volumio volumio[1015]: 0+0 records in Mar 04 10:50:01 volumio volumio[1015]: 0+0 records out Mar 04 10:50:01 volumio volumio[1015]: 0 bytes copied, 0.000140828 s, 0.0 kB/s Mar 04 10:50:01 volumio volumio[1015]: info: camilladsp spawned new process with pid 5182, instance 1, run: true Mar 04 10:50:02 volumio volumio[1015]: 0+0 records in Mar 04 10:50:02 volumio volumio[1015]: 0+0 records out Mar 04 10:50:02 volumio volumio[1015]: 0 bytes copied, 0.000125152 s, 0.0 kB/s Mar 04 10:50:02 volumio volumio[1015]: info: camilladsp spawned new process with pid 5187, instance 1, run: true Mar 04 10:50:03 volumio volumio[1015]: 0+0 records in Mar 04 10:50:03 volumio volumio[1015]: 0+0 records out Mar 04 10:50:03 volumio volumio[1015]: 0 bytes copied, 0.000141089 s, 0.0 kB/s Mar 04 10:50:03 volumio volumio[1015]: info: camilladsp spawned new process with pid 5192, instance 1, run: true Mar 04 10:50:04 volumio volumio[1015]: 0+0 records in Mar 04 10:50:04 volumio volumio[1015]: 0+0 records out Mar 04 10:50:04 volumio volumio[1015]: 0 bytes copied, 0.000124943 s, 0.0 kB/s Mar 04 10:50:04 volumio volumio[1015]: info: camilladsp spawned new process with pid 5197, instance 1, run: true Mar 04 10:50:06 volumio volumio[1015]: 0+0 records in Mar 04 10:50:06 volumio volumio[1015]: 0+0 records out Mar 04 10:50:06 volumio volumio[1015]: 0 bytes copied, 0.000142755 s, 0.0 kB/s Mar 04 10:50:06 volumio volumio[1015]: info: camilladsp spawned new process with pid 5219, instance 1, run: true Mar 04 10:50:07 volumio volumio[1015]: 0+0 records in Mar 04 10:50:07 volumio volumio[1015]: 0+0 records out Mar 04 10:50:07 volumio volumio[1015]: 0 bytes copied, 0.000125308 s, 0.0 kB/s Mar 04 10:50:07 volumio volumio[1015]: info: camilladsp spawned new process with pid 5224, instance 1, run: true Mar 04 10:50:07 volumio volumio[1015]: info: VolumeController::SetAlsaVolume55 Mar 04 10:50:07 volumio volumio[1015]: info: CoreStateMachine::pushState Mar 04 10:50:07 volumio volumio[1015]: info: CorePlayQueue::getTrack 5 Mar 04 10:50:07 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 04 10:50:07 volumio volumio[1015]: info: CoreCommandRouter::volumioPushState Mar 04 10:50:07 volumio volumio[1015]: info: MRS: Pushing multiroomSync output update for this device Mar 04 10:50:07 volumio volumio[1015]: info: MRS: Pushing multiroomSync output Mar 04 10:50:07 volumio volumio[1015]: info: [ASDebug] CurState: stop PrevState: stop Mar 04 10:50:07 volumio volumio[1015]: info: [GPIO_Control] Status changed: stop Mar 04 10:50:07 volumio volumio[1015]: SPOTIFY: RECEIVED VOLUMIO VOLUME 55 Mar 04 10:50:07 volumio volumio[1015]: SPOTIFY: SPOTIFY VOLUME 54 Mar 04 10:50:07 volumio volumio[1015]: SPOTIFY: VOLUMIO VOLUME 55 Mar 04 10:50:07 volumio volumio[1015]: SPOTIFY: DELTA VOLUME ENOUGH: false Mar 04 10:50:07 volumio volumio[1015]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: Invalid card number. Mar 04 10:50:08 volumio volumio[1015]: info: VolumeController::SetAlsaVolume60 Mar 04 10:50:08 volumio volumio[1015]: info: CoreStateMachine::pushState Mar 04 10:50:08 volumio volumio[1015]: info: CorePlayQueue::getTrack 5 Mar 04 10:50:08 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 04 10:50:08 volumio volumio[1015]: info: CoreCommandRouter::volumioPushState Mar 04 10:50:08 volumio volumio[1015]: info: MRS: Pushing multiroomSync output update for this device Mar 04 10:50:08 volumio volumio[1015]: info: MRS: Pushing multiroomSync output Mar 04 10:50:08 volumio volumio[1015]: 0+0 records in Mar 04 10:50:08 volumio volumio[1015]: 0+0 records out Mar 04 10:50:08 volumio volumio[1015]: 0 bytes copied, 0.000141975 s, 0.0 kB/s Mar 04 10:50:08 volumio volumio[1015]: info: camilladsp spawned new process with pid 5231, instance 1, run: true Mar 04 10:50:08 volumio volumio[1015]: info: [ASDebug] CurState: stop PrevState: stop Mar 04 10:50:08 volumio volumio[1015]: info: [GPIO_Control] Status changed: stop Mar 04 10:50:08 volumio volumio[1015]: SPOTIFY: RECEIVED VOLUMIO VOLUME 60 Mar 04 10:50:08 volumio volumio[1015]: SPOTIFY: SPOTIFY VOLUME 54 Mar 04 10:50:08 volumio volumio[1015]: SPOTIFY: VOLUMIO VOLUME 60 Mar 04 10:50:08 volumio volumio[1015]: SPOTIFY: DELTA VOLUME ENOUGH: true Mar 04 10:50:08 volumio volumio[1015]: info: Setting Spotify Volume from Volumio: 60 Mar 04 10:50:08 volumio volumio[1015]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: Invalid card number. Mar 04 10:50:08 volumio volumio[1015]: info: VolumeController::SetAlsaVolume70 Mar 04 10:50:08 volumio volumio[1015]: info: CoreStateMachine::pushState Mar 04 10:50:08 volumio volumio[1015]: info: CorePlayQueue::getTrack 5 Mar 04 10:50:08 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 04 10:50:08 volumio volumio[1015]: info: CoreCommandRouter::volumioPushState Mar 04 10:50:08 volumio volumio[1015]: info: MRS: Pushing multiroomSync output update for this device Mar 04 10:50:08 volumio volumio[1015]: info: MRS: Pushing multiroomSync output Mar 04 10:50:08 volumio volumio[1015]: info: [ASDebug] CurState: stop PrevState: stop Mar 04 10:50:08 volumio volumio[1015]: info: [GPIO_Control] Status changed: stop Mar 04 10:50:08 volumio volumio[1015]: SPOTIFY: RECEIVED VOLUMIO VOLUME 70 Mar 04 10:50:08 volumio volumio[1015]: SPOTIFY: SPOTIFY VOLUME 60 Mar 04 10:50:08 volumio volumio[1015]: SPOTIFY: VOLUMIO VOLUME 70 Mar 04 10:50:08 volumio volumio[1015]: SPOTIFY: DELTA VOLUME ENOUGH: true Mar 04 10:50:08 volumio volumio[1015]: info: Setting Spotify Volume from Volumio: 70 Mar 04 10:50:08 volumio volumio[1015]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: Invalid card number. Mar 04 10:50:08 volumio volumio[1015]: info: VolumeController::SetAlsaVolume75 Mar 04 10:50:08 volumio volumio[1015]: info: CoreStateMachine::pushState Mar 04 10:50:08 volumio volumio[1015]: info: CorePlayQueue::getTrack 5 Mar 04 10:50:08 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 04 10:50:08 volumio volumio[1015]: info: CoreCommandRouter::volumioPushState Mar 04 10:50:08 volumio volumio[1015]: info: MRS: Pushing multiroomSync output update for this device Mar 04 10:50:08 volumio volumio[1015]: info: MRS: Pushing multiroomSync output Mar 04 10:50:08 volumio volumio[1015]: info: [ASDebug] CurState: stop PrevState: stop Mar 04 10:50:08 volumio volumio[1015]: info: [GPIO_Control] Status changed: stop Mar 04 10:50:08 volumio volumio[1015]: SPOTIFY: RECEIVED VOLUMIO VOLUME 75 Mar 04 10:50:08 volumio volumio[1015]: SPOTIFY: SPOTIFY VOLUME 70 Mar 04 10:50:08 volumio volumio[1015]: SPOTIFY: VOLUMIO VOLUME 75 Mar 04 10:50:08 volumio volumio[1015]: SPOTIFY: DELTA VOLUME ENOUGH: true Mar 04 10:50:08 volumio volumio[1015]: info: Setting Spotify Volume from Volumio: 75 Mar 04 10:50:08 volumio volumio[1015]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: Invalid card number. Mar 04 10:50:09 volumio volumio[1015]: info: VolumeController::SetAlsaVolume80 Mar 04 10:50:09 volumio volumio[1015]: info: CoreStateMachine::pushState Mar 04 10:50:09 volumio volumio[1015]: info: CorePlayQueue::getTrack 5 Mar 04 10:50:09 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 04 10:50:09 volumio volumio[1015]: info: CoreCommandRouter::volumioPushState Mar 04 10:50:09 volumio volumio[1015]: info: MRS: Pushing multiroomSync output update for this device Mar 04 10:50:09 volumio volumio[1015]: info: MRS: Pushing multiroomSync output Mar 04 10:50:09 volumio volumio[1015]: 0+0 records in Mar 04 10:50:09 volumio volumio[1015]: 0+0 records out Mar 04 10:50:09 volumio volumio[1015]: 0 bytes copied, 0.000123381 s, 0.0 kB/s Mar 04 10:50:09 volumio volumio[1015]: info: camilladsp spawned new process with pid 5239, instance 1, run: true Mar 04 10:50:09 volumio volumio[1015]: info: [ASDebug] CurState: stop PrevState: stop Mar 04 10:50:09 volumio volumio[1015]: info: [GPIO_Control] Status changed: stop Mar 04 10:50:09 volumio volumio[1015]: SPOTIFY: RECEIVED VOLUMIO VOLUME 80 Mar 04 10:50:09 volumio volumio[1015]: SPOTIFY: SPOTIFY VOLUME 75 Mar 04 10:50:09 volumio volumio[1015]: SPOTIFY: VOLUMIO VOLUME 80 Mar 04 10:50:09 volumio volumio[1015]: SPOTIFY: DELTA VOLUME ENOUGH: true Mar 04 10:50:09 volumio volumio[1015]: info: Setting Spotify Volume from Volumio: 80 Mar 04 10:50:09 volumio volumio[1015]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: Invalid card number. Mar 04 10:50:09 volumio volumio[1015]: info: VolumeController::SetAlsaVolume95 Mar 04 10:50:09 volumio volumio[1015]: info: CoreStateMachine::pushState Mar 04 10:50:09 volumio volumio[1015]: info: CorePlayQueue::getTrack 5 Mar 04 10:50:09 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo Mar 04 10:50:09 volumio volumio[1015]: info: CoreCommandRouter::volumioPushState Mar 04 10:50:09 volumio volumio[1015]: info: MRS: Pushing multiroomSync output update for this device Mar 04 10:50:09 volumio volumio[1015]: info: MRS: Pushing multiroomSync output Mar 04 10:50:09 volumio volumio[1015]: info: [ASDebug] CurState: stop PrevState: stop Mar 04 10:50:09 volumio volumio[1015]: info: [GPIO_Control] Status changed: stop Mar 04 10:50:09 volumio volumio[1015]: SPOTIFY: RECEIVED VOLUMIO VOLUME 95 Mar 04 10:50:09 volumio volumio[1015]: SPOTIFY: SPOTIFY VOLUME 80 Mar 04 10:50:09 volumio volumio[1015]: SPOTIFY: VOLUMIO VOLUME 95 Mar 04 10:50:09 volumio volumio[1015]: SPOTIFY: DELTA VOLUME ENOUGH: true Mar 04 10:50:09 volumio volumio[1015]: info: Setting Spotify Volume from Volumio: 95 Mar 04 10:50:09 volumio volumio[1015]: error: Cannot set ALSA Volume: Error: Alsa Mixer Error: Invalid card number. Mar 04 10:50:10 volumio volumio[1015]: 0+0 records in Mar 04 10:50:10 volumio volumio[1015]: 0+0 records out Mar 04 10:50:10 volumio volumio[1015]: 0 bytes copied, 0.000141036 s, 0.0 kB/s Mar 04 10:50:10 volumio volumio[1015]: info: camilladsp spawned new process with pid 5245, instance 1, run: true Mar 04 10:50:10 volumio volumio[1015]: SPOTIFY: SETTING SPOTIFY VOLUME 95 Mar 04 10:50:10 volumio volumio[1015]: info: Sending Spotify command with payload to local API: /player/volume Mar 04 10:50:10 volumio go-librespot[24674]: time="2025-03-04T10:50:10+06:00" level=debug msg="update volume to 62258/65535" Mar 04 10:50:11 volumio volumio[1015]: 0+0 records in Mar 04 10:50:11 volumio volumio[1015]: 0+0 records out Mar 04 10:50:11 volumio volumio[1015]: 0 bytes copied, 0.000124371 s, 0.0 kB/s Mar 04 10:50:11 volumio volumio[1015]: info: camilladsp spawned new process with pid 5250, instance 1, run: true Mar 04 10:50:12 volumio go-librespot[24674]: time="2025-03-04T10:50:12+06:00" level=debug msg="put connect state because VOLUME_CHANGED" Mar 04 10:50:12 volumio go-librespot[24674]: time="2025-03-04T10:50:12+06:00" level=trace msg="emitting websocket event: volume" Mar 04 10:50:12 volumio volumio[1015]: SPOTIFY: received: {"type":"volume","data":{"value":95,"max":100}} Mar 04 10:50:12 volumio volumio[1015]: SPOTIFY: RECEIVED SPOTIFY VOLUME 95 Mar 04 10:50:12 volumio volumio[1015]: SPOTIFY: received: {"type":"volume","data":{"value":95,"max":100}} Mar 04 10:50:12 volumio volumio[1015]: SPOTIFY: RECEIVED SPOTIFY VOLUME 95 Mar 04 10:50:12 volumio volumio[1015]: 0+0 records in Mar 04 10:50:12 volumio volumio[1015]: 0+0 records out Mar 04 10:50:12 volumio volumio[1015]: 0 bytes copied, 0.000137651 s, 0.0 kB/s Mar 04 10:50:12 volumio volumio[1015]: info: camilladsp spawned new process with pid 5255, instance 1, run: true Mar 04 10:50:13 volumio volumio[1015]: 0+0 records in Mar 04 10:50:13 volumio volumio[1015]: 0+0 records out Mar 04 10:50:13 volumio volumio[1015]: 0 bytes copied, 0.000123121 s, 0.0 kB/s Mar 04 10:50:13 volumio volumio[1015]: info: camilladsp spawned new process with pid 5260, instance 1, run: true Mar 04 10:50:13 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: multiroom , setAudioOutputVolume Mar 04 10:50:13 volumio volumio[1015]: error: MRS: impossible to set browserPlayback volume: device not found Mar 04 10:50:13 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: multiroom , setAudioOutputVolume Mar 04 10:50:13 volumio volumio[1015]: error: MRS: impossible to set browserPlayback volume: device not found Mar 04 10:50:13 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: multiroom , setAudioOutputVolume Mar 04 10:50:13 volumio volumio[1015]: error: MRS: impossible to set browserPlayback volume: device not found Mar 04 10:50:13 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: multiroom , setAudioOutputVolume Mar 04 10:50:13 volumio volumio[1015]: error: MRS: impossible to set browserPlayback volume: device not found Mar 04 10:50:13 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: multiroom , setAudioOutputVolume Mar 04 10:50:13 volumio volumio[1015]: error: MRS: impossible to set browserPlayback volume: device not found Mar 04 10:50:13 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: multiroom , setAudioOutputVolume Mar 04 10:50:13 volumio volumio[1015]: error: MRS: impossible to set browserPlayback volume: device not found Mar 04 10:50:13 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: multiroom , setAudioOutputVolume Mar 04 10:50:13 volumio volumio[1015]: error: MRS: impossible to set browserPlayback volume: device not found Mar 04 10:50:13 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: multiroom , setAudioOutputVolume Mar 04 10:50:13 volumio volumio[1015]: error: MRS: impossible to set browserPlayback volume: device not found Mar 04 10:50:13 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: multiroom , setAudioOutputVolume Mar 04 10:50:13 volumio volumio[1015]: error: MRS: impossible to set browserPlayback volume: device not found Mar 04 10:50:13 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: multiroom , setAudioOutputVolume Mar 04 10:50:13 volumio volumio[1015]: error: MRS: impossible to set browserPlayback volume: device not found Mar 04 10:50:13 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: multiroom , setAudioOutputVolume Mar 04 10:50:13 volumio volumio[1015]: error: MRS: impossible to set browserPlayback volume: device not found Mar 04 10:50:13 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: multiroom , setAudioOutputVolume Mar 04 10:50:13 volumio volumio[1015]: error: MRS: impossible to set browserPlayback volume: device not found Mar 04 10:50:13 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: multiroom , setAudioOutputVolume Mar 04 10:50:13 volumio volumio[1015]: error: MRS: impossible to set browserPlayback volume: device not found Mar 04 10:50:14 volumio volumio[1015]: 0+0 records in Mar 04 10:50:14 volumio volumio[1015]: 0+0 records out Mar 04 10:50:14 volumio volumio[1015]: 0 bytes copied, 0.000124527 s, 0.0 kB/s Mar 04 10:50:14 volumio volumio[1015]: info: camilladsp spawned new process with pid 5265, instance 1, run: true Mar 04 10:50:15 volumio volumio[1015]: 0+0 records in Mar 04 10:50:15 volumio volumio[1015]: 0+0 records out Mar 04 10:50:15 volumio volumio[1015]: 0 bytes copied, 0.000142131 s, 0.0 kB/s Mar 04 10:50:15 volumio volumio[1015]: info: camilladsp spawned new process with pid 5273, instance 1, run: true Mar 04 10:50:16 volumio volumio[1015]: 0+0 records in Mar 04 10:50:16 volumio volumio[1015]: 0+0 records out Mar 04 10:50:16 volumio volumio[1015]: 0 bytes copied, 0.000121923 s, 0.0 kB/s Mar 04 10:50:16 volumio volumio[1015]: info: camilladsp spawned new process with pid 5292, instance 1, run: true Mar 04 10:50:17 volumio volumio[1015]: 0+0 records in Mar 04 10:50:17 volumio volumio[1015]: 0+0 records out Mar 04 10:50:17 volumio volumio[1015]: 0 bytes copied, 0.000124631 s, 0.0 kB/s Mar 04 10:50:17 volumio volumio[1015]: info: camilladsp spawned new process with pid 5298, instance 1, run: true Mar 04 10:50:18 volumio volumio[1015]: 0+0 records in Mar 04 10:50:18 volumio volumio[1015]: 0+0 records out Mar 04 10:50:18 volumio volumio[1015]: 0 bytes copied, 0.000123537 s, 0.0 kB/s Mar 04 10:50:18 volumio volumio[1015]: info: camilladsp spawned new process with pid 5303, instance 1, run: true Mar 04 10:50:19 volumio volumio[1015]: info: CoreCommandRouter::executeOnPlugin: multiroom , audioOutputPlay Mar 04 10:50:19 volumio volumio[1015]: info: Error : CoreCommandRouter::executeOnPlugin: No method [audioOutputPlay] in plugin multiroom Mar 04 10:50:19 volumio volumio[1015]: |||||||||||||||||||||||| WARNING: FATAL ERROR ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 04 10:50:19 volumio volumio[1015]: TypeError: Cannot read property 'then' of undefined Mar 04 10:50:19 volumio volumio[1015]: at outputs.audioOutputPlay (/volumio/app/plugins/audio_interface/outputs/index.js:367:9) Mar 04 10:50:19 volumio volumio[1015]: at CoreCommandRouter.audioOutputPlay (/volumio/app/index.js:2273:30) Mar 04 10:50:19 volumio volumio[1015]: at Socket. (/volumio/app/plugins/user_interface/websocket/index.js:1450:26) Mar 04 10:50:19 volumio volumio[1015]: at Socket.emit (events.js:315:20) Mar 04 10:50:19 volumio volumio[1015]: at /volumio/node_modules/socket.io/lib/socket.js:528:12 Mar 04 10:50:19 volumio volumio[1015]: at processTicksAndRejections (internal/process/task_queues.js:75:11) Mar 04 10:50:19 volumio volumio[1015]: ||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||||| Mar 04 10:50:20 volumio sudo[5315]: volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/journalctl --since=2025-03-04 10:49 Mar 04 10:50:20 volumio sudo[5315]: 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"