Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

SendError on playback start #744

Closed
2 of 6 tasks
EvilOlaf opened this issue Dec 23, 2020 · 15 comments
Closed
2 of 6 tasks

SendError on playback start #744

EvilOlaf opened this issue Dec 23, 2020 · 15 comments
Labels
bug A functionality or parts of a program that do not work as intended

Comments

@EvilOlaf
Copy link

EvilOlaf commented Dec 23, 2020

Description
As soon as a title is selected it causes spotifyd to crash with

Caught panic with message: called `Result::unwrap()` on an `Err` value: "SendError(..)"

To Reproduce

  1. Start spotifyd with config variables set: username, password, bitrate, no_audio_cache = true
  2. Use Smartphone or any other Spotifyapp to connect
  3. Select a title and play
  4. See error mentioned above

Expected behavior
Should not crash but play I guess...

Logs

Click to show logs ``` spotifyd --verbose --no-daemon Loading config from "/home/p1/.config/spotifyd/spotifyd.conf" CliConfig { config_path: None, no_daemon: true, verbose: true, pid: None, shared_config: SharedConfigValues { username: Some("taken out for privacy"), username_cmd: None, password: Some("taken out for privacy"), password_cmd: None, use_keyring: false, on_song_change_hook: None, cache_path: None, no-audio-cache: true, backend: None, volume_controller: None, device: None, control: None, mixer: None, device_name: None, bitrate: Some(Bitrate320), initial_volume: None, volume_normalisation: false, normalisation_pregain: None, zeroconf_port: None, proxy: None, device_type: None } } Found user shell: Some("/bin/bash") No proxy specified registering with poller registering with poller registering with poller registering with poller registering with poller registering with poller build; num-workers=6 registering with poller Using software volume controller. starting background reactor adding I/O source: 0 registering with poller Zeroconf server listening on 0.0.0.0:40771 adding I/O source: 4194305 registering with poller adding I/O source: 8388610 registering with poller event Writable Token(4194305) loop process - 1 events, 0.000s event Writable Token(8388610) loop process - 1 events, 0.000s adding I/O source: 12582915 registering with poller event Writable Token(12582915) loop process - 1 events, 0.000s park; waiting for idle connection: "http://apresolve.spotify.com" Http::connect("http://apresolve.spotify.com/") consuming notification queue scheduling Read for: 0 scheduling Read for: 1 sending packet to 224.0.0.251:5353 event Readable | Writable Token(4194305) loop process - 1 events, 0.000s resolving host="apresolve.spotify.com", port=80 scheduling Read for: 2 sending packet to [ff02::fb]:5353 scheduling Read for: 3 loop poll - 1.376958ms loop time - Instant { tv_sec: 95291, tv_nsec: 20398852 } loop process, 44.917µs received packet from 192.168.178.70:5353 received packet from 192.168.178.70:5353 with no query scheduling Read for: 1 scheduling Read for: 1 scheduling Read for: 2 loop poll - 174.125µs loop time - Instant { tv_sec: 95291, tv_nsec: 20642686 } loop process, 40.25µs event Readable | Writable Token(8388610) event Writable Token(4194305) loop process - 2 events, 0.000s event Readable Token(0) loop process - 1 events, 0.000s scheduling Read for: 1 received packet from [fe80::8616:d5d3:a38b:c658]:5353 received packet from [fe80::8616:d5d3:a38b:c658]:5353 with no query scheduling Read for: 2 scheduling Read for: 2 scheduling Read for: 0 loop poll - 1.474375ms loop time - Instant { tv_sec: 95291, tv_nsec: 22176561 } loop process, 40.25µs Conn::read_head adding I/O source: 16777220 registering with poller scheduling Read for: 4 flushed State { reading: Init, writing: Init, keep_alive: Busy, error: None } wants_read_again? false loop poll - 213.5µs loop time - Instant { tv_sec: 95291, tv_nsec: 22453936 } loop process, 88.083µs event Readable | Writable Token(16777220) loop process - 1 events, 0.000s Conn::read_head read 224 bytes Request.parse([Header; 100], [u8; 224]) Request.parse Complete(224) maybe_literal not found, copying "Keep-Alive" parsed 6 headers (224 bytes) incoming body is content-length (0 bytes) expecting_continue(version=Http11, header=None) = false should_keep_alive(version=Http11, header=Some(Connection([KeepAlive]))) = true read_keep_alive; is_mid_message=true should_keep_alive(version=Http11, header=None) = true Server::encode has_body=true, method=Some(Get) encoding chunked 456B flushed 552 bytes scheduling Read for: 4 maybe_notify; read_from_io blocked flushed State { reading: Init, writing: Init, keep_alive: Idle, error: None } wants_read_again? false loop poll - 1.332625ms loop time - Instant { tv_sec: 95291, tv_nsec: 23912561 } loop process, 40.541µs loop poll - 24.120375ms loop time - Instant { tv_sec: 95291, tv_nsec: 48097686 } loop process, 88.667µs connecting to [2600:1901:0:524d::]:80 adding I/O source: 20971525 registering with poller scheduling Write for: 5 event Writable Token(20971525) loop process - 1 events, 0.000s loop poll - 23.509375ms loop time - Instant { tv_sec: 95291, tv_nsec: 72097061 } loop process, 122.792µs read_keep_alive; is_mid_message=false scheduling Read for: 5 should_keep_alive(version=Http11, header=None) = true Client::encode has_body=false, method=None reclaiming write buf Vec flushed 47 bytes flushed State { reading: Init, writing: KeepAlive, keep_alive: Busy, error: None } wants_read_again? false loop poll - 337.458µs loop time - Instant { tv_sec: 95291, tv_nsec: 72770519 } loop process, 15.167µs event Readable | Writable Token(16777220) loop process - 1 events, 0.000s Conn::read_head read 0 bytes parse eof State::close_read() read eof read_keep_alive; is_mid_message=true flushed State { reading: Closed, writing: Init, keep_alive: Disabled, error: None } wants_read_again? false shut down IO deregistering handle with poller dropping I/O source: 4 loop poll - 1.723042ms loop time - Instant { tv_sec: 95291, tv_nsec: 74516311 } loop process, 74.375µs event Readable | Writable Token(20971525) loop process - 1 events, 0.000s Conn::read_head read 594 bytes Response.parse([Header; 100], [u8; 594]) Response.parse Complete(176) maybe_literal not found, copying "Via" parsed 5 headers (176 bytes) incoming body is content-length (418 bytes) expecting_continue(version=Http11, header=None) = false should_keep_alive(version=Http11, header=None) = true Conn::read_body decode; state=Length(418) flushed State { reading: Body(Length(0)), writing: KeepAlive, keep_alive: Busy, error: None } wants_read_again? false loop poll - 29.336834ms loop time - Instant { tv_sec: 95291, tv_nsec: 103974478 } loop process, 22.166µs Conn::read_body decode; state=Length(0) incoming body completed scheduling Read for: 5 maybe_notify; read_from_io blocked read_keep_alive; is_mid_message=false scheduling Read for: 5 signal: Want flushed State { reading: Init, writing: Init, keep_alive: Idle, error: None } wants_read_again? false poll_want: taker wants! pool dropped, dropping pooled ("http://apresolve.spotify.com") loop poll - 148.167µs loop time - Instant { tv_sec: 95291, tv_nsec: 104341978 } loop process, 14.875µs Connecting to AP "gew1-accesspoint-b-9f0d.ap.spotify.com:443" adding I/O source: 25165828 registering with poller scheduling Write for: 4 read_keep_alive; is_mid_message=false scheduling Read for: 5 client tx closed State::close_read() State::close_write() flushed State { reading: Closed, writing: Closed, keep_alive: Disabled, error: None } wants_read_again? false shut down IO deregistering handle with poller dropping I/O source: 5 signal: Closed loop poll - 253.458µs loop time - Instant { tv_sec: 95291, tv_nsec: 132774561 } loop process, 34.125µs event Writable Token(25165828) loop process - 1 events, 0.000s loop poll - 30.864458ms loop time - Instant { tv_sec: 95291, tv_nsec: 163702894 } loop process, 87.209µs event Readable Token(0) loop process - 1 events, 0.000s scheduling Read for: 4 scheduling Read for: 0 loop poll - 156.625µs loop time - Instant { tv_sec: 95291, tv_nsec: 201503186 } loop process, 25.375µs Conn::read_head adding I/O source: 29360133 registering with poller scheduling Read for: 5 flushed State { reading: Init, writing: Init, keep_alive: Busy, error: None } wants_read_again? false loop poll - 201.25µs loop time - Instant { tv_sec: 95291, tv_nsec: 201739436 } loop process, 27.417µs event Readable | Writable Token(29360133) loop process - 1 events, 0.000s Conn::read_head read 221 bytes Request.parse([Header; 100], [u8; 221]) Request.parse Complete(221) maybe_literal not found, copying "Keep-Alive" parsed 6 headers (221 bytes) incoming body is content-length (0 bytes) expecting_continue(version=Http11, header=None) = false should_keep_alive(version=Http11, header=Some(Connection([KeepAlive]))) = true read_keep_alive; is_mid_message=true should_keep_alive(version=Http11, header=None) = true Server::encode has_body=true, method=Some(Get) encoding chunked 456B flushed 552 bytes scheduling Read for: 5 maybe_notify; read_from_io blocked flushed State { reading: Init, writing: Init, keep_alive: Idle, error: None } wants_read_again? false loop poll - 838.25µs loop time - Instant { tv_sec: 95291, tv_nsec: 202619686 } loop process, 51.917µs event Readable | Writable Token(29360133) loop process - 1 events, 0.000s Conn::read_head read 0 bytes parse eof State::close_read() read eof read_keep_alive; is_mid_message=true flushed State { reading: Closed, writing: Init, keep_alive: Disabled, error: None } wants_read_again? false shut down IO deregistering handle with poller dropping I/O source: 5 loop poll - 5.996959ms loop time - Instant { tv_sec: 95291, tv_nsec: 208697728 } loop process, 37.041µs event Readable | Writable Token(25165828) loop process - 1 events, 0.000s loop poll - 35.941458ms loop time - Instant { tv_sec: 95291, tv_nsec: 244699269 } loop process, 133.292µs flushing framed transport writing; remaining=136 framed transport flushed scheduling Read for: 4 event Readable | Writable Token(25165828) loop process - 1 events, 0.000s event Readable | Writable Token(25165828) loop process - 1 events, 0.000s loop poll - 152.653417ms loop time - Instant { tv_sec: 95291, tv_nsec: 435967603 } loop process, 248.208µs attempting to decode a frame frame decoded from buffer Authenticated as "s5dywt4qf5tga4rjmf5k48xbm" ! new Session[0] new Spirc[0] new MercuryManager new Player[0] Using alsa sink input volume:65535 to mixer: 65535 attempting to decode a frame frame decoded from buffer Session[0] strong=3 weak=2 attempting to decode a frame frame decoded from buffer attempting to decode a frame frame decoded from buffer attempting to decode a frame frame decoded from buffer Country: "DE" attempting to decode a frame frame decoded from buffer attempting to decode a frame frame decoded from buffer attempting to decode a frame frame decoded from buffer attempting to decode a frame scheduling Read for: 4 flushing framed transport writing; remaining=454 framed transport flushed loop poll - 3.871292ms loop time - Instant { tv_sec: 95291, tv_nsec: 441466978 } loop process, 233.333µs event Readable | Writable Token(25165828) loop process - 1 events, 0.000s attempting to decode a frame frame decoded from buffer attempting to decode a frame scheduling Read for: 4 flushing framed transport framed transport flushed loop poll - 29.385084ms loop time - Instant { tv_sec: 95291, tv_nsec: 471196228 } loop process, 41.416µs event Readable | Writable Token(25165828) loop process - 1 events, 0.000s attempting to decode a frame frame decoded from buffer attempting to decode a frame frame decoded from buffer attempting to decode a frame frame decoded from buffer unknown subscription uri=hm://remote/user/s5dywt4qf5tga4rjmf5k48xbm/ attempting to decode a frame frame decoded from buffer unknown subscription uri=hm://remote/user/s5dywt4qf5tga4rjmf5k48xbm/ attempting to decode a frame scheduling Read for: 4 flushing framed transport framed transport flushed loop poll - 67.574958ms loop time - Instant { tv_sec: 95291, tv_nsec: 538834186 } loop process, 51.333µs subscribed uri=hm://remote/user/s5dywt4qf5tga4rjmf5k48xbm/ count=0 loop poll - 9.917µs loop time - Instant { tv_sec: 95291, tv_nsec: 539055561 } loop process, 70.875µs event Readable | Writable Token(4194305) loop process - 1 events, 0.000s received packet from 192.168.178.50:5353 scheduling Read for: 1 scheduling Read for: 1 scheduling Read for: 2 loop poll - 1.999206835s loop time - Instant { tv_sec: 95293, tv_nsec: 538369729 } loop process, 54.541µs event Readable Token(0) loop process - 1 events, 0.000s scheduling Read for: 0 loop poll - 27.510917ms loop time - Instant { tv_sec: 95293, tv_nsec: 565985937 } loop process, 25.958µs Conn::read_head adding I/O source: 33554437 registering with poller scheduling Read for: 5 flushed State { reading: Init, writing: Init, keep_alive: Busy, error: None } wants_read_again? false loop poll - 136.208µs loop time - Instant { tv_sec: 95293, tv_nsec: 566164437 } loop process, 14.292µs event Readable | Writable Token(33554437) loop process - 1 events, 0.000s Conn::read_head read 221 bytes Request.parse([Header; 100], [u8; 221]) Request.parse Complete(221) maybe_literal not found, copying "Keep-Alive" parsed 6 headers (221 bytes) incoming body is content-length (0 bytes) expecting_continue(version=Http11, header=None) = false should_keep_alive(version=Http11, header=Some(Connection([KeepAlive]))) = true read_keep_alive; is_mid_message=true should_keep_alive(version=Http11, header=None) = true Server::encode has_body=true, method=Some(Get) encoding chunked 456B flushed 552 bytes scheduling Read for: 5 maybe_notify; read_from_io blocked flushed State { reading: Init, writing: Init, keep_alive: Idle, error: None } wants_read_again? false loop poll - 1.098708ms loop time - Instant { tv_sec: 95293, tv_nsec: 567285020 } loop process, 20.125µs event Readable | Writable Token(33554437) loop process - 1 events, 0.000s Conn::read_head read 0 bytes parse eof State::close_read() read eof read_keep_alive; is_mid_message=true flushed State { reading: Closed, writing: Init, keep_alive: Disabled, error: None } wants_read_again? false shut down IO deregistering handle with poller dropping I/O source: 5 loop poll - 4.258334ms loop time - Instant { tv_sec: 95293, tv_nsec: 571577479 } loop process, 23.041µs event Readable | Writable Token(25165828) loop process - 1 events, 0.000s attempting to decode a frame attempting to decode a frame frame decoded from buffer attempting to decode a frame scheduling Read for: 4 flushing framed transport framed transport flushed loop poll - 56.067708ms loop time - Instant { tv_sec: 95293, tv_nsec: 627684562 } loop process, 73.792µs kMessageTypeNotify "Pixel 5" bef8fafb0a447e65096fe138edfc2255a38241a7 255617509 1608720869112 loop poll - 8.75µs loop time - Instant { tv_sec: 95293, tv_nsec: 627985854 } loop process, 86.041µs event Readable | Writable Token(4194305) loop process - 1 events, 0.000s received packet from 192.168.178.50:5353 scheduling Read for: 1 scheduling Read for: 1 sending packet to 224.0.0.251:5353 scheduling Read for: 2 loop poll - 15.569209ms loop time - Instant { tv_sec: 95293, tv_nsec: 643649854 } loop process, 58.041µs event Readable | Writable Token(4194305) loop process - 1 events, 0.000s received packet from 192.168.178.70:5353 received packet from 192.168.178.70:5353 with no query scheduling Read for: 1 scheduling Read for: 1 scheduling Read for: 2 loop poll - 252.584µs loop time - Instant { tv_sec: 95293, tv_nsec: 643978854 } loop process, 122.208µs event Writable Token(4194305) loop process - 1 events, 0.000s event Readable | Writable Token(4194305) loop process - 1 events, 0.000s received packet from 192.168.178.50:5353 scheduling Read for: 1 scheduling Read for: 1 scheduling Read for: 2 loop poll - 902.057876ms loop time - Instant { tv_sec: 95294, tv_nsec: 546188396 } loop process, 24.5µs event Readable Token(0) loop process - 1 events, 0.000s scheduling Read for: 0 loop poll - 236.710833ms loop time - Instant { tv_sec: 95294, tv_nsec: 782962521 } loop process, 25.667µs Conn::read_head adding I/O source: 37748741 registering with poller scheduling Read for: 5 flushed State { reading: Init, writing: Init, keep_alive: Busy, error: None } wants_read_again? false loop poll - 181.125µs loop time - Instant { tv_sec: 95294, tv_nsec: 783216271 } loop process, 14.292µs event Readable | Writable Token(37748741) loop process - 1 events, 0.000s Conn::read_head read 221 bytes Request.parse([Header; 100], [u8; 221]) Request.parse Complete(221) maybe_literal not found, copying "Keep-Alive" parsed 6 headers (221 bytes) incoming body is content-length (0 bytes) expecting_continue(version=Http11, header=None) = false should_keep_alive(version=Http11, header=Some(Connection([KeepAlive]))) = true read_keep_alive; is_mid_message=true should_keep_alive(version=Http11, header=None) = true Server::encode has_body=true, method=Some(Get) encoding chunked 456B flushed 552 bytes scheduling Read for: 5 maybe_notify; read_from_io blocked flushed State { reading: Init, writing: Init, keep_alive: Idle, error: None } wants_read_again? false loop poll - 1.029584ms loop time - Instant { tv_sec: 95294, tv_nsec: 784267438 } loop process, 30.041µs event Readable | Writable Token(37748741) loop process - 1 events, 0.000s Conn::read_head read 0 bytes parse eof State::close_read() read eof read_keep_alive; is_mid_message=true flushed State { reading: Closed, writing: Init, keep_alive: Disabled, error: None } wants_read_again? false shut down IO deregistering handle with poller dropping I/O source: 5 loop poll - 3.45025ms loop time - Instant { tv_sec: 95294, tv_nsec: 787758229 } loop process, 149.917µs event Readable | Writable Token(25165828) loop process - 1 events, 0.000s attempting to decode a frame frame decoded from buffer attempting to decode a frame scheduling Read for: 4 flushing framed transport framed transport flushed loop poll - 36.223542ms loop time - Instant { tv_sec: 95294, tv_nsec: 824210438 } loop process, 977.375µs kMessageTypeLoad "Pixel 5" bef8fafb0a447e65096fe138edfc2255a38241a7 255618645 1608720869112 State: context_uri: "spotify:user:spotify:playlist:37i9dQZEVXcGXovc8hM96I" index: 0 position_ms: 398190 status: kPlayStatusPause position_measured_at: 1608720870298 context_description: "" shuffle: false repeat: true playing_from_fallback: true row: 0 playing_track_index: 0 track {gid: "\256\350\376\350\243\017M\315\204\376b\324\306\356\003\367"} track {gid: "'\032\330\"^{I\377\202\025\321\372\320\223\344\r"} track {gid: "|\323\226y\2555OG\251R\373\323\006m\252\367"} track {gid: "M \363\267\364\300@W\211\024\020\216\235\032OA"} track {gid: "\037\240\276\177\334\206J8\222\377E\231\005.\365\210"} track {gid: "\275\363e\206\312\361K\370\262*\016\334\311\342T\327"} track {gid: "P`\251\312\2008A\207\277\027\tB\202\316\337\221"} track {gid: "re\241\355\023gG\326\227\220\240\350\313\347IC"} track {gid: "\204\0241\373h\324J\001\2554\263\243\311\177%\311"} track {gid: "\304\313\376u.\253B\322\251S\037F\247\316zV"} track {gid: "\316Td%/\363Il\207\226y\301.\327\372\325"} track {gid: "\341\206\340\227\345`N\261\237\003\342l\317\355\362\035"} track {gid: "C\273\331v\355\004Ag\214!\352\243\r{\201\345"} track {gid: "G7\005\227\217\367D\345\217\312\231TZM\337\240"} track {gid: "\225\317\352)\027\322D_\2102_\032\272q\314|"} track {gid: "\037W=\024\026\206D\315\200\020\001\203\252\370T\335"} track {gid: "\342(\023\343\232\266D\273\251\000\037N\004U8\361"} track {gid: "\357'[\235\307kAR\276\322\001?\233^\235I"} track {gid: "?\201\366\023\326\222D\320\215\315g\017\0034\034x"} track {gid: "\243\022\307\0064\007By\215\364\344\327{\221e\374"} track {gid: "\274E\024\"\"\212M\207\260\027\036`\207^\\\332"} track {gid: "\364\r\007Bw\263C\324\236\230@\355V\345\377\240"} track {gid: "0d\202\370\2229I%\247\242%3bkHo"} track {gid: "\027=\337\r\304\360F\354\220\216>\261!\353|4"} track {gid: "\300W_\233,oG\334\255$\272\202\230\341\334^"} track {gid: "p\372\222\344O\020J\343\263]\177N)*8S"} track {gid: "x\353\221\202\361\013Fb\202p\345\335{\314=\027"} track {gid: "v\377\320\2109\n@\357\211\013\3146\222}\301\014"} track {gid: "\321^\266\343\271\025A\235\270b\021\350\022\375b\201"} track {gid: "1\315\243\346>\023N\206\253]]'\222\246@\037"} Frame has 30 tracks Loading context: index: [0] of 30 command=Load(SpotifyId { id: 232495454301193030630253895377182655479, audio_type: Track }, false, 398190) scheduling Read for: 4 flushing framed transport writing; remaining=1168 framed transport flushed loop poll - 1.722ms loop time - Instant { tv_sec: 95294, tv_nsec: 833381604 } loop process, 656.834µs event Readable | Writable Token(25165828) loop process - 1 events, 0.000s attempting to decode a frame frame decoded from buffer attempting to decode a frame scheduling Read for: 4 flushing framed transport framed transport flushed loop poll - 16.333042ms loop time - Instant { tv_sec: 95294, tv_nsec: 850702521 } loop process, 130.083µs kMessageTypeNotify "Pixel 5" bef8fafb0a447e65096fe138edfc2255a38241a7 255618715 1608720870318 loop poll - 12.25µs loop time - Instant { tv_sec: 95294, tv_nsec: 851176479 } loop process, 126.584µs event Readable | Writable Token(25165828) loop process - 1 events, 0.000s attempting to decode a frame scheduling Read for: 4 flushing framed transport framed transport flushed loop poll - 15.846833ms loop time - Instant { tv_sec: 95294, tv_nsec: 867211146 } loop process, 42.292µs event Readable | Writable Token(4194305) loop process - 1 events, 0.000s received packet from 192.168.178.50:5353 scheduling Read for: 1 scheduling Read for: 1 sending packet to 224.0.0.251:5353 scheduling Read for: 2 loop poll - 14.790125ms loop time - Instant { tv_sec: 95294, tv_nsec: 882069521 } loop process, 44.333µs event Readable | Writable Token(4194305) loop process - 1 events, 0.000s received packet from 192.168.178.70:5353 received packet from 192.168.178.70:5353 with no query scheduling Read for: 1 scheduling Read for: 1 scheduling Read for: 2 loop poll - 400.166µs loop time - Instant { tv_sec: 95294, tv_nsec: 882540854 } loop process, 35µs event Writable Token(4194305) loop process - 1 events, 0.000s event Readable | Writable Token(25165828) loop process - 1 events, 0.000s attempting to decode a frame frame decoded from buffer attempting to decode a frame frame decoded from buffer attempting to decode a frame scheduling Read for: 4 flushing framed transport framed transport flushed loop poll - 14.975625ms loop time - Instant { tv_sec: 95294, tv_nsec: 897568979 } loop process, 44.042µs loop poll - 13.417µs loop time - Instant { tv_sec: 95294, tv_nsec: 897716563 } loop process, 36.75µs Loading with Spotify URI scheduling Read for: 4 flushing framed transport writing; remaining=830 framed transport flushed loop poll - 1.295583ms loop time - Instant { tv_sec: 95294, tv_nsec: 899065229 } loop process, 43.167µs event Readable | Writable Token(25165828) loop process - 1 events, 0.000s event Readable | Writable Token(25165828) loop process - 1 events, 0.000s attempting to decode a frame attempting to decode a frame frame decoded from buffer attempting to decode a frame frame decoded from buffer attempting to decode a frame attempting to decode a frame frame decoded from buffer attempting to decode a frame attempting to decode a frame scheduling Read for: 4 flushing framed transport framed transport flushed event Writable Token(25165828) loop process - 1 events, 0.000s loop poll - 34.981333ms loop time - Instant { tv_sec: 95294, tv_nsec: 934115396 } loop process, 296.917µs event Readable | Writable Token(25165828) loop process - 1 events, 0.000s event Readable | Writable Token(25165828) loop process - 1 events, 0.000s attempting to decode a frame frame decoded from buffer attempting to decode a frame attempting to decode a frame event Readable | Writable Token(25165828) loop process - 1 events, 0.000s frame decoded from buffer attempting to decode a frame frame decoded from buffer attempting to decode a frame attempting to decode a frame event Readable | Writable Token(25165828) loop process - 1 events, 0.000s event Readable | Writable Token(25165828) loop process - 1 events, 0.000s frame decoded from buffer event Readable | Writable Token(25165828) loop process - 1 events, 0.000s attempting to decode a frame frame decoded from buffer attempting to decode a frame attempting to decode a frame frame decoded from buffer attempting to decode a frame frame decoded from buffer attempting to decode a frame scheduling Read for: 4 flushing framed transport framed transport flushed loop poll - 31.409ms loop time - Instant { tv_sec: 95294, tv_nsec: 965893938 } loop process, 43.75µs new AudioKeyManager Downloading file a60dacdbb5aadd077420c4f6ff04a36ac69746be new ChannelManager scheduling Read for: 4 flushing framed transport writing; remaining=102 framed transport flushed loop poll - 2.430458ms loop time - Instant { tv_sec: 95294, tv_nsec: 968394396 } loop process, 42.583µs consuming notification queue loop poll - 62.708µs loop time - Instant { tv_sec: 95294, tv_nsec: 968526229 } loop process, 35µs event Readable | Writable Token(25165828) loop process - 1 events, 0.000s attempting to decode a frame frame decoded from buffer attempting to decode a frame attempting to decode a frame frame decoded from buffer event Readable | Writable Token(25165828) loop process - 1 events, 0.000s attempting to decode a frame attempting to decode a frame attempting to decode a frame frame decoded from buffer attempting to decode a frame attempting to decode a frame frame decoded from buffer attempting to decode a frame attempting to decode a frame frame decoded from buffer attempting to decode a frame frame decoded from buffer attempting to decode a frame scheduling Read for: 4 flushing framed transport framed transport flushed loop poll - 43.677083ms loop time - Instant { tv_sec: 95295, tv_nsec: 12253479 } loop process, 45.209µs consuming notification queue Ping time estimated as: 44 ms. loop poll - 307.416µs loop time - Instant { tv_sec: 95295, tv_nsec: 12633229 } loop process, 39.667µs event Readable | Writable Token(25165828) loop process - 1 events, 0.000s attempting to decode a frame frame decoded from buffer attempting to decode a frame scheduling Read for: 4 flushing framed transport framed transport flushed loop poll - 28.694209ms loop time - Instant { tv_sec: 95295, tv_nsec: 41386938 } loop process, 23.625µs Normalisation Data: NormalisationData { track_gain_db: -8.599998, track_peak: 1.0203071, album_gain_db: -9.220001, album_peak: 1.0723367 } Applied normalisation factor: 0.3715353 Caught panic with message: attempted to zero-initialize type `librespot_tremor::tremor_sys::ov_callbacks`, which is invalid drop Player[0] loop poll - 788.667µs loop time - Instant { tv_sec: 95295, tv_nsec: 42215563 } loop process, 33.833µs loop poll - 15.167µs loop time - Instant { tv_sec: 95295, tv_nsec: 42332521 } loop process, 16.042µs event Readable | Writable Token(4194305) loop process - 1 events, 0.000s received packet from 192.168.178.50:5353 scheduling Read for: 1 scheduling Read for: 1 scheduling Read for: 2 loop poll - 520.185001ms loop time - Instant { tv_sec: 95295, tv_nsec: 562540855 } loop process, 22.75µs event Readable | Writable Token(25165828) loop process - 1 events, 0.000s attempting to decode a frame frame decoded from buffer attempting to decode a frame scheduling Read for: 4 flushing framed transport framed transport flushed loop poll - 112.047125ms loop time - Instant { tv_sec: 95295, tv_nsec: 674627063 } loop process, 22.167µs kMessageTypePlay "Pixel 5" bef8fafb0a447e65096fe138edfc2255a38241a7 255619562 1608720870374 Caught panic with message: called `Result::unwrap()` on an `Err` value: "SendError(..)" drop Spirc[0] Shutting down player thread ... Player thread panicked! drop Session[0] drop AudioKeyManager drop ChannelManager drop MercuryManager shutdown; state=pool::State { lifecycle: Running, num_futures: 0 } -> transitioned to shutdown -> shutting down workers dropping I/O source: 3 deregistering handle with poller dropping I/O source: 0 deregistering handle with poller dropping I/O source: 1 deregistering handle with poller dropping I/O source: 2 drop Dispatch deregistering handle with poller dropping I/O source: 4 ```

