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

Spotifyd crashes after update (to 0.3.0) #765

Closed
wazabees opened this issue Jan 13, 2021 · 15 comments
Closed

Spotifyd crashes after update (to 0.3.0) #765

wazabees opened this issue Jan 13, 2021 · 15 comments
Assignees
Labels
bug A functionality or parts of a program that do not work as intended wontfix Issues that will not be fixed under any circumstances

Comments

@wazabees
Copy link

wazabees commented Jan 13, 2021


Hijacking for visibility: Make sure to update to the new TOML config file format (see README) when using 0.3.0!!!
Edited by @sirwindfield


Description
spotifyd does not start after updating from version 0.2.24 to 0.2.25. Downgrading to 0.2.24 works.

Expected behavior
For spotifyd to launch in the background withour errors.

Logs

Click to show logs journalctl log
Jan 13 09:06:40 arch systemd[945]: Started A spotify playing daemon.
Jan 13 09:06:40 arch spotifyd[10656]: Loading config from "/home/username/.config/spotifyd/spotifyd.conf"
Jan 13 09:06:40 arch spotifyd[10656]: thread 'main' panicked at 'called `Result::unwrap()` on an `Err` value: Error { inner: ErrorInner { kind: NumberInvalid, line: Some(2), col: 11, at: Some(49), message: "", key: [] } }', src/config.rs:468:67
Jan 13 09:06:40 arch spotifyd[10656]: note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace
Jan 13 09:06:40 arch systemd[945]: spotifyd.service: Main process exited, code=exited, status=101/n/a

Disabling the systemd unit and running manually:

╰─❯ spotifyd --verbose
thread 'main' panicked at 'called `Result::unwrap()` on an `Err` value: Error { inner: ErrorInner { kind: NumberInvalid, line: Some(2), col: 11, at: Some(49), message: "", key: [] } }', src/config.rs:468:67
note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace

Versions (please complete the following information):

  • OS: Arch linux, 5.10.6-arch1-1
  • Spotifyd: 0.2.25
  • cargo: 1.49.0

Comments:
The Arch linux package has a bug report here, that looks like the same issue:
https://bugs.archlinux.org/task/69308?project=5&string=spotifyd

The bug report on Arch also points to #719

@wazabees wazabees added the bug A functionality or parts of a program that do not work as intended label Jan 13, 2021
@JojiiOfficial
Copy link
Member

Thats probably an issue which will affect most of the upgraded clients. Upgrade your config file to the format shown on the readme. We have added a breaking change to this release so parsing configs will fail if you used the old version in combination with a config file.

@JojiiOfficial JojiiOfficial pinned this issue Jan 13, 2021
@JojiiOfficial JojiiOfficial changed the title thread main panicked Spotifyd crashes after update Jan 13, 2021
@robinvd robinvd changed the title Spotifyd crashes after update Spotifyd crashes after update (to 0.2.25) Jan 13, 2021
@wazabees
Copy link
Author

wazabees commented Jan 13, 2021

I updated my config file according to the readme and it would seem initial_volume = 90 also needs quotes:

╰─❯ spotifyd --verbose
thread 'main' panicked at 'called `Result::unwrap()` on an `Err` value: Error { inner: ErrorInner { kind: Custom, line: Some(64), col: 17, at: Some(1937), message: "invalid type: integer `90`, expected a string", key: ["global", "initial_volume"] } }', src/config.rs:468:67
note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace

After my update, I was able to get spotifyd running, but I am now seeing other errors. I use spotify-tui and I started a track playing. There was no audio. Then I switched to a different track and spotifyd crashed.I do not know if it's related to this report. Log below, and I have redacted some of the information (I think).

Click to show logs

