- Spotify Skill (see GitHub - forslund/spotify-skill: Mycroft Skill to control spotify using the Spotify Connect API)
- Picroft release candidate on a Raspberry Pi 4B, 4GB RAM.
- Using WM8960 Audio HAT as input/output audio device.
Hello,
I have trouble with the Spotify skill on Picroft (see hardware platform and OS details above). I can play anything from my Spotify client on my laptop selecting my picroft device and it sounds just fine. However, when I ask mycroft to play any song, I can see that Spotify is playing a song but no sound is coming from my picroft device.
Looking at the raspotify logs, it appears that mycroft is failing in getting ahold of the audio device. I have tried setting up the --device option to hw:0,0 but it doesn’t work.
A few details about my systems’ installation:
Audio setup:
- I had trouble setting up the audio. After installing the drivers, I (1) blacklisted the raspberry pi’s default audio module so that only the wm8960 device is loaded; (2) resorted to using “sudo aplay %1” in the pycroft configuration as otherwise it would’t work.
Spotify skill setup
- Installing the skill directly from the marketplace wouldn’t work because of authentication issues.
- I installed the skill using the instructions in GitHub - forslund/spotify-skill: Mycroft Skill to control spotify using the Spotify Connect API.
The logs from raspotify:
Nov 01 16:10:06 picroft systemd[1]: Started Raspotify.
Nov 01 16:10:06 picroft librespot[3260]: [2021-11-01T16:10:06Z INFO librespot] librespot (raspotify v0.16.0) 0adb851 (2020-12-15). Built on 2020-12-30. Build ID: KLdkAvgt
Nov 01 16:10:06 picroft librespot[3260]: [2021-11-01T16:10:06Z INFO librespot_core::session] Connecting to AP "gew1-accesspoint-a-r6tw.ap.spotify.com:4070"
Nov 01 16:10:06 picroft librespot[3260]: [2021-11-01T16:10:06Z INFO librespot_core::session] Authenticated as "<myusername>" !
Nov 01 16:10:06 picroft librespot[3260]: [2021-11-01T16:10:06Z INFO librespot_playback::audio_backend::alsa] Using alsa sink
Nov 01 16:10:06 picroft librespot[3260]: [2021-11-01T16:10:06Z INFO librespot_core::session] Country: "GB"
Nov 01 16:10:25 picroft librespot[3260]: [2021-11-01T16:10:25Z INFO librespot_playback::player] Loading <Right on Time> with Spotify URI <spotify:track:5i4WgW0TL9VSosy73Q3Ttv>
Nov 01 16:10:26 picroft librespot[3260]: [2021-11-01T16:10:26Z INFO librespot_playback::player] <Right on Time> (185228 ms) loaded
Nov 01 16:10:27 picroft librespot[3260]: [2021-11-01T16:10:27Z ERROR librespot_playback::audio_backend::alsa] Alsa error PCM open ALSA function 'snd_pcm_open' failed with error 'EBUSY: Device or resource busy'
Nov 01 16:10:27 picroft librespot[3260]: [2021-11-01T16:10:27Z ERROR librespot_playback::player] Could not start audio: Alsa error: PCM open failed
Nov 01 16:10:27 picroft librespot[3260]: [2021-11-01T16:10:27Z ERROR librespot_playback::audio_backend::alsa] Alsa error PCM open ALSA function 'snd_pcm_open' failed with error 'EBUSY: Device or resource busy'
Nov 01 16:10:27 picroft librespot[3260]: [2021-11-01T16:10:27Z ERROR librespot_playback::player] Could not start audio: Alsa error: PCM open failed
Nov 01 16:10:27 picroft librespot[3260]: [2021-11-01T16:10:27Z ERROR librespot_playback::audio_backend::alsa] Alsa error PCM open ALSA function 'snd_pcm_open' failed with error 'EBUSY: Device or resource busy'
Nov 01 16:10:27 picroft librespot[3260]: [2021-11-01T16:10:27Z ERROR librespot_playback::player] Could not start audio: Alsa error: PCM open failed
Nov 01 16:10:27 picroft librespot[3260]: thread '<unnamed>' panicked at 'called `Option::unwrap()` on a `None` value', playback/src/audio_backend/alsa.rs:138:45
Nov 01 16:10:27 picroft librespot[3260]: stack backtrace:
Nov 01 16:10:27 picroft librespot[3260]: 0: 0x89a278 - std::backtrace_rs::backtrace::libunwind::trace::h9c6af82ecb947420
Nov 01 16:10:27 picroft librespot[3260]: at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/../../backtrace/src/backtrace/libunwind.rs:96
Nov 01 16:10:27 picroft librespot[3260]: 1: 0x89a278 - std::backtrace_rs::backtrace::trace_unsynchronized::h80561bf66e637b12
Nov 01 16:10:27 picroft librespot[3260]: at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/../../backtrace/src/backtrace/mod.rs:66
Nov 01 16:10:27 picroft librespot[3260]: 2: 0x89a278 - std::sys_common::backtrace::_print_fmt::h8904fddc87bf6b5e
Nov 01 16:10:27 picroft librespot[3260]: at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/sys_common/backtrace.rs:79
Nov 01 16:10:27 picroft librespot[3260]: 3: 0x89a278 - <std::sys_common::backtrace::_print::DisplayBacktrace as core::fmt::Display>::fmt::hc883ceb7a13219f2
Nov 01 16:10:27 picroft librespot[3260]: at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/sys_common/backtrace.rs:58
Nov 01 16:10:27 picroft librespot[3260]: 4: 0x8c2290 - core::fmt::write::ha75209c8e86bef45
Nov 01 16:10:27 picroft librespot[3260]: at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/core/src/fmt/mod.rs:1080
Nov 01 16:10:27 picroft librespot[3260]: 5: 0x892e18 - std::io::Write::write_fmt::h4cce8be81a41c537
Nov 01 16:10:27 picroft librespot[3260]: at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/io/mod.rs:1516
Nov 01 16:10:27 picroft librespot[3260]: 6: 0x89d1c0 - std::sys_common::backtrace::_print::hdc9e28891c09ab0b
Nov 01 16:10:27 picroft librespot[3260]: at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/sys_common/backtrace.rs:61
Nov 01 16:10:27 picroft librespot[3260]: 7: 0x89d1c0 - std::sys_common::backtrace::print::h85895381379b4dc1
Nov 01 16:10:27 picroft librespot[3260]: at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/sys_common/backtrace.rs:48
Nov 01 16:10:27 picroft librespot[3260]: 8: 0x89d1c0 - std::panicking::default_hook::{{closure}}::h6b4de484f2428118
Nov 01 16:10:27 picroft librespot[3260]: at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/panicking.rs:208
Nov 01 16:10:27 picroft librespot[3260]: 9: 0x89cdbc - std::panicking::default_hook::h3966366a200b03f1
Nov 01 16:10:27 picroft librespot[3260]: at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/panicking.rs:227
Nov 01 16:10:27 picroft librespot[3260]: 10: 0x89d910 - std::panicking::rust_panic_with_hook::h068b5368b0949ced
Nov 01 16:10:27 picroft librespot[3260]: at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/panicking.rs:577
Nov 01 16:10:27 picroft librespot[3260]: 11: 0x89d4c4 - std::panicking::begin_panic_handler::{{closure}}::hde463ebfc6f96538
Nov 01 16:10:27 picroft librespot[3260]: at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/panicking.rs:484
Nov 01 16:10:27 picroft librespot[3260]: 12: 0x89a7f8 - std::sys_common::backtrace::__rust_end_short_backtrace::hb945924c40726c97
Nov 01 16:10:27 picroft librespot[3260]: at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/sys_common/backtrace.rs:153
Nov 01 16:10:27 picroft librespot[3260]: 13: 0x89d47c - rust_begin_unwind
Nov 01 16:10:27 picroft librespot[3260]: at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/panicking.rs:483
Nov 01 16:10:27 picroft librespot[3260]: 14: 0x8bf960 - core::panicking::panic_fmt::h27b19d6e6dedd33e
Nov 01 16:10:27 picroft librespot[3260]: at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/core/src/panicking.rs:85
Nov 01 16:10:27 picroft librespot[3260]: 15: 0x8bf8bc - core::panicking::panic::h2a6f9b05d102de10
Nov 01 16:10:27 picroft librespot[3260]: at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/core/src/panicking.rs:50
Nov 01 16:10:27 picroft librespot[3260]: 16: 0x526020 - <librespot_playback::audio_backend::alsa::AlsaSink as librespot_playback::audio_backend::Sink>::write::hfb124b87fed1cc15
Nov 01 16:10:27 picroft librespot[3260]: 17: 0x503304 - <librespot_playback::player::PlayerInternal as futures::future::Future>::poll::he6e04a5bccf94e34
Nov 01 16:10:27 picroft librespot[3260]: 18: 0x467300 - futures::task_impl::std::set::hab1c1811473e3998
Nov 01 16:10:27 picroft librespot[3260]: 19: 0x45d838 - std::sys_common::backtrace::__rust_begin_short_backtrace::h8286c5a0fd04a387
Nov 01 16:10:27 picroft librespot[3260]: 20: 0x4784f4 - core::ops::function::FnOnce::call_once{{vtable.shim}}::h76e6c7604d7daced
Nov 01 16:10:27 picroft librespot[3260]: 21: 0x8a4940 - <alloc::boxed::Box<F> as core::ops::function::FnOnce<A>>::call_once::h6b7ad05f87ff90ae
Nov 01 16:10:27 picroft librespot[3260]: at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/alloc/src/boxed.rs:1042
Nov 01 16:10:27 picroft librespot[3260]: 22: 0x8a4940 - <alloc::boxed::Box<F> as core::ops::function::FnOnce<A>>::call_once::he9130e675b8d97ee
Nov 01 16:10:27 picroft librespot[3260]: at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/alloc/src/boxed.rs:1042
Nov 01 16:10:27 picroft librespot[3260]: 23: 0x8a4940 - std::sys::unix::thread::Thread::new::thread_start::h7a3f6590d8e03e95
Nov 01 16:10:27 picroft librespot[3260]: at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/sys/unix/thread.rs:87
Nov 01 16:10:35 picroft librespot[3260]: thread 'main' panicked at 'called `Result::unwrap()` on an `Err` value: SendError("...")', playback/src/player.rs:281:61
Nov 01 16:10:35 picroft librespot[3260]: stack backtrace:
Nov 01 16:10:35 picroft librespot[3260]: 0: 0x89a278 - std::backtrace_rs::backtrace::libunwind::trace::h9c6af82ecb947420
Nov 01 16:10:35 picroft librespot[3260]: at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/../../backtrace/src/backtrace/libunwind.rs:96
Nov 01 16:10:35 picroft librespot[3260]: 1: 0x89a278 - std::backtrace_rs::backtrace::trace_unsynchronized::h80561bf66e637b12
Nov 01 16:10:35 picroft librespot[3260]: at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/../../backtrace/src/backtrace/mod.rs:66
Nov 01 16:10:35 picroft librespot[3260]: 2: 0x89a278 - std::sys_common::backtrace::_print_fmt::h8904fddc87bf6b5e
Nov 01 16:10:35 picroft librespot[3260]: at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/sys_common/backtrace.rs:79
Nov 01 16:10:35 picroft librespot[3260]: 3: 0x89a278 - <std::sys_common::backtrace::_print::DisplayBacktrace as core::fmt::Display>::fmt::hc883ceb7a13219f2
Nov 01 16:10:35 picroft librespot[3260]: at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/sys_common/backtrace.rs:58
Nov 01 16:10:35 picroft librespot[3260]: 4: 0x8c2290 - core::fmt::write::ha75209c8e86bef45
Nov 01 16:10:35 picroft librespot[3260]: at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/core/src/fmt/mod.rs:1080
Nov 01 16:10:35 picroft librespot[3260]: 5: 0x892e18 - std::io::Write::write_fmt::h4cce8be81a41c537
Nov 01 16:10:35 picroft librespot[3260]: at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/io/mod.rs:1516
Nov 01 16:10:35 picroft librespot[3260]: 6: 0x89d1c0 - std::sys_common::backtrace::_print::hdc9e28891c09ab0b
Nov 01 16:10:35 picroft librespot[3260]: at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/sys_common/backtrace.rs:61
Nov 01 16:10:35 picroft librespot[3260]: 7: 0x89d1c0 - std::sys_common::backtrace::print::h85895381379b4dc1
Nov 01 16:10:35 picroft librespot[3260]: at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/sys_common/backtrace.rs:48
Nov 01 16:10:35 picroft librespot[3260]: 8: 0x89d1c0 - std::panicking::default_hook::{{closure}}::h6b4de484f2428118
Nov 01 16:10:35 picroft librespot[3260]: at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/panicking.rs:208
Nov 01 16:10:35 picroft librespot[3260]: 9: 0x89cdbc - std::panicking::default_hook::h3966366a200b03f1
Nov 01 16:10:35 picroft librespot[3260]: at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/panicking.rs:227
Nov 01 16:10:35 picroft librespot[3260]: 10: 0x89d910 - std::panicking::rust_panic_with_hook::h068b5368b0949ced
Nov 01 16:10:35 picroft librespot[3260]: at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/panicking.rs:577
Nov 01 16:10:35 picroft librespot[3260]: 11: 0x89d4c4 - std::panicking::begin_panic_handler::{{closure}}::hde463ebfc6f96538
Nov 01 16:10:35 picroft librespot[3260]: at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/panicking.rs:484
Nov 01 16:10:35 picroft librespot[3260]: 12: 0x89a7f8 - std::sys_common::backtrace::__rust_end_short_backtrace::hb945924c40726c97
Nov 01 16:10:35 picroft librespot[3260]: at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/sys_common/backtrace.rs:153
Nov 01 16:10:35 picroft librespot[3260]: 13: 0x89d47c - rust_begin_unwind
Nov 01 16:10:35 picroft librespot[3260]: at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/panicking.rs:483
Nov 01 16:10:35 picroft librespot[3260]: 14: 0x8bf960 - core::panicking::panic_fmt::h27b19d6e6dedd33e
Nov 01 16:10:35 picroft librespot[3260]: at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/core/src/panicking.rs:85
Nov 01 16:10:35 picroft librespot[3260]: 15: 0x8bf7b8 - core::option::expect_none_failed::h0ec77a052e666b69
Nov 01 16:10:35 picroft librespot[3260]: at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/core/src/option.rs:1234
Nov 01 16:10:35 picroft librespot[3260]: 16: 0x5000a8 - librespot_playback::player::Player::pause::h4bd7037998ab1226
Nov 01 16:10:35 picroft librespot[3260]: 17: 0x4af590 - librespot_connect::spirc::SpircTask::handle_pause::had01063f6bb2c635
Nov 01 16:10:35 picroft librespot[3260]: 18: 0x4ada34 - <librespot_connect::spirc::SpircTask as futures::future::Future>::poll::h400d0c6a9af9b895
Nov 01 16:10:35 picroft librespot[3260]: 19: 0x473ab4 - <librespot::Main as futures::future::Future>::poll::h169a5d4027f550f1
Nov 01 16:10:35 picroft librespot[3260]: 20: 0x466cf0 - futures::task_impl::std::set::h171bb0e3315231c5
Nov 01 16:10:35 picroft librespot[3260]: 21: 0x4855b0 - <futures::future::lazy::Lazy<F,R> as futures::future::Future>::poll::h6ad5d06c62a954b1
Nov 01 16:10:35 picroft librespot[3260]: 22: 0x466e70 - futures::task_impl::std::set::h1b4107da043418f3
Nov 01 16:10:35 picroft librespot[3260]: 23: 0x45dc1c - std::thread::local::LocalKey<T>::with::h10f666118935c490
Nov 01 16:10:35 picroft librespot[3260]: 24: 0x45c6b8 - tokio_current_thread::Entered<P>::block_on::hbb47725fa57f8e44
Nov 01 16:10:35 picroft librespot[3260]: 25: 0x4635b8 - tokio_timer::timer::handle::with_default::h938751ab893a9316
Nov 01 16:10:35 picroft librespot[3260]: 26: 0x45dff8 - std::thread::local::LocalKey<T>::with::hed23bc0e3035947a
Nov 01 16:10:35 picroft librespot[3260]: 27: 0x45b990 - scoped_tls::ScopedKey<T>::set::heda756cd7e82ddd6
Nov 01 16:10:35 picroft librespot[3260]: 28: 0x462cf0 - tokio_core::reactor::Core::run::hccb77cd75ccb2c67
Nov 01 16:10:35 picroft librespot[3260]: 29: 0x476448 - librespot::main::h6da7c78e457a1f2f
Nov 01 16:10:35 picroft librespot[3260]: 30: 0x45dabc - std::sys_common::backtrace::__rust_begin_short_backtrace::h92f05e3879870930
Nov 01 16:10:35 picroft librespot[3260]: 31: 0x48030c - std::rt::lang_start::{{closure}}::h067bf4c6ab425fd6
Nov 01 16:10:35 picroft librespot[3260]: 32: 0x89dd30 - core::ops::function::impls::<impl core::ops::function::FnOnce<A> for &F>::call_once::h2c136973bfb85920
Nov 01 16:10:35 picroft librespot[3260]: at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/core/src/ops/function.rs:259
Nov 01 16:10:35 picroft librespot[3260]: 33: 0x89dd30 - std::panicking::try::do_call::hc0787118c306af2e
Nov 01 16:10:35 picroft librespot[3260]: at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/panicking.rs:381
Nov 01 16:10:35 picroft librespot[3260]: 34: 0x89dd30 - std::panicking::try::he0aeb9ab5f254114
Nov 01 16:10:35 picroft librespot[3260]: at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/panicking.rs:345
Nov 01 16:10:35 picroft librespot[3260]: 35: 0x89dd30 - std::panic::catch_unwind::hb91533e13ff48846
Nov 01 16:10:35 picroft librespot[3260]: at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/panic.rs:382
Nov 01 16:10:35 picroft librespot[3260]: 36: 0x89dd30 - std::rt::lang_start_internal::hf9465186f7b70c75
Nov 01 16:10:35 picroft librespot[3260]: at /rustc/7eac88abb2e57e752f3302f02be5f3ce3d7adfb4/library/std/src/rt.rs:51
Nov 01 16:10:35 picroft librespot[3260]: 37: 0x477460 - main
Nov 01 16:10:35 picroft librespot[3260]: 38: 0xb6ca9718 - __libc_start_main
Nov 01 16:10:35 picroft librespot[3260]: [2021-11-01T16:10:35Z ERROR librespot_playback::player] Player thread panicked!
Nov 01 16:10:35 picroft systemd[1]: raspotify.service: Main process exited, code=exited, status=101/n/a
Nov 01 16:10:35 picroft systemd[1]: raspotify.service: Failed with result 'exit-code'.
Any help is much appreciated. Thank you.