Compilation flags

  • dbus_mpris
  • dbus_keyring
  • alsa_backend
  • portaudio_backend
  • pulseaudio_backend
  • rodio_backend

Versions (please complete the following information):

  • OS: Debian 10 aarch64 on Linux 4.4.213-rockchip64
  • Spotifyd: 0.2.24
  • cargo: 1.48.0 (65cbdd2dc 2020-10-14)

Additional info that might be helpful.
It might be necessary to set a proper device and control which I tried a couple of combinations but was not successful.

aplay -L
default
    Playback/recording through the PulseAudio sound server
null
    Discard all samples (playback) or generate zero samples (capture)
jack
    JACK Audio Connection Kit
pulse
    PulseAudio Sound Server
sysdefault:CARD=HDMICODEC
    HDMI-CODEC, ff8a0000.i2s-i2s-hifi i2s-hifi-0
    Default Audio Device
dmix:CARD=HDMICODEC,DEV=0
    HDMI-CODEC, ff8a0000.i2s-i2s-hifi i2s-hifi-0
    Direct sample mixing device
dsnoop:CARD=HDMICODEC,DEV=0
    HDMI-CODEC, ff8a0000.i2s-i2s-hifi i2s-hifi-0
    Direct sample snooping device
hw:CARD=HDMICODEC,DEV=0
    HDMI-CODEC, ff8a0000.i2s-i2s-hifi i2s-hifi-0
    Direct hardware device without any conversions
