Could you share some logs?
Either from the /dev page using the livelog feature or via ssh.
# Volumio logs
journalctl -f -o cat
# vollibrespot logs
journalctl -f -o cat -u volspotconnect2.service
Note you might need sudo before these commands depending on the version of Volumio your running
Here the entire sequence:
1 - stop web radio
2 - start Spotify, Play
3 - does not work
4 - Close Spotify
5 - disable and re-enable the VolSpot plugin
6 - Start Spotify
7 - It works normally
Starting Live Log...
wlan0: CTRL-EVENT-DISCONNECTED bssid=3c:b7:4b:3a:4d:50 reason=7 locally_generated=1
wlan0: CTRL-EVENT-REGDOM-CHANGE init=CORE type=WORLD
wlan0: Trying to associate with SSID 'Mapear 2.4 GHz'
wlan0: Associated with 3c:b7:4b:3a:4d:50
wlan0: WPA: Key negotiation completed with 3c:b7:4b:3a:4d:50 [PTK=CCMP GTK=TKIP]
wlan0: CTRL-EVENT-CONNECTED - Connection to 3c:b7:4b:3a:4d:50 completed [id=0 id_str=]
wlan0: CTRL-EVENT-REGDOM-CHANGE init=COUNTRY_IE type=COUNTRY alpha2=AR
info: CALLMETHOD: system_controller system enableLiveLog true
info: CoreCommandRouter::executeOnPlugin: system , enableLiveLog
info: Launching a new LiveLog session
info: CoreCommandRouter::volumioGetState
info: CorePlayQueue::getTrack 0
info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom
info: Listing playlists
info: CoreCommandRouter::volumioGetQueue
info: CoreStateMachine::getQueue
info: CorePlayQueue::getQueue
info: CoreCommandRouter::volumioGetVisibleSources
info: CoreCommandRouter::executeOnPlugin: my_music , getDisabledSources
info: CoreCommandRouter::volumioPause
info: CoreStateMachine::pause
info: CoreStateMachine::stPlaybackTimer
info: CoreStateMachine::servicePause
info: CorePlayQueue::getTrack 0
info: CoreCommandRouter::servicePause
info:
---------------------------- MPD announces state update: player
info: ControllerMpd::getState
info: CorePlayQueue::getTrack 0
info: CoreCommandRouter::servicePushState
info: CorePlayQueue::getTrack 0
info: CoreStateMachine::syncState stateService pause
info: CoreStateMachine::syncState currentStatus pause
info: CoreStateMachine::pushState
info: CorePlayQueue::getTrack 0
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
info: CoreStateMachine::stPlaybackTimer
info:
---------------------------- MPD announces state update: player
info: ControllerMpd::getState
info: ControllerMpd::pushState
info: CoreCommandRouter::servicePushState
info: CorePlayQueue::getTrack 0
info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd
info: ControllerMpd::pushState
info: CoreCommandRouter::servicePushState
info: CorePlayQueue::getTrack 0
info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd
info: ------------------------------ 42ms
info: ------------------------------ 21ms
[Vollibrespot] : Connecting to AP "guc3-accesspoint-b-wdpz.ap.spotify.com:443"
[Vollibrespot] : Authenticated as "danielfelix" !
[Vollibrespot] : Setting up new mixer: card:hw:2 mixer:Digital index:0
[Vollibrespot] : Alsa Mixer info min: 0 (MilliBel(-9999999)[dB]) -- max: 207 (MilliBel(0)[dB]) HW: true
[Vollibrespot] : Using alsa sink
[Vollibrespot] : Metadata pipe established
[Vollibrespot] : Event: Volume { volume_to_mixer: 13107 }
[Vollibrespot] : Country: "AR"
[SpotifyConnect] 20
[SpotifyConnect] Volume: Spotify:20 Volumio: 20
info: CoreStateMachine::pushState
info: CorePlayQueue::getTrack 0
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
[Vollibrespot] : Fetching autoplay context uri
[Vollibrespot] : Event: SessionActive { became_active_at: 1596579087456 }
[Vollibrespot] : SessionActive!
[Vollibrespot] : Event: PlaybackStarted { track_id: SpotifyId { id: 181526245921843748686528109162483859992, audio_type: Track } }
[Vollibrespot] : Event: PlaybackLoading { track_id: SpotifyId { id: 181526245921843748686528109162483859992, audio_type: Track } }
[SpotifyConnect] A connect session has begun
[SpotifyConnect] Device palyback is active!
info: CoreCommandRouter::volumioGetState
info: CorePlayQueue::getTrack 0
[SpotifyConnect] Currently active: radio_paradise
[SpotifyConnect] Stopping currently active service
info: CoreCommandRouter::volumioStop
info: CoreStateMachine::stop
info: CoreStateMachine::setConsumeUpdateService undefined
UNSET VOLATILE
info: CoreStateMachine::updateTrackBlock
info: CorePlayQueue::getTrackBlock
info: CoreStateMachine::stPlaybackTimer
info: CoreStateMachine::pushState
info: CorePlayQueue::getTrack 0
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
info: CoreStateMachine::serviceStop
info: CorePlayQueue::getTrack 0
info: CoreCommandRouter::serviceStop
info: ControllerMpd::stop
info:
---------------------------- MPD announces state update: player
info: ControllerMpd::getState
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CorePlayQueue::getTrack 0
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
info: CorePlayQueue::getTrack 0
info: CoreStateMachine::syncState stateService stop
info: CoreStateMachine::syncState currentStatus stop
info: CoreStateMachine::pushState
info: CorePlayQueue::getTrack 0
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
info: No code
info: CoreStateMachine::pushState
info: CorePlayQueue::getTrack 0
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
[SpotifyConnect] Vollibrespot Active
info: CoreCommandRouter::volumioGetState
info: CorePlayQueue::getTrack 0
[SpotifyConnect] Currently active: radio_paradise
[SpotifyConnect] Setting Volatile state to Volspotconnect2
info: CoreStateMachine::setConsumeUpdateService undefined
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
info: CorePlayQueue::getTrack 0
info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received volspotconnect2
info: CoreCommandRouter::volumioGetState
[SpotifyConnect] Currently active: undefined
[SpotifyConnect] Pushing new state :: true
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
info: CorePlayQueue::getTrack 0
info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received volspotconnect2
info:
---------------------------- MPD announces state update: player
info: ControllerMpd::getState
info: ControllerMpd::pushState
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
info: CorePlayQueue::getTrack 0
info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd
info: ------------------------------ 81ms
info: ControllerMpd::pushState
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
info: CorePlayQueue::getTrack 0
info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd
info: ------------------------------ 45ms
[Vollibrespot] : No autoplay_uri found
[Vollibrespot] : AutoplayError: MercuryError
[Vollibrespot] : Event: GotToken { token: Token { access_token: "BQCPebyLQxpHQ6SibGmaNKDiwBDTmCdsIi6V19xUOtaas1KZ-9j7ww8TSReKmsqPf5K8Mlc6UFJytaLBQX5hCy0fW3nPkhExOQvqxm1WYNRNA0cyIuhNzvGNS-bGkXfcLXwRcavd0cJthT-fIq78Tr_Ke1Xnp0wranDm-QM", expires_in: 3600, token_type: "Bearer", scope: ["streaming", "user-read-playback-state", "user-modify-playback-state", "user-read-currently-playing", "user-read-private"] } }
[SpotifyConnect] BQCPebyLQxpHQ6SibGmaNKDiwBDTmCdsIi6V19xUOtaas1KZ-9j7ww8TSReKmsqPf5K8Mlc6UFJytaLBQX5hCy0fW3nPkhExOQvqxm1WYNRNA0cyIuhNzvGNS-bGkXfcLXwRcavd0cJthT-fIq78Tr_Ke1Xnp0wranDm-QM
[Vollibrespot] : Loading with Spotify URI
[SpotifyConnect] Setting VLS device_id: c6e56cf6b68c07041768b06e2f29a439e7724b0e
[Vollibrespot] : (409640 ms) loaded
[Vollibrespot] : Event: PlaybackStopped { track_id: SpotifyId { id: 181526245921843748686528109162483859992, audio_type: Track } }
[SpotifyConnect] Device palyback is inactive
[SpotifyConnect] Device Session is_active: true
[Vollibrespot] : Fetching autoplay context uri
[Vollibrespot] : Event: TrackChanged { old_track_id: SpotifyId { id: 181526245921843748686528109162483859992, audio_type: Track }, track_id: SpotifyId { id: 145388607699475846999067032348438672553, audio_type: Track } }
[Vollibrespot] : No autoplay_uri found
[Vollibrespot] : AutoplayError: MercuryError
[Vollibrespot] : Loading with Spotify URI
[Vollibrespot] : (206800 ms) loaded
[Vollibrespot] : Alsa error PCM open ALSA function 'snd_pcm_open' failed with error 'EBUSY: Device or resource busy'
[Vollibrespot] : Could not start audio: Alsa error: PCM open failed
[Vollibrespot] : Alsa error PCM open ALSA function 'snd_pcm_open' failed with error 'EBUSY: Device or resource busy'
[Vollibrespot] : Could not start audio: Alsa error: PCM open failed
[Vollibrespot] : Alsa error PCM open ALSA function 'snd_pcm_open' failed with error 'EBUSY: Device or resource busy'
[Vollibrespot] : Could not start audio: Alsa error: PCM open failed
thread '' panicked at 'called `Option::unwrap()` on a `None` value', /build/cache/git/checkouts/librespot-6f197fd632ef9380/659de68/playback/src/audio_backend/alsa.rs:128:19
stack backtrace:
0: 0xad1828 - backtrace::backtrace::libunwind::trace::h100c6c70e4af496c
at /cargo/registry/src/github.com-1ecc6299db9ec823/backtrace-0.3.40/src/backtrace/libunwind.rs:88
1: 0xad1828 - backtrace::backtrace::trace_unsynchronized::hf78ddc194bf45009
at /cargo/registry/src/github.com-1ecc6299db9ec823/backtrace-0.3.40/src/backtrace/mod.rs:66
2: 0xad1828 - std::sys_common::backtrace::_print_fmt::h967a212a8894e4a4
at src/libstd/sys_common/backtrace.rs:77
3: 0xad1828 - ::fmt::h5fe383ce2118859a
at src/libstd/sys_common/backtrace.rs:59
4: 0xaed03c - core::fmt::write::h937f59172f6eeeaf
at src/libcore/fmt/mod.rs:1052
5: 0xacb6ec - std::io::Write::write_fmt::hc70e2634948b89c8
at src/libstd/io/mod.rs:1426
6: 0xad3cf0 - std::sys_common::backtrace::_print::hbfc81757b29a60f4
at src/libstd/sys_common/backtrace.rs:62
7: 0xad3cf0 - std::sys_common::backtrace::print::h8bc349c117633211
at src/libstd/sys_common/backtrace.rs:49
8: 0xad3cf0 - std::panicking::default_hook::{{closure}}::h82c47dcbb8503118
at src/libstd/panicking.rs:204
9: 0xad3964 - std::panicking::default_hook::hc04800be16711189
at src/libstd/panicking.rs:224
10: 0xad43a0 - std::panicking::rust_panic_with_hook::h2413ff75e44cd581
at src/libstd/panicking.rs:472
11: 0xad3fb4 - rust_begin_unwind
at src/libstd/panicking.rs:380
12: 0xaeaaa8 - core::panicking::panic_fmt::h2c56481ca2ee7c2f
at src/libcore/panicking.rs:85
13: 0xaeaa04 - core::panicking::panic::h858859fb9e6c3f07
at src/libcore/panicking.rs:52
14: 0x69bf40 - ::write::h72619216e3588ead
15: 0x676e38 - ::poll::h8c3aa347eb5050fe
16: 0x578b0c - futures::task_impl::std::set::h959dffae037fa8a9
17: 0x573048 - futures::task_impl::Spawn::poll_future_notify::h3ba01a9dfc1d022c
18: 0x57f6d4 - std::sys_common::backtrace::__rust_begin_short_backtrace::h53457226459490b1
19: 0x590e08 - std::panicking::try::do_call::h3a2683b9b75c33db
20: 0xad85f8 - __rust_maybe_catch_panic
at src/libpanic_unwind/lib.rs:86
21: 0x591140 - core::ops::function::FnOnce::call_once{{vtable.shim}}::he4fab1c16e3e7b3d
22: 0xac4488 - as core::ops::function::FnOnce>::call_once::h0eb934bdc214e7b7
at /rustc/b8cedc00407a4c56a3bda1ed605c6fc166655447/src/liballoc/boxed.rs:1015
23: 0xad78f8 - as core::ops::function::FnOnce>::call_once::h4eeee9ec160fd74c
at /rustc/b8cedc00407a4c56a3bda1ed605c6fc166655447/src/liballoc/boxed.rs:1015
24: 0xad78f8 - std::sys_common::thread::start_thread::hd648575d6de17db0
at src/libstd/sys_common/thread.rs:13
25: 0xad78f8 - std::sys::unix::thread::Thread::new::thread_start::hc1903f20153f9439
at src/libstd/sys/unix/thread.rs:80
[Vollibrespot] : Event: PlaybackLoading { track_id: SpotifyId { id: 145388607699475846999067032348438672553, audio_type: Track } }
[SpotifyConnect] Apenas Floto
[SpotifyConnect] Pushing metadata
info: CoreCommandRouter::volumioGetState
[SpotifyConnect] Currently active: undefined
[SpotifyConnect] Pushing new state :: true
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
info: CorePlayQueue::getTrack 0
info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received volspotconnect2
info: CoreCommandRouter::executeOnPlugin: my_volumio , detectVolumioHardware
info: Could not detect Volumio Device: Error: Command failed: aplay -l | grep es90x8q2m-dac-dai-0
[SpotifyConnect] Relinquishing Volumio State
UNSET VOLATILE
[SpotifyConnect] unSetVolatile called
[SpotifyConnect] Relinquishing Volumio State to another service
[SpotifyConnect] Received stop
[SpotifyConnect] Stopping Vollibrespot daemon
[SpotifyConnect] Closing metadata listener
info: CoreStateMachine::resetVolumioState
info: CoreStateMachine::getcurrentVolume
info: CoreCommandRouter::volumioRetrievevolume
volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl stop volspotconnect2.service
pam_unix(sudo:session): session opened for user root by (uid=0)
info: Disabling plugin volspotconnect2
info: Done.
Stopping Volspotconnect2 Daemon...
Stopped Volspotconnect2 Daemon.
pam_unix(sudo:session): session closed for user root
[SpotifyConnect] Vollibrespot Daemon service stoped!
info: VolumeController:: Volume=20 Mute =false
info: CoreStateMachine::pushState
info: CorePlayQueue::getTrack 0
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
info: CoreStateMachine::updateTrackBlock
info: CorePlayQueue::getTrackBlock
info: CoreCommandRouter::volumioRetrievevolume
info: VolumeController:: Volume=20 Mute =false
info: CoreStateMachine::pushState
info: CorePlayQueue::getTrack 0
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
info: Enabling plugin volspotconnect2
info: Loading plugin "volspotconnect2"...
info: PLUGIN START: volspotconnect2
[SpotifyConnect] Creating VLS config file
info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
info: CoreCommandRouter::executeOnPlugin: alsa_controller , getConfigParam
[SpotifyConnect] Starting metadata listener
volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/systemctl start volspotconnect2.service
pam_unix(sudo:session): session opened for user root by (uid=0)
Starting Volspotconnect2 Daemon...
Started Volspotconnect2 Daemon.
pam_unix(sudo:session): session closed for user root
vollibrespot v0.2.1 1438440 2020-05-15 (librespot 659de68 2020-05-10) -- Built On 2020-05-15
Reading Config from "volspotify.toml"
[Vollibrespot] : Using Alsa backend with device: plughw:Loopback
[SpotifyConnect] Vollibrespot Daemon service started!
e[34m [Metrics] e[39m SpotifyConnect: e[31m 0s 103.86ms e[39m
info: Done.
[Vollibrespot] : Failed to register IPv6 receiver: Os { code: 19, kind: Other, message: "No such device" }
[Vollibrespot] : Connecting to AP "guc3-accesspoint-b-qsg4.ap.spotify.com:443"
[Vollibrespot] : Authenticated as "danielfelix" !
[Vollibrespot] : Setting up new mixer: card:hw:2 mixer:Digital index:0
[Vollibrespot] : Alsa Mixer info min: 0 (MilliBel(-9999999)[dB]) -- max: 207 (MilliBel(0)[dB]) HW: true
[Vollibrespot] : Using alsa sink
[Vollibrespot] : Metadata pipe established
[Vollibrespot] : Country: "AR"
[Vollibrespot] : Event: Volume { volume_to_mixer: 13107 }
[SpotifyConnect] 20
[SpotifyConnect] Volume: Spotify:20 Volumio: 20
info: CoreStateMachine::pushState
info: CorePlayQueue::getTrack 0
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
[Vollibrespot] : Fetching autoplay context uri
[Vollibrespot] : Event: SessionActive { became_active_at: 1596579216043 }
[Vollibrespot] : SessionActive!
[Vollibrespot] : Event: PlaybackStarted { track_id: SpotifyId { id: 145388607699475846999067032348438672553, audio_type: Track } }
[Vollibrespot] : Event: PlaybackLoading { track_id: SpotifyId { id: 145388607699475846999067032348438672553, audio_type: Track } }
[SpotifyConnect] A connect session has begun
[SpotifyConnect] Device palyback is active!
info: CoreCommandRouter::volumioGetState
info: CorePlayQueue::getTrack 0
[SpotifyConnect] Currently active: radio_paradise
[SpotifyConnect] Stopping currently active service
info: CoreCommandRouter::volumioStop
info: CoreStateMachine::stop
info: CoreStateMachine::setConsumeUpdateService undefined
UNSET VOLATILE
[SpotifyConnect] Vollibrespot Active
info: CoreCommandRouter::volumioGetState
info: CorePlayQueue::getTrack 0
[SpotifyConnect] Currently active: radio_paradise
[SpotifyConnect] Setting Volatile state to Volspotconnect2
info: CoreStateMachine::setConsumeUpdateService undefined
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
info: CorePlayQueue::getTrack 0
info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received volspotconnect2
info: CoreCommandRouter::volumioGetState
[SpotifyConnect] Currently active: undefined
[SpotifyConnect] Pushing new state :: true
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
info: CorePlayQueue::getTrack 0
info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received volspotconnect2
[Vollibrespot] : No autoplay_uri found
[Vollibrespot] : AutoplayError: MercuryError
[Vollibrespot] : Event: GotToken { token: Token { access_token: "BQB0Apw4ZCdb8LaOXCHJrav_-Y_aSqDpTn552JY1kNq18_SsaIwe9hjxaDd3kLjPL1riJ6eGL_cym-p1hrXtdj-S-NA0QenKeu6gpzvaz-McmRrJG0hQoASJAPqo3T4fH0wYCxz9xwayhTCMSPL4VSgGtG1klVacVemxRCw", expires_in: 3600, token_type: "Bearer", scope: ["streaming", "user-read-playback-state", "user-modify-playback-state", "user-read-currently-playing", "user-read-private"] } }
[SpotifyConnect] BQB0Apw4ZCdb8LaOXCHJrav_-Y_aSqDpTn552JY1kNq18_SsaIwe9hjxaDd3kLjPL1riJ6eGL_cym-p1hrXtdj-S-NA0QenKeu6gpzvaz-McmRrJG0hQoASJAPqo3T4fH0wYCxz9xwayhTCMSPL4VSgGtG1klVacVemxRCw
[Vollibrespot] : Loading with Spotify URI
[SpotifyConnect] Setting VLS device_id: c6e56cf6b68c07041768b06e2f29a439e7724b0e
[Vollibrespot] : (206800 ms) loaded
[Vollibrespot] : Event: PlaybackStopped { track_id: SpotifyId { id: 145388607699475846999067032348438672553, audio_type: Track } }
[SpotifyConnect] Device palyback is inactive
[SpotifyConnect] Device Session is_active: true
[Vollibrespot] : Resolving uri "spotify:station:user:spotify:playlist:37i9dQZEVXcMU5Gn41qZ9Y"
[Vollibrespot] : Event: TrackChanged { old_track_id: SpotifyId { id: 145388607699475846999067032348438672553, audio_type: Track }, track_id: SpotifyId { id: 22747588139279626277758005283872091704, audio_type: Track } }
[Vollibrespot] : Loading with Spotify URI
[Vollibrespot] : Resolved 50 tracks from <"spotify:station:user:spotify:playlist:37i9dQZEVXcMU5Gn41qZ9Y">
[Vollibrespot] : (186466 ms) loaded
[SpotifyConnect] Mrs. Cold
[SpotifyConnect] Pushing metadata
info: CoreCommandRouter::volumioGetState
[SpotifyConnect] Currently active: undefined
[SpotifyConnect] Pushing new state :: true
[Vollibrespot] : Event: PlaybackLoading { track_id: SpotifyId { id: 22747588139279626277758005283872091704, audio_type: Track } }
[Vollibrespot] : Event: SinkActive
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
info: CorePlayQueue::getTrack 0
info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received volspotconnect2
[SpotifyConnect] Sink acquired
info: CoreCommandRouter::volumioGetState
[SpotifyConnect] Currently active: undefined
[SpotifyConnect] Pushing new state :: true
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
CIFS VFS: Server 192.168.0.18 has not responded in 180 seconds. Reconnecting...
Thanks for the log! 
Now it’s clear(er) what is happening - there seems to be some issues with the playback notification. When you stop radio_paradise - it does pasue, but there seems to be some conflict with a second state update from mpd
info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd
info: ControllerMpd::pushState
info: CoreCommandRouter::servicePushState
info: CorePlayQueue::getTrack 0
info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received mpd
So then, for some reason, when the plugin requests Volumio to stop the currently active service, it fails.
[SpotifyConnect] Currently active: radio_paradise
[SpotifyConnect] Stopping currently active service
info: CoreCommandRouter::volumioStop
info: CoreStateMachine::stop
info: CoreStateMachine::setConsumeUpdateService undefined
UNSET VOLATILE
info: CoreStateMachine::updateTrackBlock
info: CorePlayQueue::getTrackBlock
info: CoreStateMachine::stPlaybackTimer
info: CoreStateMachine::pushState
info: CorePlayQueue::getTrack 0
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
info: CoreStateMachine::serviceStop
info: CorePlayQueue::getTrack 0
info: CoreCommandRouter::serviceStop
info: ControllerMpd::stop
info:
---------------------------- MPD announces state update: player
info: ControllerMpd::getState
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CorePlayQueue::getTrack 0
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
info: CorePlayQueue::getTrack 0
info: CoreStateMachine::syncState stateService stop
info: CoreStateMachine::syncState currentStatus stop
info: CoreStateMachine::pushState
info: CorePlayQueue::getTrack 0
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
info: No code
info: CoreStateMachine::pushState
info: CorePlayQueue::getTrack 0
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
[SpotifyConnect] Vollibrespot Active
info: CoreCommandRouter::volumioGetState
info: CorePlayQueue::getTrack 0
[SpotifyConnect] Currently active: radio_paradise
[SpotifyConnect] Setting Volatile state to Volspotconnect2
info: CoreStateMachine::setConsumeUpdateService undefined
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
info: CorePlayQueue::getTrack 0
info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received volspotconnect2
info: CoreCommandRouter::volumioGetState
[SpotifyConnect] Currently active: undefined
[SpotifyConnect] Pushing new state :: true
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
info: CorePlayQueue::getTrack 0
info: Received update from a service different from the one supposed to be playing music. Skipping notification.Current radio_paradise Received volspotconnect2
This then means that the ALSA sink is still held by the previous service radio_paradise and when the VLS daemon starts playing, it can’t access the sink and crashes.
[Vollibrespot] : Alsa error PCM open ALSA function 'snd_pcm_open' failed with error 'EBUSY: Device or resource busy'
[Vollibrespot] : Could not start audio: Alsa error: PCM open failed
Does this happen only with the radio_paradise plugin?
Ok, now that we know that it fails when the RP Plugin is in use, I will see what happens in another situation and I will tell you about it.
Thanks for your time!
I’m testing … so far the simplest solution when Spotify can’t play is to make mpc stop from Putty. After that it works properly.
I also found that it not only fails with the RP Plugin.
Hi! I used google translate, sorry. I`m user beaglebone black and Volumio 2.779. Plugin Spotify 2.0.3 working, volumio spotify connect 2 1.0.5 not working. DNS 8.8.8.8 and 8.8.4.4. I do not understand Linux, please, help!
Downloading plugin at http://plugins.volumio.org/plugins/volumio/armhf/music_service/volspotconnect2/volspotconnect2.zip
END DOWNLOAD: http://plugins.volumio.org/plugins/volumio/armhf/music_service/volspotconnect2/volspotconnect2.zip
Creating install location
Unpacking plugin
Checking for duplicate plugin
Copying plugin to location
Installing necessary utilities
Launching a bash shell
Installing volspotconnect2 dependencies
Detected cpu architecture as armv7l
Plugin installation script failed!!
An error occurred while installing the plugin Error
Why don’t you install it simply from the UI plugin page?
Doesn’t get up.
Enable ssh, and follow the journal logs while trying to install the plugin. Please post the full log
Starting Live Log…
info: CoreCommandRouter::executeOnPlugin: multiroom , getMultiroom
error: Could not retrieve plugin audio_interface multiroom
info: Listing playlists
info: CoreCommandRouter::executeOnPlugin: appearance , getUiSettings
info: CoreCommandRouter::executeOnPlugin: wizard , getShowWizard
info: CoreCommandRouter::executeOnPlugin: system , getShowWizard
info: CoreCommandRouter::executeOnPlugin: system , getPrivacySettings
info: CALLMETHOD: system_controller system enableLiveLog true
info: CoreCommandRouter::executeOnPlugin: system , enableLiveLog
info: Launching a new LiveLog session
info: Downloading plugin at http://plugins.volumio.org/plugins/volumio/armhf/music_service/volspotconnect2/volspotconnect2.zip
info: END DOWNLOAD: http://plugins.volumio.org/plugins/volumio/armhf/music_service/volspotconnect2/volspotconnect2.zip
info: Folder /tmp/plugins removed
info: Checking if plugin already exists
info: Rename folder
info: Folder /tmp/downloaded_plugin.zip removed
info: Move to category
info: Checking if install.sh is present
info: Executing install.sh
volumio : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/sh /data/plugins/music_service/volspotconnect2/install.sh
pam_unix(sudo:session): session opened for user root by (uid=0)
info: Launching a bash shell
info: Installing volspotconnect2 dependencies
info: Detected cpu architecture as armv7l
pam_unix(sudo:session): session closed for user root
info: Plugin installation script failed!!
info: Install script return the error Error: Command failed: echo volumio | sudo -S sh /data/plugins/music_service/volspotconnect2/install.sh > /tmp/installog
[sudo] password for volumio:
info: An error occurred installing the plugin. Rolling back config
info: Plugin folders cleanup
info: Scanning into folder /volumio/app/plugins/
info: Scanning category audio_interface
info: Scanning category miscellanea
info: Scanning category music_service
info: Scanning category plugins.json
info: Scanning category system_controller
info: Scanning category user_interface
info: Scanning into folder /data/plugins/
info: Scanning category music_service
info: Plugin folders cleanup completed
info: Error: Error
info: Folder /tmp/plugins removed
info: Folder /tmp/downloaded_plugin.zip removed
info: Folder /data/temp removed
Plugin installs won’t work if you change your password… Reset it back it it should work!
Hi there,
I’ve installed the Spotify Connect2 v 1.0.5 plug in. When I open up Spotify, I see ‘Volumio’ as a device option, however, when I tap on Volumio it tries to connect, but then fails - reverting to the existing playback source.
I’m not too technical, can anyone help out with this?
Hi, podcast support does no longer work again.
Thanks for your work
I have this exact same issue, does anyone have a solution ?
Could you share some logs?
Either a link to a full debug log or a quick snippet from the /dev page using the livelog feature or via ssh.
# Volumio logs
journalctl -f
# vollibrespot logs
journalctl -f -o cat -u volspotconnect2.service
Note you might need sudo before these commands depending on the version of Volumio your running
Most issues come from improper mixer setup, so those details would help as well…
Is there any way I can manually set the spotify connect device name in the config?
Hi,
after upgrading to Volumio 3, Spotify Connect has stopped working properly. Spotify on my laptops/phones etc don’t find my Primo. Checking the settings, there appears to be no way to enter my account details. After some tinkering, I find that I can get it to work by entering my account details directly in volspotify.toml.
It works, but 1: The password is in plain text, and 2: changing any setting through the UI will remove the login credentials, and it stops working again.
Also, volume is very low, this also appears to only be fixable by editing volspotify.toml.
Have I missed anything? I’m perfectly competent of editing Linux config files, but that’s not how I want to use my Primo.
I have a Primo also (updated to v3) and Spotify Connect works without a problem.
For Spotify Connect you don’t need any login in Volumio, it is only if you use Spotify via the Volumio UI you need to login.
You have remembered to activate the plugin?