╰─❯ spotifyd --verbose --no-daemon
Loading config from "/home/username/.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: Some("/home/username/.cache/spotifyd/"), no-audio-cache: false, backend: Some(Alsa), volume_controller: None, device: Some("hw:3,0"), control: Some("hw:3,0"), mixer: Some("hardware"), device_name: Some("Spotifyd"), bitrate: Some(Bitrate320), initial_volume: None, volume_normalisation: false, normalisation_pregain: None, zeroconf_port: Some(1234), proxy: None, device_type: Some(Computer) } }
Found user shell: Some("/usr/bin/zsh")
No proxy specified
registering with poller
registering with poller
registering with poller
registering with poller
registering with poller
registering with poller
registering with poller
registering with poller
registering with poller
registering with poller
registering with poller
registering with poller
registering with poller
registering with poller
registering with poller
registering with poller
build; num-workers=16
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:1234
adding I/O source: 4194305
registering with poller
event Writable Token(4194305)
loop process - 1 events, 0.000s
adding I/O source: 8388610
registering with poller
event Writable Token(8388610)
loop process - 1 events, 0.000s
adding I/O source: 12582915
registering with poller
park; waiting for idle connection: "http://apresolve.spotify.com"
Http::connect("http://apresolve.spotify.com/")
consuming notification queue
event Writable Token(12582915)
scheduling Read for: 0
resolving host="apresolve.spotify.com", port=80
loop process - 1 events, 0.000s
scheduling Read for: 1
sending packet to 224.0.0.251:5353
event Readable | Writable Token(4194305)
loop process - 1 events, 0.000s
scheduling Read for: 2
sending packet to [ff02::fb]:5353
event Readable | Writable Token(4194305)
loop process - 1 events, 0.000s
event Readable | Writable Token(8388610)
loop process - 1 events, 0.000s
scheduling Read for: 3
loop poll - 361.631µs
loop time - Instant { tv_sec: 37708, tv_nsec: 446940519 }
loop process, 4.031µs
received packet from ...:5353
received packet from ...:5353 with no query
scheduling Read for: 1
scheduling Read for: 1
received packet from [...]:5353
received packet from [...]:5353 with no query
scheduling Read for: 2
scheduling Read for: 2
loop poll - 24.266µs
loop time - Instant { tv_sec: 37708, tv_nsec: 446971016 }
loop process, 4.062µs
event Writable Token(8388610)
loop process - 1 events, 0.000s
loop poll - 402.237µs
loop time - Instant { tv_sec: 37708, tv_nsec: 447378842 }
loop process, 6.706µs
connecting to 34.98.74.57:80
adding I/O source: 16777220
registering with poller
scheduling Write for: 4
event Writable Token(16777220)
loop process - 1 events, 0.000s
loop poll - 23.88975ms
loop time - Instant { tv_sec: 37708, tv_nsec: 471325024 }
loop process, 10.384µs
read_keep_alive; is_mid_message=false
scheduling Read for: 4
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 - 58.076µs
loop time - Instant { tv_sec: 37708, tv_nsec: 471412493 }
loop process, 3.954µs
event Readable | Writable Token(16777220)
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.213833ms
loop time - Instant { tv_sec: 37708, tv_nsec: 500632335 }
loop process, 9.618µs
Conn::read_body
decode; state=Length(0)
incoming body completed
scheduling Read for: 4
maybe_notify; read_from_io blocked
read_keep_alive; is_mid_message=false
scheduling Read for: 4
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 - 64.728µs
loop time - Instant { tv_sec: 37708, tv_nsec: 500738237 }
loop process, 8.906µs
Connecting to AP "gew1-accesspoint-e-l0np.ap.spotify.com:443"
adding I/O source: 20971525
registering with poller
scheduling Write for: 5
read_keep_alive; is_mid_message=false
scheduling Read for: 4
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: 4
signal: Closed
loop poll - 175.432µs
loop time - Instant { tv_sec: 37708, tv_nsec: 572503152 }
loop process, 14.673µs
event Writable Token(20971525)
loop process - 1 events, 0.000s
loop poll - 43.493538ms
loop time - Instant { tv_sec: 37708, tv_nsec: 616018440 }
loop process, 42.845µs
scheduling Read for: 5
event Readable | Writable Token(20971525)
loop process - 1 events, 0.000s
loop poll - 44.969772ms
loop time - Instant { tv_sec: 37708, tv_nsec: 681441459 }
loop process, 43.128µs
flushing framed transport
writing; remaining=136
framed transport flushed
scheduling Read for: 5
event Readable | Writable Token(20971525)
loop process - 1 events, 0.000s
event Readable | Writable Token(20971525)
loop process - 1 events, 0.000s
loop poll - 135.475557ms
loop time - Instant { tv_sec: 37708, tv_nsec: 836897185 }
loop process, 33.571µs
attempting to decode a frame
frame decoded from buffer
Authenticated as "username" !
new Session[0]
new Spirc[0]
new MercuryManager
input volume:65535 to mixer: 65535
new Player[0]
Using alsa sink
attempting to decode a frame
frame decoded from buffer
Session[0] strong=4 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: "SE"
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: 5
flushing framed transport
writing; remaining=854
framed transport flushed
loop poll - 358.75µs
loop time - Instant { tv_sec: 37708, tv_nsec: 837962171 }
loop process, 13.833µs
event Readable | Writable Token(20971525)
loop process - 1 events, 0.000s
attempting to decode a frame
frame decoded from buffer
attempting to decode a frame
scheduling Read for: 5
flushing framed transport
framed transport flushed
loop poll - 46.120124ms
loop time - Instant { tv_sec: 37708, tv_nsec: 884102548 }
loop process, 21.78µs
event Readable | Writable Token(20971525)
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: 5
flushing framed transport
framed transport flushed
loop poll - 5.262361ms
loop time - Instant { tv_sec: 37708, tv_nsec: 889395592 }
loop process, 19.897µs
subscribed uri=hm://remote/user/username/ count=0
loop poll - 4.067µs
loop time - Instant { tv_sec: 37708, tv_nsec: 889460710 }
loop process, 17.713µs
event Readable | Writable Token(20971525)
loop process - 1 events, 0.000s
attempting to decode a frame
frame decoded from buffer
attempting to decode a frame
scheduling Read for: 5
flushing framed transport
framed transport flushed
loop poll - 47.330279ms
loop time - Instant { tv_sec: 37708, tv_nsec: 936813916 }
loop process, 15.297µs
Modify_watch: Watch { fd: 59, read: true, write: false }, poll_now: false
adding I/O source: 25165828
registering with poller
Dropping AConnection
scheduling Read for: 4
scheduling Read for: 4
D-Bus i/o poll ready: 59 is NotReady
handle_msgs: (Signal, Some("/org/freedesktop/DBus"), Some("org.freedesktop.DBus"), Some("NameAcquired"))
handle_msgs: (Signal, Some("/org/freedesktop/DBus"), Some("org.freedesktop.DBus"), Some("NameAcquired"))
loop poll - 101.546µs
loop time - Instant { tv_sec: 37708, tv_nsec: 939432044 }
loop process, 17.103µs
event Readable | Writable Token(8388610)
loop process - 1 events, 0.000s
scheduling Read for: 1
received packet from [...]:5353
received packet from [...]:5353 with no query
scheduling Read for: 2
scheduling Read for: 2
loop poll - 33.279520327s
loop time - Instant { tv_sec: 37742, tv_nsec: 218976283 }
loop process, 24.542µs
event Readable | Writable Token(8388610)
loop process - 1 events, 0.000s
scheduling Read for: 1
received packet from [...]:5353
received packet from [...]:5353 with no query
scheduling Read for: 2
scheduling Read for: 2
loop poll - 7.945184017s
loop time - Instant { tv_sec: 37750, tv_nsec: 164195574 }
loop process, 22.159µs
event Readable | Writable Token(8388610)
loop process - 1 events, 0.000s
scheduling Read for: 1
received packet from [...]:5353
received packet from [...]:5353 with no query
scheduling Read for: 2
scheduling Read for: 2
loop poll - 8.0219537s
loop time - Instant { tv_sec: 37758, tv_nsec: 186184362 }
loop process, 22.828µs
event Readable | Writable Token(8388610)
loop process - 1 events, 0.000s
scheduling Read for: 1
received packet from [...]:5353
received packet from [...]:5353 with no query
scheduling Read for: 2
scheduling Read for: 2
loop poll - 8.005869229s
loop time - Instant { tv_sec: 37766, tv_nsec: 192089049 }
loop process, 22.739µs
event Readable | Writable Token(20971525)
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: 5
flushing framed transport
framed transport flushed
loop poll - 11.90799605s
loop time - Instant { tv_sec: 37778, tv_nsec: 100123313 }
loop process, 19µs
Polling message stream
msgstream found Ok(Ready(Some((Signal, Some("/org/freedesktop/DBus"), Some("org.freedesktop.DBus"), Some("NameAcquired")))))
Unhandled DBus message: (Signal, Some("/org/freedesktop/DBus"), Some("org.freedesktop.DBus"), Some("NameAcquired"))
Polling message stream
msgstream found Ok(Ready(Some((Signal, Some("/org/freedesktop/DBus"), Some("org.freedesktop.DBus"), Some("NameAcquired")))))
Unhandled DBus message: (Signal, Some("/org/freedesktop/DBus"), Some("org.freedesktop.DBus"), Some("NameAcquired"))
Polling message stream
msgstream found Ok(NotReady)
kMessageTypeLoad "" webapi-51a6e61d21864d4e96966284938391b8 2068033883 1610533216412
State: context_uri: "spotify:playlist:4fXzb5BGHZcCY0X75LyGVT" index: 8 position_ms: 0 status: kPlayStatusPlay position_measured_at: 1610533285624 context_description: "Loved Tracks" shuffle: false repeat: false playing_from_fallback: true row: 0 playing_track_index: 8 track {gid: "\357P\315\026\305\330A$\207\273\337\2740\256\236u"} track {gid: "\277\372u\330\264\214@\323\240\363\272+\241\2703\323"} track {gid: "0\256\354\222\346MI\324\215\223\241\264\217\014\340\236"} track {gid: "\366S\256\367\211\030D\335\241\344\221sjJm\370"} track {gid: "T(\275[$\230D\360\241&!\023:\032\277E"} track {gid: "k(!\277\203zIK\213\315&\006\331\177\004y"} track {gid: "\010\177\251\ti\354I\327\210\313\274\221i\346\255\324"} track {gid: "\326\325Y\271\213YI\t\266w\322\261\202\303\370h"} track {gid: "j\236f\343\303\352E\334\203N\202\351\000j\357Y"} track {gid: "\253h\334:\3730E_\211I\367x\355Z\336?"} track {gid: "\255\217\315\233\216\214F\300\227/d\313Y)o\353"} track {gid: " \257\334E\243}B0\207S\272o\"\034a\212"} track {gid: "\220\362'\350$\315E\000\201\354\027#\242\231E4"} track {gid: "Qe\022\021\272\214O]\205VTw\236\374\256\225"} track {gid: "\264\225\030HO\351M\363\231\302\346\346i-M\020"} track {gid: "\210\245~$+\344HA\272\t\0106\225c\350\343"} track {gid: "\303\352'\227\244\376M\035\252\006\337\245+\244W1"} track {gid: "\367\364Q\267M\002Ma\241\220<\347\263|g\341"} track {gid: "\260\036\230z\322jL\224\245\340\243\312\200z\334\224"} track {gid: "\215\026\250G,\230@{\222;\327-\3250\323\217"} track {gid: "\327\356\213\246\211\025M\371\223J\220\332\301\372\332R"} track {gid: "a\344\r\276\252'M\\\276q1\016\232\320H\177"} track {gid: "|\363I\235\241\032L\253\217kD\271|\030\343,"} track {gid: "\345\313V\371\026\303@\367\240\332=\363e'\036|"} track {gid: "\311\014\264;\334\252IC\236\275\217\n\316^H#"} track {gid: "\212Y\245`\220zD\264\250#\216}\001\336!B"} track {gid: "\225\341\212&9jE+\234\030B\356\261\257K\334"} track {gid: "\372=\022X\3626G \225\026\365\257_\037]\033"} track {gid: "\313\202f\361\327\353I\004\262$\226\346\004@\026\020"} track {gid: "Z\201W\030z|I\275\207\023u\343R\321\264\266"} track {gid: "jOQ8\217\267KB\2339\255A\3146wM"} track {gid: "\010\203\3021\\uK\242\222\207(\0210\223w\177"} track {gid: "1\366\006\"\016\354J\301\255\216\272U\021\n\222\033"} track {gid: "$\225x\306\371\rM\377\234\311\236\024\010r\310t"} track {gid: "\340U.\025\246\\D}\227Y\3055&\177\207\003"} track {gid: "\314)\343\366\rjK\343\245\350i\205\334\000\204\344"} track {gid: "C\036\274\035p\027@\310\267\356\262C1\225\010\016"} track {gid: "\263Vr\323\252\221N\206\241\336\037N\322bI\223"} track {gid: "hh=\014\242\374A\207\217\004\341\374,\224\033="} track {gid: "\336\376\\\021\213\303O\327\246c8|\376^\345\306"} track {gid: "\251QP\312r\272H\211\240\250\207\364#C\275\210"} track {gid: "5(]\224L\024D\371\215\030{e\343\216|\312"} track {gid: "@M\343`=\016Mk\235 \343\301\034\3421-"} track {gid: "/\330J\364I8If\220\370)\304\263j\037\376"} track {gid: "\327\345\010\273O\233M#\225\326=$\344\311\362\353"} track {gid: "?\201\366\226\335HI&\244\313\307\r\322,{("} track {gid: "n\332@\312F1O`\233=)\274\255\330\200P"} track {gid: "\224A\227\006\361\376L\201\201\326\361h\220J\247\255"} track {gid: "\310\367\204U \245D\305\224\256\311\2212\261\211|"} track {gid: "S\323\\3\177\345IV\227[_VIM\030\""} track {gid: "\355\316\274\305\033\254Jn\251\342\003!\304\377\300`"} track {gid: "\335\205a\324D\361G\232\214 /\264\375\241\356\253"} track {gid: "\0043\032#?_B\340\234\256\0062H0\300\303"} track {gid: "\266\244\020\037\215\212D\201\261\211\\>z\225\202\341"} track {gid: "\300\351\317\310/\247EK\237\006oS\266<<\021"} track {gid: "\326\024w\277^\266K\356\242\356\351\003(\270\335x"} track {gid: "Z:G\344\264\320B\277\213\207P|\215\251vF"} track {gid: ";\2610\340\354\314C\264\240\255\240\026\355_\006\313"} track {gid: "\221sd\271\270\021G\257\215\214`\221\216\345nP"} track {gid: "\277:\315@\020\002M\257\210\322J\005\355F\260\021"} track {gid: "+e\016@-\207D\004\233N<O\307\006\357i"} track {gid: "\016\031\323\335\370\326M\371\210V\232\350L\001T\305"} track {gid: "\236\352\332@m\346@\033\247\253\0305\262!+\361"} track {gid: "\233\345-\315\356\236G\203\201\035\237\033\305Y\301\315"} track {gid: "\204\277\224\221\306\253O\366\257\016~\360\217\023A5"} track {gid: "$\330OE-\310C\313\204\362v\010\367?\317\341"} track {gid: ",\256\363\r\267@Eh\240\301\350h\361\223\344 "} track {gid: "P\314*\"\304GJ\351\230T<P\007\352\274\216"} track {gid: "\006\213\240Sv\007NW\2056\252\242\261\034?\317"} track {gid: "\243\363U\311\255\365G\252\271\362\0075\3424\236\324"} track {gid: "\265\314\251\t4\360N\\\243D\363\323\377\235\272\036"} track {gid: "\313\244\340IU\364Lg\252\323cC\306\003X\233"} track {gid: "g3H}\206\226J}\224*\ra\355MVo"} track {gid: "\247\237{e\002QF.\250\036l$\201\240Ws"} track {gid: "|\261\300\020\225\260I\277\254%\320%\377\"\024\330"} track {gid: "A82\312\004\001M=\262\r\252\017\257\330\215<"} track {gid: "\034\345\177\243\254cB\310\247\335\263\213\t\200\2477"} track {gid: "\031\201\234\221\235\341E\231\217J\330\014C_\256a"} track {gid: "^{dn\273\234D\231\206u\322T\031R\243\264"} track {gid: "\361\367W\260\367\031M\264\245\352\177d\354\035;^"} track {gid: "(e\210R\247}D\372\240\302*\372\362wK-"} track {gid: "\374\r\234\tR\tD\237\270-\364\225A \2215"} track {gid: "\247\271\262d\271^C\370\205\\\000\350\214\241;\221"} track {gid: "T\345\312\261.\004NX\245\226=}\375\014\371\300"} track {gid: "\014k\303}\352sG\030\2462\242H\212\361\247M"} track {gid: "}\301\327\272X\322BD\207\322\260LIM|/"} track {gid: "\315\032YMm*BC\226\215\266/\025\327\313\376"} track {gid: "%w\257\237\211\333E\304\267\214W\205\376\221\251:"} track {gid: "tk\345;\225oA\256\224\007\014\372p\\\002\006"}
Frame has 89 tracks
Loading context: <spotify:playlist:4fXzb5BGHZcCY0X75LyGVT> index: [8] of 89
command=Load(SpotifyId { id: 141720637308054843969484012818073841497, audio_type: Track }, true, 0)
scheduling Read for: 5
flushing framed transport
writing; remaining=2371
framed transport flushed
loop poll - 150.029µs
loop time - Instant { tv_sec: 37778, tv_nsec: 101359056 }
loop process, 19.851µs
event Readable | Writable Token(20971525)
loop process - 1 events, 0.000s
attempting to decode a frame
frame decoded from buffer
attempting to decode a frame
scheduling Read for: 5
flushing framed transport
framed transport flushed
loop poll - 38.488773ms
loop time - Instant { tv_sec: 37778, tv_nsec: 139877062 }
loop process, 22.886µs
Loading <Barrel Roll> with Spotify URI <spotify:track:3fbzKcWaLyY4ZNhnyhuBDP>
new AudioKeyManager
scheduling Read for: 5
flushing framed transport
writing; remaining=49
framed transport flushed
loop poll - 366.953µs
loop time - Instant { tv_sec: 37778, tv_nsec: 140278920 }
loop process, 14.951µs
File 605862b7fadf277a0e0d4c614877b76ee9e31cb4 already in cache
event Readable | Writable Token(20971525)
loop process - 1 events, 0.000s
attempting to decode a frame
frame decoded from buffer
attempting to decode a frame
scheduling Read for: 5
flushing framed transport
framed transport flushed
loop poll - 36.253364ms
loop time - Instant { tv_sec: 37778, tv_nsec: 176555337 }
loop process, 18.471µs
Polling message stream
msgstream found Ok(NotReady)
loop poll - 3.79µs
loop time - Instant { tv_sec: 37778, tv_nsec: 176626212 }
loop process, 15.744µs
event Readable | Writable Token(20971525)
loop process - 1 events, 0.000s
attempting to decode a frame
frame decoded from buffer
attempting to decode a frame
scheduling Read for: 5
flushing framed transport
framed transport flushed
loop poll - 81.60628ms
loop time - Instant { tv_sec: 37778, tv_nsec: 258253677 }
loop process, 22.82µs
Normalisation Data: NormalisationData { track_gain_db: -8.779999, track_peak: 1.0450463, album_gain_db: -9.690002, album_peak: 1.0726554 }
Applied normalisation factor: 0.3639151
Caught panic with message: attempted to zero-initialize type `librespot_tremor::tremor_sys::ov_callbacks`, which is invalid
drop Player[0]
loop poll - 3.294939ms
loop time - Instant { tv_sec: 37778, tv_nsec: 261582801 }
loop process, 42.647µs
Polling message stream
msgstream found Ok(NotReady)
loop poll - 16.19714704s
loop time - Instant { tv_sec: 37794, tv_nsec: 458823197 }
loop process, 41.404µs
loop poll - 3.967944703s
loop time - Instant { tv_sec: 37798, tv_nsec: 426820785 }
loop process, 41.221µs
loop poll - 19.943968ms
loop time - Instant { tv_sec: 37798, tv_nsec: 446817702 }
loop process, 31.867µs
loop poll - 3.552µs
loop time - Instant { tv_sec: 37798, tv_nsec: 446861979 }
loop process, 10.723µs
event Readable | Writable Token(8388610)
loop process - 1 events, 0.000s
scheduling Read for: 1
received packet from [...]:5353
received packet from [...]:5353 with no query
scheduling Read for: 2
scheduling Read for: 2
loop poll - 11.618719175s
loop time - Instant { tv_sec: 37810, tv_nsec: 65596972 }
loop process, 18.264µs
^[[B^[[Bevent Readable | Writable Token(20971525)
loop process - 1 events, 0.000s
attempting to decode a frame
frame decoded from buffer
attempting to decode a frame
scheduling Read for: 5
flushing framed transport
framed transport flushed
loop poll - 7.18675834s
loop time - Instant { tv_sec: 37817, tv_nsec: 252386657 }
loop process, 15.417µs
Polling message stream
msgstream found Ok(NotReady)
kMessageTypeLoad "" webapi-... 2068073025 1610533285669
State: context_uri: "spotify:playlist:..." index: 10 position_ms: 0 status: kPlayStatusPlay position_measured_at: 1610533324776 context_description: "Loved Tracks" shuffle: false repeat: false playing_from_fallback: true row: 0 playing_track_index: 10 track {gid: "k(!\277\203zIK\213\315&\006\331\177\004y"} track {gid: "\010\177\251\ti\354I\327\210\313\274\221i\346\255\324"} track {gid: "\326\325Y\271\213YI\t\266w\322\261\202\303\370h"} track {gid: "j\236f\343\303\352E\334\203N\202\351\000j\357Y"} track {gid: "\253h\334:\3730E_\211I\367x\355Z\336?"} track {gid: "\255\217\315\233\216\214F\300\227/d\313Y)o\353"} track {gid: " \257\334E\243}B0\207S\272o\"\034a\212"} track {gid: "\220\362'\350$\315E\000\201\354\027#\242\231E4"} track {gid: "Qe\022\021\272\214O]\205VTw\236\374\256\225"} track {gid: "\264\225\030HO\351M\363\231\302\346\346i-M\020"} track {gid: "\210\245~$+\344HA\272\t\0106\225c\350\343"} track {gid: "\303\352'\227\244\376M\035\252\006\337\245+\244W1"} track {gid: "\367\364Q\267M\002Ma\241\220<\347\263|g\341"} track {gid: "\260\036\230z\322jL\224\245\340\243\312\200z\334\224"} track {gid: "\215\026\250G,\230@{\222;\327-\3250\323\217"} track {gid: "\327\356\213\246\211\025M\371\223J\220\332\301\372\332R"} track {gid: "a\344\r\276\252'M\\\276q1\016\232\320H\177"} track {gid: "|\363I\235\241\032L\253\217kD\271|\030\343,"} track {gid: "\345\313V\371\026\303@\367\240\332=\363e'\036|"} track {gid: "\311\014\264;\334\252IC\236\275\217\n\316^H#"} track {gid: "\212Y\245`\220zD\264\250#\216}\001\336!B"} track {gid: "\225\341\212&9jE+\234\030B\356\261\257K\334"} track {gid: "\372=\022X\3626G \225\026\365\257_\037]\033"} track {gid: "\313\202f\361\327\353I\004\262$\226\346\004@\026\020"} track {gid: "Z\201W\030z|I\275\207\023u\343R\321\264\266"} track {gid: "jOQ8\217\267KB\2339\255A\3146wM"} track {gid: "\010\203\3021\\uK\242\222\207(\0210\223w\177"} track {gid: "1\366\006\"\016\354J\301\255\216\272U\021\n\222\033"} track {gid: "$\225x\306\371\rM\377\234\311\236\024\010r\310t"} track {gid: "\340U.\025\246\\D}\227Y\3055&\177\207\003"} track {gid: "\314)\343\366\rjK\343\245\350i\205\334\000\204\344"} track {gid: "C\036\274\035p\027@\310\267\356\262C1\225\010\016"} track {gid: "\263Vr\323\252\221N\206\241\336\037N\322bI\223"} track {gid: "hh=\014\242\374A\207\217\004\341\374,\224\033="} track {gid: "\336\376\\\021\213\303O\327\246c8|\376^\345\306"} track {gid: "\251QP\312r\272H\211\240\250\207\364#C\275\210"} track {gid: "5(]\224L\024D\371\215\030{e\343\216|\312"} track {gid: "@M\343`=\016Mk\235 \343\301\034\3421-"} track {gid: "/\330J\364I8If\220\370)\304\263j\037\376"} track {gid: "\327\345\010\273O\233M#\225\326=$\344\311\362\353"} track {gid: "?\201\366\226\335HI&\244\313\307\r\322,{("} track {gid: "n\332@\312F1O`\233=)\274\255\330\200P"} track {gid: "\224A\227\006\361\376L\201\201\326\361h\220J\247\255"} track {gid: "\310\367\204U \245D\305\224\256\311\2212\261\211|"} track {gid: "S\323\\3\177\345IV\227[_VIM\030\""} track {gid: "\355\316\274\305\033\254Jn\251\342\003!\304\377\300`"} track {gid: "\335\205a\324D\361G\232\214 /\264\375\241\356\253"} track {gid: "\0043\032#?_B\340\234\256\0062H0\300\303"} track {gid: "\266\244\020\037\215\212D\201\261\211\\>z\225\202\341"} track {gid: "\300\351\317\310/\247EK\237\006oS\266<<\021"} track {gid: "\326\024w\277^\266K\356\242\356\351\003(\270\335x"} track {gid: "Z:G\344\264\320B\277\213\207P|\215\251vF"} track {gid: ";\2610\340\354\314C\264\240\255\240\026\355_\006\313"} track {gid: "\221sd\271\270\021G\257\215\214`\221\216\345nP"} track {gid: "\277:\315@\020\002M\257\210\322J\005\355F\260\021"} track {gid: "+e\016@-\207D\004\233N<O\307\006\357i"} track {gid: "\016\031\323\335\370\326M\371\210V\232\350L\001T\305"} track {gid: "\236\352\332@m\346@\033\247\253\0305\262!+\361"} track {gid: "\233\345-\315\356\236G\203\201\035\237\033\305Y\301\315"} track {gid: "\204\277\224\221\306\253O\366\257\016~\360\217\023A5"} track {gid: "$\330OE-\310C\313\204\362v\010\367?\317\341"} track {gid: ",\256\363\r\267@Eh\240\301\350h\361\223\344 "} track {gid: "P\314*\"\304GJ\351\230T<P\007\352\274\216"} track {gid: "\006\213\240Sv\007NW\2056\252\242\261\034?\317"} track {gid: "\243\363U\311\255\365G\252\271\362\0075\3424\236\324"} track {gid: "\265\314\251\t4\360N\\\243D\363\323\377\235\272\036"} track {gid: "\313\244\340IU\364Lg\252\323cC\306\003X\233"} track {gid: "g3H}\206\226J}\224*\ra\355MVo"} track {gid: "\247\237{e\002QF.\250\036l$\201\240Ws"} track {gid: "|\261\300\020\225\260I\277\254%\320%\377\"\024\330"} track {gid: "A82\312\004\001M=\262\r\252\017\257\330\215<"} track {gid: "\034\345\177\243\254cB\310\247\335\263\213\t\200\2477"} track {gid: "\031\201\234\221\235\341E\231\217J\330\014C_\256a"} track {gid: "^{dn\273\234D\231\206u\322T\031R\243\264"} track {gid: "\361\367W\260\367\031M\264\245\352\177d\354\035;^"} track {gid: "(e\210R\247}D\372\240\302*\372\362wK-"} track {gid: "\374\r\234\tR\tD\237\270-\364\225A \2215"} track {gid: "\247\271\262d\271^C\370\205\\\000\350\214\241;\221"} track {gid: "T\345\312\261.\004NX\245\226=}\375\014\371\300"} track {gid: "\014k\303}\352sG\030\2462\242H\212\361\247M"} track {gid: "}\301\327\272X\322BD\207\322\260LIM|/"} track {gid: "\315\032YMm*BC\226\215\266/\025\327\313\376"} track {gid: "%w\257\237\211\333E\304\267\214W\205\376\221\251:"} track {gid: "tk\345;\225oA\256\224\007\014\372p\\\002\006"} track {gid: "\007B\236\221\202\366K\374\264\362\372\021*\022\3311"} track {gid: "4Ym\275\335\235I\241\256\300\233h\300*\353H"} track {gid: "\327\037\276\366\210\022F\024\213\345W\327y\246\377$"} track {gid: "\304q\364\270y\030E\315\260\347\257\"s\357\270\010"} track {gid: "\033q<01m@\034\216\251\341C/\025\036\325"} track {gid: "\272,\207\262\343*Hj\250\007\252\265\357E\211\003"} track {gid: "U\007\225\215\016QF]\246\322N>,`$3"}
Frame has 91 tracks
Loading context: <spotify:playlist:...> index: [10] of 91
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 MercuryManager
Dropping AMessageStream
AMessageStream telling ADriver to quit
shutdown; state=pool::State { lifecycle: Running, num_futures: 0 }
  -> transitioned to shutdown
  -> shutting down workers
deregistering handle with poller
dropping I/O source: 0
dropping I/O source: 3
dropping I/O source: 4
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: 5


@robinvd
Copy link
Contributor

robinvd commented Jan 13, 2021

@wazabees #744 maybe?

@wazabees
Copy link
Author

@wazabees #744 maybe?

The bug report you linked is for 0.2.24 though, which worked perfectly and without errors for me. The error only appeared in 0.2.25 after updating my config file according to the readme.

@robinvd
Copy link
Contributor

robinvd commented Jan 13, 2021

the arch linux bug report you linked should be the same as #744, i think the user of that issue was compiling from master and thus already using new code (eventhough the report says 0.2.24)

@mainrs
Copy link
Member

mainrs commented Jan 14, 2021

Thats probably an issue which will affect most of the upgraded clients. Upgrade your config file to the format shown on the readme. We have added a breaking change to this release so parsing configs will fail if you used the old version in combination with a config file.

0.2.25 is a breaking change? Shouldn't the version be 0.3.0 then?

Edit: I always thought that this was inside the specification, but it seems it's not. "Anything can change at any time" is their wording. But I think that pumping the minor might still be a good idea to indicate a larger change and not just "a fix or patch".

@robinvd
Copy link
Contributor

robinvd commented Jan 14, 2021

0.2.25 is a breaking change? Shouldn't the version be 0.3.0 then?

That might have been better!,

maybe at some point we should bump it to 1.0 to promise a stable release as anything < 1.0 has to guaranties in semantic versioning

@mainrs
Copy link
Member

mainrs commented Jan 14, 2021

Ye, I always hesitated to bump to v1 as even the features that are available aren't complete or buggy (like MPRIS). If those are fixed I'd be happy to go for the v1 I think.

@robinvd
Copy link
Contributor

robinvd commented Jan 14, 2021

as we already released to crates.io im not sure if there is a way to reverse the release?

@mainrs
Copy link
Member

mainrs commented Jan 14, 2021

ye, you can yank releases on crates.io: https://doc.rust-lang.org/cargo/reference/publishing.html#cargo-yank. cargo will then ignore those releases when trying to install the crate.

@robinvd
Copy link
Contributor

robinvd commented Jan 14, 2021

also the newest CI job/tag is on the HEAD and not on the same commit as the crates.io release. So i think yanking the release and making a new release/tag on 0.3 might be a good idea

@mainrs
Copy link
Member

mainrs commented Jan 14, 2021

also the newest CI job/tag is on the HEAD and not on the same commit as the crates.io release. So i think yanking the release and making a new release/tag on 0.3 might be a good idea

Definitely!

@robinvd robinvd changed the title Spotifyd crashes after update (to 0.2.25) Spotifyd crashes after update (to 0.3.0) Jan 14, 2021
@robinvd
Copy link
Contributor

robinvd commented Jan 14, 2021

the 0.2.25 release is yanked from crates.io and from github releases, and a new crates.io/github release has been make. And the binaries are succesfully pushed by cd to the release page 🎉

@ghost
Copy link

ghost commented Jan 15, 2021

I updated my config file according to the readme and it would seem initial_volume = 90 also needs quotes:

╰─❯ spotifyd --verbose
thread 'main' panicked at 'called `Result::unwrap()` on an `Err` value: Error { inner: ErrorInner { kind: Custom, line: Some(64), col: 17, at: Some(1937), message: "invalid type: integer `90`, expected a string", key: ["global", "initial_volume"] } }', src/config.rs:468:67
note: run with `RUST_BACKTRACE=1` environment variable to display a backtrace

After my update, I was able to get spotifyd running, but I am now seeing other errors. I use spotify-tui and I started a track playing. There was no audio. Then I switched to a different track and spotifyd crashed.I do not know if it's related to this report. Log below, and I have redacted some of the information (I think).

Click to show logs

I deleted the client.yml file in .config/spotify-tui directory and reconfigured spotify-tui and it works fine

jackson15j added a commit to jackson15j/dot_files that referenced this issue Jan 26, 2021
Was hitting issue: Spotifyd/spotifyd#786 (real issue:
Spotifyd/spotifyd#765), but updating to the latest
configuration file
changes (https://spotifyd.github.io/spotifyd/config/File.html) fixed my
`spotifyd` service from running.
@robinvd robinvd self-assigned this Feb 15, 2021
wip-sync pushed a commit to NetBSD/pkgsrc-wip that referenced this issue Feb 22, 2021
Important, you'll like hit this [upstream issue][1] and see something
like:

```
thread 'main' panicked at 'called `Result::unwrap()` on an `Err` value:
Error { inner: ErrorInner { kind: Custom, line: Some(64), col: 17, at:
Some(1937), message: "invalid type: integer `90`, expected a string",
key: ["global", "initial_volume"] } }', src/config.rs:468:67
note: run with `RUST_BACKTRACE=1` environment variable to display a
backtrace
```

This is due to the config format changing and values needing quoting.

Adds a new patch [based on this PR][2].

[1]: Spotifyd/spotifyd#765
[2]: Spotifyd/spotifyd#796
@stale
Copy link

stale bot commented May 16, 2021

This issue has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs. Thank you for your contributions.

@stale stale bot added the wontfix Issues that will not be fixed under any circumstances label May 16, 2021
@stale stale bot closed this as completed May 27, 2021
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 wontfix Issues that will not be fixed under any circumstances
Projects
None yet
Development

No branches or pull requests

4 participants