plughw:CARD=HDMICODEC,DEV=0
    HDMI-CODEC, ff8a0000.i2s-i2s-hifi i2s-hifi-0
    Hardware device with all software conversions
usbstream:CARD=HDMICODEC
    HDMI-CODEC
    USB Stream Output
pactl list
Modul #0
	Name: module-device-restore
	Argument: 
	Nutzungszähler: k. A.
	Eigenschaften:
		module.author = "Lennart Poettering"
		module.description = "Automatically restore the volume/mute state of devices"
		module.version = "12.2"

Modul #1
	Name: module-stream-restore
	Argument: 
	Nutzungszähler: k. A.
	Eigenschaften:
		module.author = "Lennart Poettering"
		module.description = "Automatically restore the volume/mute/device state of streams"
		module.version = "12.2"

Modul #2
	Name: module-card-restore
	Argument: 
	Nutzungszähler: k. A.
	Eigenschaften:
		module.author = "Lennart Poettering"
		module.description = "Automatically restore profile of cards"
		module.version = "12.2"

Modul #3
	Name: module-augment-properties
	Argument: 
	Nutzungszähler: k. A.
	Eigenschaften:
		module.author = "Lennart Poettering"
		module.description = "Augment the property sets of streams with additional static information"
		module.version = "12.2"

