Volumio version: 3.179
Hardware: Lenovo ThinkCentre M93p
Audio: Analogue Out
After giving up getting WiFi to work on my Mac Mini, I installed Volumio on an old Lenovo PC I had in storage. WiFi is now working on the PC, but I can’t get Spotify Connect to work. I had the same issue on the Mac, but at one point it did work, I even saw the App registered on my Spotify accound.
Then I moved over to the Lenovo, removed the app from my Spotify account, and installed the plugin again. I can see Volumio as a “Play on device”-option in the Spotify app, but when I try to connect, it just blinks for a while before returning to the iPhone or iPad.
Here’s the log output using Mixer Type Software:
Starting Live Log...
volspotconnect2.service: Scheduled restart job, restart counter is at 1.
Stopped Volspotconnect2 Daemon.
Started Volspotconnect2 Daemon.
vollibrespot v0.2.3 769ce77 2021-06-04 (librespot 08d8bcc 2020-10-07) -- Built On 2021-06-04
Reading Config from "volspotify.toml"
[Vollibrespot] : Using Alsa backend with device: volumio
[Vollibrespot] : Failed to register IPv6 receiver: Os { code: 19, kind: Other, message: "No such device" }
info: CALLMETHOD: system_controller system enableLiveLog true
info: CoreCommandRouter::executeOnPlugin: system , enableLiveLog
info: Launching a new LiveLog session
[Vollibrespot] : Connecting to AP "ap-gew1.spotify.com:443"
[Vollibrespot] : Authenticated as "REDACTED" !
[Vollibrespot] : Setting up new mixer: card:hw:1,0 mixer:SoftMaster index:0
ALSA lib conf.c:4898:(parse_args) Unknown parameter 1
ALSA lib conf.c:5031:(snd_config_expand) Parse arguments error: No such file or directory
ALSA lib control.c:1375:(snd_ctl_open_noupdate) Invalid CTL hw:1,0
thread 'main' panicked at 'Error setting up mixer!: Error("snd_mixer_attach", Sys(ENOENT))', /build/cache/git/checkouts/librespot-6f197fd632ef9380/08d8bcc/playback/src/mixer/alsamixer.rs:184:39
stack backtrace:
0: 0x560b54968240 - std::backtrace_rs::backtrace::libunwind::trace::h63b7a90188ab5fb3
at /rustc/9bc8c42bb2f19e745a63f3445f1ac248fb015e53/library/std/src/../../backtrace/src/backtrace/libunwind.rs:90:5
1: 0x560b54968240 - std::backtrace_rs::backtrace::trace_unsynchronized::h80aefbf9b851eca7
at /rustc/9bc8c42bb2f19e745a63f3445f1ac248fb015e53/library/std/src/../../backtrace/src/backtrace/mod.rs:66:5
2: 0x560b54968240 - std::sys_common::backtrace::_print_fmt::hbef05ae4237a4d72
at /rustc/9bc8c42bb2f19e745a63f3445f1ac248fb015e53/library/std/src/sys_common/backtrace.rs:67:5
3: 0x560b54968240 - ::fmt::h28abce2fdb9884c2
at /rustc/9bc8c42bb2f19e745a63f3445f1ac248fb015e53/library/std/src/sys_common/backtrace.rs:46:22
4: 0x560b5498835f - core::fmt::write::h3b84512577ca38a8
at /rustc/9bc8c42bb2f19e745a63f3445f1ac248fb015e53/library/core/src/fmt/mod.rs:1092:17
5: 0x560b54961772 - std::io::Write::write_fmt::h465f8feea02e2aa1
at /rustc/9bc8c42bb2f19e745a63f3445f1ac248fb015e53/library/std/src/io/mod.rs:1572:15
6: 0x560b5496a595 - std::sys_common::backtrace::_print::h525280ee0d29bdde
at /rustc/9bc8c42bb2f19e745a63f3445f1ac248fb015e53/library/std/src/sys_common/backtrace.rs:49:5
7: 0x560b5496a595 - std::sys_common::backtrace::print::h1f0f5b9f3ef8fb78
at /rustc/9bc8c42bb2f19e745a63f3445f1ac248fb015e53/library/std/src/sys_common/backtrace.rs:36:9
8: 0x560b5496a595 - std::panicking::default_hook::{{closure}}::ha5838f6faa4a5a8f
at /rustc/9bc8c42bb2f19e745a63f3445f1ac248fb015e53/library/std/src/panicking.rs:208:50
9: 0x560b5496a043 - std::panicking::default_hook::hfb9fe98acb0dcb3b
at /rustc/9bc8c42bb2f19e745a63f3445f1ac248fb015e53/library/std/src/panicking.rs:225:9
10: 0x560b5496ab9d - std::panicking::rust_panic_with_hook::hb89f5f19036e6af8
at /rustc/9bc8c42bb2f19e745a63f3445f1ac248fb015e53/library/std/src/panicking.rs:591:17
11: 0x560b5496a737 - std::panicking::begin_panic_handler::{{closure}}::h119e7951427f41da
at /rustc/9bc8c42bb2f19e745a63f3445f1ac248fb015e53/library/std/src/panicking.rs:497:13
12: 0x560b549686fc - std::sys_common::backtrace::__rust_end_short_backtrace::hce386c44bf47a128
at /rustc/9bc8c42bb2f19e745a63f3445f1ac248fb015e53/library/std/src/sys_common/backtrace.rs:141:18
13: 0x560b5496a699 - rust_begin_unwind
at /rustc/9bc8c42bb2f19e745a63f3445f1ac248fb015e53/library/std/src/panicking.rs:493:5
14: 0x560b54461ba1 - core::panicking::panic_fmt::h2242888e8769cd33
at /rustc/9bc8c42bb2f19e745a63f3445f1ac248fb015e53/library/core/src/panicking.rs:92:14
15: 0x560b54461a93 - core::option::expect_none_failed::hb1edf11f73e63728
at /rustc/9bc8c42bb2f19e745a63f3445f1ac248fb015e53/library/core/src/option.rs:1329:5
16: 0x560b54586d2f - ::open::h0e299499548bf8cb
17: 0x560b544b6d07 - librespot_playback::mixer::mk_sink::hea945d3f1b291efc
18: 0x560b54489fca - ::poll::h789d742187cbd50d
19: 0x560b544a6133 - futures::task_impl::std::set::h188eb9e1a8950863
20: 0x560b544bdc0d - std::thread::local::LocalKey::with::hb45052fc6a2ae633
21: 0x560b54498184 - tokio_current_thread::Entered
::block_on::h885eb0739f27f74e
22: 0x560b544bcf18 - std::thread::local::LocalKey::with::h221054beb46a2abc
23: 0x560b544d2250 - tokio_timer::clock::clock::with_default::h159e4adfb11c433f
24: 0x560b54493104 - tokio::runtime::current_thread::runtime::Runtime::block_on::h7d24b175f2e44b17
25: 0x560b5448d3c9 - vollibrespot::main::hb13811fd4ab212f8
26: 0x560b544bc353 - std::sys_common::backtrace::__rust_begin_short_backtrace::h20ed102c66600ce2
27: 0x560b544bc859 - std::rt::lang_start::{{closure}}::h81eea2a75fc78b02
28: 0x560b5496af9a - core::ops::function::impls:: for &F>::call_once::h44574effd2120c86
at /rustc/9bc8c42bb2f19e745a63f3445f1ac248fb015e53/library/core/src/ops/function.rs:259:13
29: 0x560b5496af9a - std::panicking::try::do_call::h10b0bd4879c8dfb0
at /rustc/9bc8c42bb2f19e745a63f3445f1ac248fb015e53/library/std/src/panicking.rs:379:40
30: 0x560b5496af9a - std::panicking::try::h60c6780d33419e92
at /rustc/9bc8c42bb2f19e745a63f3445f1ac248fb015e53/library/std/src/panicking.rs:343:19
31: 0x560b5496af9a - std::panic::catch_unwind::h111f33e08c52e2ce
at /rustc/9bc8c42bb2f19e745a63f3445f1ac248fb015e53/library/std/src/panic.rs:431:14
32: 0x560b5496af9a - std::rt::lang_start_internal::h126f2e09345dbfda
at /rustc/9bc8c42bb2f19e745a63f3445f1ac248fb015e53/library/std/src/rt.rs:51:25
33: 0x560b5448ea62 - main
34: 0x7f56bb1e909b - __libc_start_main
35: 0x560b5446228a - _start
36: 0x0 -
volspotconnect2.service: Main process exited, code=exited, status=101/n/a
volspotconnect2.service: Failed with result 'exit-code'.
volspotconnect2.service: Service RestartSec=2s expired, scheduling restart.
volspotconnect2.service: Scheduled restart job, restart counter is at 2.
Stopped Volspotconnect2 Daemon.
Started Volspotconnect2 Daemon.
vollibrespot v0.2.3 769ce77 2021-06-04 (librespot 08d8bcc 2020-10-07) -- Built On 2021-06-04
Reading Config from "volspotify.toml"
[Vollibrespot] : Using Alsa backend with device: volumio
[Vollibrespot] : Failed to register IPv6 receiver: Os { code: 19, kind: Other, message: "No such device" }
process exited with code null
I changed the Mixer Type to none, it’s still not working, but the log is different
Starting Live Log...
assert.ok(self.idling)
error: updateQueue error: null
info: VolumeController::SetAlsaVolume100
info: CoreStateMachine::pushState
info: CorePlayQueue::getTrack 0
info: CoreCommandRouter::volumioPushState
error: updateQueue error: null
info: CALLMETHOD: system_controller system enableLiveLog true
info: CoreCommandRouter::executeOnPlugin: system , enableLiveLog
info: Launching a new LiveLog session
[Vollibrespot] : Connecting to AP "ap-gew1.spotify.com:443"
[Vollibrespot] : Authenticated as "REDACTED" !
[Vollibrespot] : Using alsa sink
[Vollibrespot] : Country: "SE"
[Vollibrespot] : Metadata pipe established
[Vollibrespot] : Event: Volume { volume_to_mixer: 21626 }
[SpotifyConnect] 32.99916075379568
[SpotifyConnect] Volume: Spotify:32.99916075379568 Volumio: 33
info: CoreStateMachine::pushState
info: CorePlayQueue::getTrack 0
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
info: CoreCommandRouter::volumioPushState
[Vollibrespot] : Fetching autoplay context uri
[Vollibrespot] : Event: SessionActive { became_active_at: 1641977222846 }
[Vollibrespot] : SessionActive!
[Vollibrespot] : Event: PlaybackStarted { track_id: SpotifyId { id: 283148506127850767767728711471594276735, audio_type: Track } }
[Vollibrespot] : Event: PlaybackLoading { track_id: SpotifyId { id: 283148506127850767767728711471594276735, audio_type: Track } }
[SpotifyConnect] A connect session has begun
[SpotifyConnect] Device palyback is active!
info: CoreCommandRouter::volumioGetState
info: CorePlayQueue::getTrack 0
[SpotifyConnect] Currently active: mpd
[SpotifyConnect] Stopping currently active service
info: CoreCommandRouter::volumioStop
info: CoreStateMachine::stop
info: CoreStateMachine::setConsumeUpdateService undefined
[SpotifyConnect] Vollibrespot Active
info: CoreCommandRouter::volumioGetState
info: CorePlayQueue::getTrack 0
[SpotifyConnect] Currently active: mpd
[SpotifyConnect] Setting Volatile state to Volspotconnect2
info: CoreStateMachine::setConsumeUpdateService undefined
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
info: CoreCommandRouter::volumioPushState
info: CorePlayQueue::getTrack 0
info: CoreStateMachine::syncState stateService stop
info: CoreStateMachine::syncState currentStatus stop
info: CoreStateMachine::pushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
info: CoreCommandRouter::volumioPushState
info: No code
info: CoreStateMachine::pushState
info: CoreCommandRouter::volumioPushState
info: CoreCommandRouter::volumioGetState
[SpotifyConnect] Currently active: undefined
[SpotifyConnect] Pushing new state :: true
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::volumioPushState
info: CorePlayQueue::getTrack 0
info: CoreStateMachine::syncState stateService stop
info: CoreStateMachine::syncState currentStatus stop
info: CoreStateMachine::pushState
info: CoreCommandRouter::volumioPushState
info: No code
info: CoreStateMachine::pushState
info: CoreCommandRouter::volumioPushState
[Vollibrespot] : error 403 for uri hm://keymaster/token/authenticated?client_id=4ced2e7c73484127be5d36015752eb43&scope=streaming,user-read-playback-state,user-modify-playback-state,user-read-currently-playing,user-read-private
[Vollibrespot] : Error: MercuryError
[Vollibrespot] : Autoplay uri resolved to <"spotify:station:playlist:37i9dQZF1E35Rhfoyhgf3p">
[Vollibrespot] : Resolving uri "spotify:station:playlist:37i9dQZF1E35Rhfoyhgf3p"
thread 'main' panicked at 'cannot poll Map twice', /build/cache/registry/src/github.com-1ecc6299db9ec823/futures-0.1.31/src/future/map.rs:35:29
stack backtrace:
0: 0x55667e998240 - std::backtrace_rs::backtrace::libunwind::trace::h63b7a90188ab5fb3
at /rustc/9bc8c42bb2f19e745a63f3445f1ac248fb015e53/library/std/src/../../backtrace/src/backtrace/libunwind.rs:90:5
1: 0x55667e998240 - std::backtrace_rs::backtrace::trace_unsynchronized::h80aefbf9b851eca7
at /rustc/9bc8c42bb2f19e745a63f3445f1ac248fb015e53/library/std/src/../../backtrace/src/backtrace/mod.rs:66:5
2: 0x55667e998240 - std::sys_common::backtrace::_print_fmt::hbef05ae4237a4d72
at /rustc/9bc8c42bb2f19e745a63f3445f1ac248fb015e53/library/std/src/sys_common/backtrace.rs:67:5
3: 0x55667e998240 - ::fmt::h28abce2fdb9884c2
at /rustc/9bc8c42bb2f19e745a63f3445f1ac248fb015e53/library/std/src/sys_common/backtrace.rs:46:22
4: 0x55667e9b835f - core::fmt::write::h3b84512577ca38a8
at /rustc/9bc8c42bb2f19e745a63f3445f1ac248fb015e53/library/core/src/fmt/mod.rs:1092:17
5: 0x55667e991772 - std::io::Write::write_fmt::h465f8feea02e2aa1
at /rustc/9bc8c42bb2f19e745a63f3445f1ac248fb015e53/library/std/src/io/mod.rs:1572:15
6: 0x55667e99a595 - std::sys_common::backtrace::_print::h525280ee0d29bdde
at /rustc/9bc8c42bb2f19e745a63f3445f1ac248fb015e53/library/std/src/sys_common/backtrace.rs:49:5
7: 0x55667e99a595 - std::sys_common::backtrace::print::h1f0f5b9f3ef8fb78
at /rustc/9bc8c42bb2f19e745a63f3445f1ac248fb015e53/library/std/src/sys_common/backtrace.rs:36:9
8: 0x55667e99a595 - std::panicking::default_hook::{{closure}}::ha5838f6faa4a5a8f
at /rustc/9bc8c42bb2f19e745a63f3445f1ac248fb015e53/library/std/src/panicking.rs:208:50
9: 0x55667e99a043 - std::panicking::default_hook::hfb9fe98acb0dcb3b
at /rustc/9bc8c42bb2f19e745a63f3445f1ac248fb015e53/library/std/src/panicking.rs:225:9
10: 0x55667e99ab9d - std::panicking::rust_panic_with_hook::hb89f5f19036e6af8
at /rustc/9bc8c42bb2f19e745a63f3445f1ac248fb015e53/library/std/src/panicking.rs:591:17
11: 0x55667e99a737 - std::panicking::begin_panic_handler::{{closure}}::h119e7951427f41da
at /rustc/9bc8c42bb2f19e745a63f3445f1ac248fb015e53/library/std/src/panicking.rs:497:13
12: 0x55667e9986fc - std::sys_common::backtrace::__rust_end_short_backtrace::hce386c44bf47a128
at /rustc/9bc8c42bb2f19e745a63f3445f1ac248fb015e53/library/std/src/sys_common/backtrace.rs:141:18
13: 0x55667e99a699 - rust_begin_unwind
at /rustc/9bc8c42bb2f19e745a63f3445f1ac248fb015e53/library/std/src/panicking.rs:493:5
14: 0x55667e491ba1 - core::panicking::panic_fmt::h2242888e8769cd33
at /rustc/9bc8c42bb2f19e745a63f3445f1ac248fb015e53/library/core/src/panicking.rs:92:14
15: 0x55667e491a03 - core::option::expect_failed::h5ed4263027530e3b
at /rustc/9bc8c42bb2f19e745a63f3445f1ac248fb015e53/library/core/src/option.rs:1321:5
16: 0x55667e69542d - as futures::future::Future>::poll::h3a7c9819ba49c603
17: 0x55667e577c1b - ::poll::h644527f107dfe1b6
18: 0x55667e4ba6e9 - ::poll::h789d742187cbd50d
19: 0x55667e4d6133 - futures::task_impl::std::set::h188eb9e1a8950863
20: 0x55667e4edc0d - std::thread::local::LocalKey::with::hb45052fc6a2ae633
21: 0x55667e4c8184 - tokio_current_thread::Entered
::block_on::h885eb0739f27f74e
22: 0x55667e4ecf18 - std::thread::local::LocalKey::with::h221054beb46a2abc
23: 0x55667e502250 - tokio_timer::clock::clock::with_default::h159e4adfb11c433f
24: 0x55667e4c3104 - tokio::runtime::current_thread::runtime::Runtime::block_on::h7d24b175f2e44b17
25: 0x55667e4bd3c9 - vollibrespot::main::hb13811fd4ab212f8
26: 0x55667e4ec353 - std::sys_common::backtrace::__rust_begin_short_backtrace::h20ed102c66600ce2
27: 0x55667e4ec859 - std::rt::lang_start::{{closure}}::h81eea2a75fc78b02
28: 0x55667e99af9a - core::ops::function::impls:: for &F>::call_once::h44574effd2120c86
at /rustc/9bc8c42bb2f19e745a63f3445f1ac248fb015e53/library/core/src/ops/function.rs:259:13
29: 0x55667e99af9a - std::panicking::try::do_call::h10b0bd4879c8dfb0
at /rustc/9bc8c42bb2f19e745a63f3445f1ac248fb015e53/library/std/src/panicking.rs:379:40
30: 0x55667e99af9a - std::panicking::try::h60c6780d33419e92
at /rustc/9bc8c42bb2f19e745a63f3445f1ac248fb015e53/library/std/src/panicking.rs:343:19
31: 0x55667e99af9a - std::panic::catch_unwind::h111f33e08c52e2ce
at /rustc/9bc8c42bb2f19e745a63f3445f1ac248fb015e53/library/std/src/panic.rs:431:14
32: 0x55667e99af9a - std::rt::lang_start_internal::h126f2e09345dbfda
at /rustc/9bc8c42bb2f19e745a63f3445f1ac248fb015e53/library/std/src/rt.rs:51:25
33: 0x55667e4bea62 - main
34: 0x7f195276809b - __libc_start_main
35: 0x55667e49228a - _start
36: 0x0 -
[Vollibrespot] : EventSender disconnected
[SpotifyConnect] Device palyback is inactive
[SpotifyConnect] Device Session is_active: true
[SpotifyConnect] Sink released
info: CoreCommandRouter::servicePushState
info: CoreStateMachine::pushState
info: CoreCommandRouter::executeOnPlugin: volumiodiscovery , saveDeviceInfo
info: CoreCommandRouter::volumioPushState
volspotconnect2.service: Main process exited, code=exited, status=101/n/a
volspotconnect2.service: Failed with result 'exit-code'.
volspotconnect2.service: Service RestartSec=2s expired, scheduling restart.
volspotconnect2.service: Scheduled restart job, restart counter is at 1.
Stopped Volspotconnect2 Daemon.
Started Volspotconnect2 Daemon.
vollibrespot v0.2.3 769ce77 2021-06-04 (librespot 08d8bcc 2020-10-07) -- Built On 2021-06-04
Reading Config from "volspotify.toml"
[Vollibrespot] : Using Alsa backend with device: volumio
[Vollibrespot] : Failed to register IPv6 receiver: Os { code: 19, kind: Other, message: "No such device" }
process exited with code null