Playing from artist often causes a crash

[kraxarn]

I'm trying to play music from an artist, for example by doing a call to the Web API using me/player/play with spotify:artist:70BYFdaZbEKbeauJ670ysI, although, any artist seem to cause issues. A couple of tracks usually play fine, but after a short while, librespot seems to crash pretty consistently with a similar error message each time:

thread 'main' panicked at 'attempt to subtract with overflow', core/src/spotify_id.rs:121:20

Only happens when playing from any artist, anything else seems to work just fine. Playing from artist works poorly in general, as it only seems to play a few tracks, maybe related?

stack_backtrace.log

[Johannesd3]

Maybe you'd like to try out my proposed fix

[kraxarn]

Thanks for the fast response, but I'm still experiencing issues. Got this error now instead:

thread 'main' panicked at 'index out of bounds: the len is 19 but the index is 18446744073709551612', core/src/spotify_id.rs:122:12

[Johannesd3]

I'm sorry if it wasn't clear, but you should test https://github.com/Johannesd3/librespot/tree/fix-integer-overflow

You're experiencing another error probably because you turned release mode on, which disables integer overflow checks.

[kraxarn]

Oh yeah, oops. I checked out your fork, but failed to notice it still checked out the dev branch :sweat_smile: Seems to work fine, but I still have the issue of it only playing a few tracks from the artist, but maybe that's a separate issue.

[Johannesd3]

Try to run it with RUST_LOG=DEBUG environment variable and look out for Malformed or no gid, attempting to parse URI <...>. I'm curious what these angle brackets contain.

[Johannesd3]

According to your stack trace, this message must appear every time shortly before crashes (would have crashed previously). Try the same on dev, and if it crashes without showing this message, I'll have to investigate further.

[kraxarn]

Sorry for being unclear, it doesn't crash anymore, or at least haven't yet. The issue now is that it doesn't play all tracks from an artist. While running with RUST_LOG=DEBUG, I found this in the log:

[2021-05-27T14:26:02Z DEBUG librespot_connect::spirc] Frame has 24 tracks
...
[2021-05-27T14:26:32Z DEBUG librespot_connect::spirc] At track 1 of 24 <"spotify:artist:70BYFdaZbEKbeauJ670ysI"> update [false]

so it thinks there are only 24 tracks, and after they are done playing, it just stops the playback. 2 of them are even duplicates, so there are really only 22 tracks.

[Johannesd3]

Yes, I know that it doesn't crash anymore. But the functions that calls the function that used to crash prints this debug message. If it doesn't appear, the function isn't called anymore, probably. But I touched only the crashing function itself, in particular it should be called exactly as many times as before. Would you please verify that the unfixed version still crashes, and whether this log message is shown before the crash?

[kraxarn]

Seems like these issues are related. First thing I noticed was

[2021-05-27T14:52:17Z DEBUG librespot_connect::spirc] Frame has 63 tracks

which means the unfixed version finds 63 tracks, but also, it crashed after the 24th track with

[2021-05-27T14:52:50Z DEBUG librespot_connect::spirc] Malformed or no gid, attempting to parse URI <spotify:meta:page:2>

so it seems like there's a paging issue and the "fixed" version only includes the first page.

[Johannesd3]

I can't imagine this little fix changed the behaviour. Is it possible that it depends on some other factor?

[kraxarn]

Weird, you're right. Just tried it again and the fixed version found 63 tracks now, how odd. When it gets to the 25th track, instead of crashing, it just skips everything:

[2021-05-27T15:09:03Z DEBUG librespot_connect::spirc] At track 24 of 63 <"spotify:artist:70BYFdaZbEKbeauJ670ysI"> update [false]
[2021-05-27T15:09:03Z DEBUG librespot_connect::spirc] Malformed or no gid, attempting to parse URI <spotify:meta:page:2>
[2021-05-27T15:09:03Z WARN  librespot_connect::spirc] Skipping track <uri: "spotify:meta:page:2"> at position [24] of 63
...
[2021-05-27T15:09:03Z DEBUG librespot_connect::spirc] Malformed or no gid, attempting to parse URI <spotify:meta:page:40>
[2021-05-27T15:09:03Z WARN  librespot_connect::spirc] Skipping track <uri: "spotify:meta:page:40"> at position [62] of 63

After that, it repeats from the beginning again. Not sure what I did differently.

[Johannesd3]

I'm no expert here. Maybe @ashthespy knows more.

[ashthespy]

Just dumped the frame -- librespot is being quite robust here!

[2021-05-28T13:49:58Z DEBUG librespot_connect::spirc] Frame has 62 tracks

is a bit of stretch, when you look at the actual frame:

State: context_uri: "spotify:artist:70BYFdaZbEKbeauJ670ysI" index: 0 position_ms: 0 status: kPlayStatusPlay position_measured_at: 1622209798991 context_description: "Shinedown" shuffle: false repeat: false playing_from_fallback: true row: 0 playing_
track_index: 0 
track {gid: "\234\260\322\354\266I@\361\225{\263\331\242J]\230"} 
track {gid: "\024k\202\205.\nHx\213*\371\317\024W\257g"} 
track {gid: "K\022\265\320x\000O&\244\252\014\366(&\r\343"} 
track {gid: "\204~]\323\235\367F\277\274d\301\3375j\317E"} 
track {gid: ".\362\216c!\221Eo\232H\241L\367T\250\212"} 
track {gid: "\036\322{\013kYL\225\204\000\270\271\275\\k\372"} 
track {gid: ")\002\261\033\177\214F\231\203V${\024)\000\013"} 
track {gid: "<J\360\002\004\327N;\203>\216\225:b\014\266"} 
track {gid: "\241\345\273\275\025\304L\204\205?\371-\372\342\215U"} 
track {gid: "=\317u\237\340\207A\014\211\245\"\207nkeu"} 
track {gid: "6h\014B\005\215D\263\271\322\272t\351\202\235\236"} 
track {gid: "K\022\265\320x\000O&\244\252\014\366(&\r\343"} 
track {gid: "\262\342>\022\227\023J\245\244\027f\356\346j\211D"} 
track {gid: "\037\271\001\275\2013N2\262@\254\"\336\314\356D"} 
track {gid: "\371\323\021\2011\230@\234\242\252o\026\270\036\334\236"} 
track {gid: "l\245\010\3570\'Df\213M\004\330\260\245\340\336"} 
track {gid: ".\362\216c!\221Eo\232H\241L\367T\250\212"} 
track {gid: "\240\343\260K\332\367Aq\252\377\317\252\021\341Tt"} 
track {gid: "\312WC{A\220G\204\262\371\240\224\220~\002\020"} 
track {gid: "\341\267ikC\313L\255\227\303\256Xh\245A\266"} 
track {gid: ";\3018\377\"\243M]\235\210\251\371=\204G\331"} 
track {gid: "\020\236\242\205x\313@\270\2224\013F\375\350\3559"} 
track {gid: "\3013.\310\215\351DJ\262\t\342p\245\365\226 "} 
track {gid: "\350\210c\365\250bH\300\230x\237\251\237\200\242\363"} 
track {uri: "spotify:meta:page:2"} 
track {uri: "spotify:meta:page:3"} 
track {uri: "spotify:meta:page:4"} 
track {uri: "spotify:meta:page:5"} 
track {uri: "spotify:meta:page:6"} 
track {uri: "spotify:meta:page:7"} 
track {uri: "spotify:meta:page:8"} 
track {uri: "spotify:meta:page:9"} 
track {uri: "spotify:meta:page:10"} 
track {uri: "spotify:meta:page:11"} 
track {uri: "spotify:meta:page:12"} 
track {uri: "spotify:meta:page:13"} 
track {uri: "spotify:meta:page:14"} 
track {uri: "spotify:meta:page:15"} 
track {uri: "spotify:meta:page:16"} 
track {uri: "spotify:meta:page:17"} 
track {uri: "spotify:meta:page:18"} 
track {uri: "spotify:meta:page:19"} 
track {uri: "spotify:meta:page:20"} 
track {uri: "spotify:meta:page:21"} 
track {uri: "spotify:meta:page:22"} 
track {uri: "spotify:meta:page:23"} 
track {uri: "spotify:meta:page:24"} 
track {uri: "spotify:meta:page:25"} 
track {uri: "spotify:meta:page:26"} 
track {uri: "spotify:meta:page:27"} 
track {uri: "spotify:meta:page:28"} 
track {uri: "spotify:meta:page:29"} 
track {uri: "spotify:meta:page:30"} 
track {uri: "spotify:meta:page:31"} 
track {uri: "spotify:meta:page:32"} 
track {uri: "spotify:meta:page:33"} 
track {uri: "spotify:meta:page:34"} 
track {uri: "spotify:meta:page:35"} 
track {uri: "spotify:meta:page:36"} 
track {uri: "spotify:meta:page:37"} 
track {uri: "spotify:meta:page:38"} 
track {uri: "spotify:meta:page:39"}
[2021-05-28T13:49:58Z DEBUG librespot_connect::spirc] Frame has 62 tracks

Will have to investigate what the official client does to fetch more of the "popular" tracks after the initial few in the frame.

[ashthespy]

Looks like we need to query some other endpoint for the rest of the tracks in the frame - from a quick look, it might be /tracks/contains?ids=xx

-- with librespot -- with desktop client

[roderickvd]

@ashthespy I'm not so experienced with doing MITM on Spotify, but if you could point me into the right direction what the xx in /tracks/contains?ids=xx might be then I shouldn't have too much trouble implementing that.

For the record I can still reproduce this with this artist radio: https://open.spotify.com/artist/70BYFdaZbEKbeauJ670ysI?si=oZOKG3aUSAOWv2qOjvVLPw&dl_branch=1

[ashthespy]

@roderickvd I'm not near my dev machine for a few days, and my memory isn't what it used to be :| will get back to you soon! Edit: IIRC id is just the base64 part of the uri. eg 7Fg4jpwpkdkGCvq1rrXnvx for spotify:track:7Fg4jpwpkdkGCvq1rrXnvx

[roderickvd]

Sure but an URI like spotify:meta:page:2 puzzles me because it misses the context?

[ashthespy]

Well, that is because we don't handle any pagination -- so ideally you would fetch the rest of tracks from the updated context/or this other endpoint, excluding the current ids.

To be very honest, I am on thin ice here, I haven't looked at things in a long long while...

[roderickvd]

@sashahilton00 was talking about pagination on Gitter too. I'm just trying to grasp how I should implement that. In the current context state I see elements like row and index, is that something I can use to move the list forward? Or when using /tracks/contains?ids=xx then concretely which ids would I specify with the example frame in https://github.com/librespot-org/librespot/issues/765#issuecomment-850439438?

Sorry if I seem pedantic :smile: just trying to get the hang of this.

[ashthespy]

It's been a while, so I might be wrong here add a pinch of healthy scepticism ;-)

playing_from_fallback: true -- that gives us the first clue, since we are on the old API, server sends a Frame with only a few "fallback" tracks.

But it looks like the desktop client does something different -- after the first 24 tracks, it adds more tracks by the same artist This is different than our current flow, which essentially boils down to hm:autoplay-enabled that yields spotify:station:artist:70BYFdaZbEKbeauJ670ysI. This would then populate a station (dynamic playlist) with multiple artists.

I fear this might be something that needs the new API and digging into @devgianlu's reverse engineering..