Modul #4
	Name: module-switch-on-port-available
	Argument: 
	Nutzungszähler: k. A.
	Eigenschaften:
		module.author = "David Henningsson"
		module.description = "Switches ports and profiles when devices are plugged/unplugged"
		module.version = "12.2"

Modul #5
	Name: module-udev-detect
	Argument: tsched=0
	Nutzungszähler: k. A.
	Eigenschaften:
		module.author = "Lennart Poettering"
		module.description = "Detect available audio hardware and load matching drivers"
		module.version = "12.2"

Modul #6
	Name: module-alsa-card
	Argument: device_id="0" name="platform-hdmi-codec" card_name="alsa_card.platform-hdmi-codec" namereg_fail=false tsched=no fixed_latency_range=no ignore_dB=no deferred_volume=yes use_ucm=yes card_properties="module-udev-detect.discovered=1"
	Nutzungszähler: 0
	Eigenschaften:
		module.author = "Lennart Poettering"
		module.description = "ALSA Card"
		module.version = "12.2"

Modul #7
	Name: module-native-protocol-unix
	Argument: 
	Nutzungszähler: k. A.
	Eigenschaften:
		module.author = "Lennart Poettering"
		module.description = "Native protocol (UNIX sockets)"
		module.version = "12.2"

Modul #8
	Name: module-gsettings
	Argument: 
	Nutzungszähler: k. A.
	Eigenschaften:
		module.author = "Sylvain Baubeau"
		module.description = "GSettings Adapter"
		module.version = "12.2"

Modul #9
	Name: module-default-device-restore
	Argument: 
	Nutzungszähler: k. A.
	Eigenschaften:
		module.author = "Lennart Poettering"
		module.description = "Automatically restore the default sink and source"
		module.version = "12.2"

Modul #10
	Name: module-rescue-streams
	Argument: 
	Nutzungszähler: k. A.
	Eigenschaften:
		module.author = "Lennart Poettering"
		module.description = "When a sink/source is removed, try to move its streams to the default sink/source"
		module.version = "12.2"

Modul #11
	Name: module-always-sink
	Argument: 
	Nutzungszähler: k. A.
	Eigenschaften:
		module.author = "Colin Guthrie"
		module.description = "Hält stets ein Ziel geladen, selbst wenn dies ein Null-Ziel ist"
		module.version = "12.2"

Modul #12
	Name: module-intended-roles
	Argument: 
	Nutzungszähler: k. A.
	Eigenschaften:
		module.author = "Lennart Poettering"
		module.description = "Automatically set device of streams based on intended roles of devices"
		module.version = "12.2"

Modul #13
	Name: module-suspend-on-idle
	Argument: 
	Nutzungszähler: k. A.
	Eigenschaften:
		module.author = "Lennart Poettering"
		module.description = "When a sink/source is idle for too long, suspend it"
		module.version = "12.2"

Modul #14
	Name: module-console-kit
	Argument: 
	Nutzungszähler: k. A.
	Eigenschaften:
		module.author = "Lennart Poettering"
		module.description = "Create a client for each ConsoleKit session of this user"
		module.version = "12.2"

Modul #15
	Name: module-systemd-login
	Argument: 
	Nutzungszähler: k. A.
	Eigenschaften:
		module.author = "Lennart Poettering"
		module.description = "Create a client for each login session of this user"
		module.version = "12.2"

Modul #16
	Name: module-position-event-sounds
	Argument: 
	Nutzungszähler: k. A.
	Eigenschaften:
		module.author = "Lennart Poettering"
		module.description = "Position event sounds between L and R depending on the position on screen of the widget triggering them."
		module.version = "12.2"

Modul #17
	Name: module-role-cork
	Argument: 
	Nutzungszähler: k. A.
	Eigenschaften:
		module.author = "Lennart Poettering"
		module.description = "Mute & cork streams with certain roles while others exist"
		module.version = "12.2"

Modul #18
	Name: module-filter-heuristics
	Argument: 
	Nutzungszähler: k. A.
	Eigenschaften:
		module.author = "Colin Guthrie"
		module.description = "Detect when various filters are desirable"
		module.version = "12.2"

Modul #19
	Name: module-filter-apply
	Argument: 
	Nutzungszähler: k. A.
	Eigenschaften:
		module.author = "Colin Guthrie"
		module.description = "Load filter sinks automatically when needed"
		module.version = "12.2"

Modul #20
	Name: module-x11-publish
	Argument: display=:0
	Nutzungszähler: k. A.
	Eigenschaften:
		module.author = "Lennart Poettering"
		module.description = "X11 credential publisher"
		module.version = "12.2"

Modul #21
	Name: module-x11-cork-request
	Argument: display=:0
	Nutzungszähler: k. A.
	Eigenschaften:
		module.author = "Lennart Poettering"
		module.description = "Synthesize X11 media key events when cork/uncork is requested"
		module.version = "12.2"

Modul #22
	Name: module-x11-xsmp
	Argument: display=:0 session_manager=local/station-p1:@/tmp/.ICE-unix/24269,unix/station-p1:/tmp/.ICE-unix/24269
	Nutzungszähler: k. A.
	Eigenschaften:
		module.author = "Lennart Poettering"
		module.description = "X11 session management"
		module.version = "12.2"

Ziel #0
	Status: SUSPENDED
	Name: alsa_output.platform-hdmi-codec.stereo-fallback
	Beschreibung: Internes Audio Stereo
	Treiber: module-alsa-card.c
	Abtastwert-Angabe: s16le 2ch 44100Hz
	Kanalzuordnung: front-left,front-right
	Besitzer-Modul: 6
	Stumm: nein
	Lautstärke: front-left: 65971 / 101% / 0,17 dB,   front-right: 65971 / 101% / 0,17 dB
	        Verteilung 0,00
	Basis-Lautstärke: 65536 / 100% / 0,00 dB
	Quellen-Monitor: alsa_output.platform-hdmi-codec.stereo-fallback.monitor
	Latenz: 0 usec, eingestellt 0 usec
	Flags: HARDWARE DECIBEL_VOLUME LATENCY 
	Eigenschaften:
		alsa.resolution_bits = "16"
		device.api = "alsa"
		device.class = "sound"
		alsa.class = "generic"
		alsa.subclass = "generic-mix"
		alsa.name = "ff8a0000.i2s-i2s-hifi i2s-hifi-0"
		alsa.id = "ff8a0000.i2s-i2s-hifi i2s-hifi-0"
		alsa.subdevice = "0"
		alsa.subdevice_name = "subdevice #0"
		alsa.device = "0"
		alsa.card = "0"
		alsa.card_name = "HDMI-CODEC"
		alsa.long_card_name = "HDMI-CODEC"
		device.bus_path = "platform-hdmi-codec"
		sysfs.path = "/devices/platform/hdmi-codec/sound/card0"
		device.form_factor = "internal"
		device.string = "hw:0"
		device.buffering.buffer_size = "17632"
		device.buffering.fragment_size = "4408"
		device.access_mode = "mmap"
		device.profile.name = "stereo-fallback"
		device.profile.description = "Stereo"
		device.description = "Internes Audio Stereo"
		module-udev-detect.discovered = "1"
		device.icon_name = "audio-card"
	Ports:
		analog-output: Analoge Ausgabe (priority: 9900)
	Aktiver Port: analog-output
	Formate:
		pcm

Quelle #0
	Status: SUSPENDED
	Name: alsa_output.platform-hdmi-codec.stereo-fallback.monitor
	Beschreibung: Monitor of Internes Audio Stereo
	Treiber: module-alsa-card.c
	Abtastwert-Angabe: s16le 2ch 44100Hz
	Kanalzuordnung: front-left,front-right
	Besitzer-Modul: 6
	Stumm: nein
	Lautstärke: front-left: 65536 / 100% / 0,00 dB,   front-right: 65536 / 100% / 0,00 dB
	        Verteilung 0,00
	Basis-Lautstärke: 65536 / 100% / 0,00 dB
	Ziel-Monitor: alsa_output.platform-hdmi-codec.stereo-fallback
	Latenz: 0 usec, eingestellt 0 usec
	Flags: DECIBEL_VOLUME LATENCY 
	Eigenschaften:
		device.description = "Monitor of Internes Audio Stereo"
		device.class = "monitor"
		alsa.card = "0"
		alsa.card_name = "HDMI-CODEC"
		alsa.long_card_name = "HDMI-CODEC"
		device.bus_path = "platform-hdmi-codec"
		sysfs.path = "/devices/platform/hdmi-codec/sound/card0"
		device.form_factor = "internal"
		device.string = "0"
		module-udev-detect.discovered = "1"
		device.icon_name = "audio-card"
	Formate:
		pcm

Client #1
	Treiber: module-systemd-login.c
	Owner-Modul: 15
	Eigenschaften:
		application.name = "Login Session 246"
		systemd-login.session = "246"

Client #2
	Treiber: protocol-native.c
	Owner-Modul: 7
	Eigenschaften:
		application.name = "mate-settings-daemon"
		native-protocol.peer = "UNIX socket client"
		native-protocol.version = "32"
		application.process.id = "24339"
		application.process.user = "p1"
		application.process.host = "station-p1"
		application.process.binary = "mate-settings-daemon"
		application.language = "de_DE.UTF-8"
		window.x11.display = ":0"
		application.process.machine_id = "c2fef1cbef224d2ba587622b5f874e8d"
		application.process.session_id = "246"

Client #6
	Treiber: module-x11-xsmp.c
	Owner-Modul: 22
	Eigenschaften:
		application.name = "XSMP Session on mate-session-manager as 1036cefd2fbdc23b1160870129298050800000242690026"
		xsmp.vendor = "mate-session-manager"
		xsmp.client.id = "1036cefd2fbdc23b1160870129298050800000242690026"

Client #7
	Treiber: protocol-native.c
	Owner-Modul: 7
	Eigenschaften:
		application.name = "MATE-Lautstärkeregleranzeige"
		native-protocol.peer = "UNIX socket client"
		native-protocol.version = "32"
		application.id = "org.mate.VolumeControlApplet"
		application.icon_name = "multimedia-volume-control"
		application.version = "1.20.2"
		application.process.id = "24429"
		application.process.user = "p1"
		application.process.host = "station-p1"
		application.process.binary = "mate-volume-control-applet"
		application.language = "de_DE.UTF-8"
		window.x11.display = ":0"
		application.process.machine_id = "c2fef1cbef224d2ba587622b5f874e8d"
		application.process.session_id = "246"

Client #31
	Treiber: protocol-native.c
	Owner-Modul: 7
	Eigenschaften:
		application.name = "Firefox"
		native-protocol.peer = "UNIX socket client"
		native-protocol.version = "32"
		application.process.id = "29079"
		application.process.user = "p1"
		application.process.host = "station-p1"
		application.process.binary = "firefox-esr"
		application.language = "de_DE.UTF-8"
		window.x11.display = ":0"
		application.process.machine_id = "c2fef1cbef224d2ba587622b5f874e8d"
		application.process.session_id = "246"
		application.icon_name = "firefox-esr"

Client #69
	Treiber: protocol-native.c
	Owner-Modul: 7
	Eigenschaften:
		application.name = "Lautstärkeregler"
		native-protocol.peer = "UNIX socket client"
		native-protocol.version = "32"
		application.id = "org.mate.VolumeControl"
		application.icon_name = "multimedia-volume-control"
		application.version = "1.20.2"
		application.process.id = "8409"
		application.process.user = "p1"
		application.process.host = "station-p1"
		application.process.binary = "mate-volume-control"
		application.language = "de_DE.UTF-8"
		window.x11.display = ":0"
		application.process.machine_id = "c2fef1cbef224d2ba587622b5f874e8d"
		application.process.session_id = "246"

Client #73
	Treiber: protocol-native.c
	Owner-Modul: 7
	Eigenschaften:
		application.name = "pactl"
		native-protocol.peer = "UNIX socket client"
		native-protocol.version = "32"
		application.process.id = "8526"
		application.process.user = "p1"
		application.process.host = "station-p1"
		application.process.binary = "pactl"
		application.language = "de_DE.UTF-8"
		window.x11.display = ":0"
		application.process.machine_id = "c2fef1cbef224d2ba587622b5f874e8d"
		application.process.session_id = "246"

Karte #0
	Name: alsa_card.platform-hdmi-codec
	Treiber: module-alsa-card.c
	Owner-Modul: 6
	Eigenschaften:
		alsa.card = "0"
		alsa.card_name = "HDMI-CODEC"
		alsa.long_card_name = "HDMI-CODEC"
		device.bus_path = "platform-hdmi-codec"
		sysfs.path = "/devices/platform/hdmi-codec/sound/card0"
		device.form_factor = "internal"
		device.string = "0"
		device.description = "Internes Audio"
		module-udev-detect.discovered = "1"
		device.icon_name = "audio-card"
	Profile:
		output:stereo-fallback: Stereo-Ausgabe (Ziele: 1, Quellen: 0, Priorität: 5100, verfügbar: ja)
		output:multichannel-output: Mehrkanal-Ausgabe (Ziele: 1, Quellen: 0, Priorität: 100, verfügbar: ja)
		off: Aus (Ziele: 0, Quellen: 0, Priorität: 0, verfügbar: ja)
	Aktives Profil: output:stereo-fallback
	Ports:
		analog-output: Analoge Ausgabe (priority: 9900, latency offset: 0 usec)
			Teil der/des Profil(s): output:stereo-fallback
		multichannel-output: Mehrkanalausgang (priority: 0, latency offset: 0 usec)
			Teil der/des Profil(s): output:multichannel-output

@EvilOlaf EvilOlaf added the bug A functionality or parts of a program that do not work as intended label Dec 23, 2020
@shatteringlass
Copy link

Should be a duplicate of #719

@EvilOlaf
Copy link
Author

EvilOlaf commented Jan 5, 2021

Retried building with rust 1.47 but unfortunately failed the same way.
Also tried with 1.51-nightly just for the heck of it but no success either.

@DoppleDankster
Copy link

Getting the same problem. my output is slightly more verbose :

Loading < SONG-TITLE > with Spotify URI <spotify:track:SOME-ID>
Caught panic with message: attempted to zero-initialize type `librespot_tremor::tremor_sys::ov_callbacks`, which is invalid
Caught panic with message: called `Result::unwrap()` on an `Err` value: "SendError(..)"
Player thread panicked!
  • version : spotiftyd-git from the AUR
  • platform: x86
  • version: full (features)
  • complete config file: (NB: had to enclose all the string vars in " " cause of known issue with the toml format on the current ver)
username = ""
password = ""
backend = "pulseaudio"
device_name = "desktop"
device_type = "computer"
bitrate = 320

the deamon does start properly, i can connect to it from spotify-tui but playing anything will make it panic.

@Icelk
Copy link
Contributor

Icelk commented Jan 7, 2021

@DoppleDankster Your problem should be a duplicate of #719
Try downgrading Rust to 1.47 or use the official “spotifyd” package.
Hope your issue gets resolved.

@DoppleDankster
Copy link

@IsELK downgraded to 1.47, got a different panick.

BUT ! when passing the config using command line arguments it worked as intended 👍

@Icelk
Copy link
Contributor

Icelk commented Jan 8, 2021

@DoppleDankster How good! Have a nice weekend.

@robinvd
Copy link
Contributor

robinvd commented Jan 12, 2021

@DoppleDankster that sounds like #698

@Icelk
Copy link
Contributor

Icelk commented Mar 12, 2021

@EvilOlaf Is this still a problem?

@EvilOlaf
Copy link
Author

Did not further investigate since I mostly use my Pinebook Pro now instead of the ROC RK3399 PC PLUS.
Oddly it works nicely on the PBP even though both devices are built around the same SoC....

@Icelk
Copy link
Contributor

Icelk commented Mar 12, 2021

Weird. I ran it successfully with same config and features on my x64 system.

Should we close this issue?

@geertmeersman
Copy link

I think it can be closed indeed. Works fine now since the last releases.

@EvilOlaf
Copy link
Author

Weird. I ran it successfully with same config and features on my x64 system.

Should we close this issue?

You know aarch64 != amd64, right?

@robinvd robinvd closed this as completed Mar 12, 2021
@robinvd
Copy link
Contributor

robinvd commented Mar 12, 2021

With the new release this should be fixed, but if anyone still has the issue on 0.3.2 then we can reopen this

@Icelk
Copy link
Contributor

Icelk commented Mar 12, 2021

@EvilOlaf

You know aarch64 != amd64, right?

Yes, I am aware. I was just making it clear I wasn’t using aarch64.

@EvilOlaf
Copy link
Author

Then nevermind 😀

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug A functionality or parts of a program that do not work as intended
Projects
None yet
Development

No branches or pull requests

6 participants