librespot-java
librespot-java copied to clipboard
Tracks skip or crash with CDN Expiration warning in log
Describe the bug Tracks stop playing suddenly and playback either stops or moves to the next track. In the logs, an error is noted "Couldn't extract expiration"
To Reproduce It is intermittent, as only some of the CDN URL's seem to be using this format. It typically takes no less than 3-4 songs to encounter, but has been as long as 20.
Expected behavior Expiration value should be parsed correctly and chunk should not be prevented from loading
Screenshots/Stracktraces/Logs 2023-10-20 09:01:26,819 WARN CdnManager:187 - Couldn't extract expiration, invalid parameter in CDN url: https://audio4-gm-fb.spotifycdn.com/audio/0f...cf?Expires=1697904086~FullPath~hmac=fTI...Q=
Version/Commit 1.6.4-SNAPSHOT from dev branch
I've submitted a PR that updates the CDN manager code and have been running it locally without issue: https://github.com/librespot-org/librespot-java/pull/736
Just for reference in case others are seeing it as a related problem: It appears Spotify is also screwing with their CDNs and there is at least one which is using the wrong cert for the host name (or returning its actual name instead of the load balanced one):
Hostname audio4-gm-fb.spotifycdn.com not verified: certificate: sha256/mikb4l8fq5rYJv+AdSiChROLrTKpCEENcVFH4engaDw= DN: CN=audio-gm-off.spotifycdn.com subjectAltNames: [audio-gm-off.spotifycdn.com]
Not sure how to fix this one, hopefully they notice and clean up the mess.
Yes, my playlist stops playing every song or so. Logs show SSL verification errors. Indeed same audio4-gm host as in above post.
2023-10-21 21:39:34,146 ERROR Player:395 - Failed retrieving chunk, playback failed!
Oct 21 21:39:34 rpi4 java[177919]: xyz.gianlu.librespot.audio.AbsChunkedInputStream$ChunkException: javax.net.ssl.SSLPeerUnverifiedException: Hostname audio4-gm->
Oct 21 21:39:34 rpi4 java[177919]: certificate: sha256/mikb4l8fq5rYJv+AdSiChROLrTKpCEENcVFH4engaDw=
Oct 21 21:39:34 rpi4 java[177919]: DN: CN=audio-gm-off.spotifycdn.com
Oct 21 21:39:34 rpi4 java[177919]: subjectAltNames: [audio-gm-off.spotifycdn.com]
Oct 21 21:39:34 rpi4 java[177919]: at xyz.gianlu.librespot.audio.cdn.CdnManager$Streamer.requestChunk(CdnManager.java:322) ~[librespot-java-api-v1.6.3.ja>
Oct 21 21:39:34 rpi4 java[177919]: at xyz.gianlu.librespot.audio.cdn.CdnManager$Streamer.access$1500(CdnManager.java:198) ~[librespot-java-api-v1.6.3.jar>
Oct 21 21:39:34 rpi4 java[177919]: at xyz.gianlu.librespot.audio.cdn.CdnManager$Streamer$InternalStream.lambda$requestChunkFromStream$0(CdnManager.java:3>
Oct 21 21:39:34 rpi4 java[177919]: at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128) [?:?]
Oct 21 21:39:34 rpi4 java[177919]: at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628) [?:?]
Oct 21 21:39:34 rpi4 java[177919]: at java.lang.Thread.run(Thread.java:829) [?:?]
Caused by: javax.net.ssl.SSLPeerUnverifiedException: Hostname audio4-gm-fb.spotifycdn.com not verified:
Oct 21 21:39:34 rpi4 java[177919]: certificate: sha256/mikb4l8fq5rYJv+AdSiChROLrTKpCEENcVFH4engaDw=
Oct 21 21:39:34 rpi4 java[177919]: DN: CN=audio-gm-off.spotifycdn.com
Oct 21 21:39:34 rpi4 java[177919]: subjectAltNames: [audio-gm-off.spotifycdn.com]
Oct 21 21:39:34 rpi4 java[177919]: at okhttp3.internal.connection.RealConnection.connectTls(RealConnection.kt:389) ~[librespot-java-api-v1.6.3.jar:1.6.4->
Oct 21 21:39:34 rpi4 java[177919]: at okhttp3.internal.connection.RealConnection.establishProtocol(RealConnection.kt:337) ~[librespot-java-api-v1.6.3.jar>
Oct 21 21:39:34 rpi4 java[177919]: at okhttp3.internal.connection.RealConnection.connect(RealConnection.kt:209) ~[librespot-java-api-v1.6.3.jar:1.6.4-SNA>
Oct 21 21:39:34 rpi4 java[177919]: at okhttp3.internal.connection.ExchangeFinder.findConnection(ExchangeFinder.kt:226) ~[librespot-java-api-v1.6.3.jar:1.>
Oct 21 21:39:34 rpi4 java[177919]: at okhttp3.internal.connection.ExchangeFinder.findHealthyConnection(ExchangeFinder.kt:106) ~[librespot-java-api-v1.6.3>
Oct 21 21:39:34 rpi4 java[177919]: at okhttp3.internal.connection.ExchangeFinder.find(ExchangeFinder.kt:74) ~[librespot-java-api-v1.6.3.jar:1.6.4-SNAPSHO>
Oct 21 21:39:34 rpi4 java[177919]: at okhttp3.internal.connection.RealCall.initExchange$okhttp(RealCall.kt:255) ~[librespot-java-api-v1.6.3.jar:1.6.4-SNA>
Oct 21 21:39:34 rpi4 java[177919]: at okhttp3.internal.connection.ConnectInterceptor.intercept(ConnectInterceptor.kt:32) ~[librespot-java-api-v1.6.3.jar:>
Oct 21 21:39:34 rpi4 java[177919]: at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.kt:109) ~[librespot-java-api-v1.6.3.jar:1.6>
Oct 21 21:39:34 rpi4 java[177919]: at okhttp3.internal.cache.CacheInterceptor.intercept(CacheInterceptor.kt:95) ~[librespot-java-api-v1.6.3.jar:1.6.4-SNA>
Oct 21 21:39:34 rpi4 java[177919]: at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.kt:109) ~[librespot-java-api-v1.6.3.jar:1.6>
Oct 21 21:39:34 rpi4 java[177919]: at okhttp3.internal.http.BridgeInterceptor.intercept(BridgeInterceptor.kt:83) ~[librespot-java-api-v1.6.3.jar:1.6.4-SN>
Oct 21 21:39:34 rpi4 java[177919]: at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.kt:109) ~[librespot-java-api-v1.6.3.jar:1.6>
Oct 21 21:39:34 rpi4 java[177919]: at okhttp3.internal.http.RetryAndFollowUpInterceptor.intercept(RetryAndFollowUpInterceptor.kt:76) ~[librespot-java-api>
Oct 21 21:39:34 rpi4 java[177919]: at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.kt:109) ~[librespot-java-api-v1.6.3.jar:1.6>
Oct 21 21:39:34 rpi4 java[177919]: at xyz.gianlu.librespot.core.Session.lambda$createClient$1(Session.java:174) ~[librespot-java-api-v1.6.3.jar:1.6.4-SNA>
Oct 21 21:39:34 rpi4 java[177919]: at okhttp3.internal.http.RealInterceptorChain.proceed(RealInterceptorChain.kt:109) ~[librespot-java-api-v1.6.3.jar:1.6>
Oct 21 21:39:34 rpi4 java[177919]: at okhttp3.internal.connection.RealCall.getResponseWithInterceptorChain$okhttp(RealCall.kt:201) ~[librespot-java-api-v>
Oct 21 21:39:34 rpi4 java[177919]: at okhttp3.internal.connection.RealCall.execute(RealCall.kt:154) ~[librespot-java-api-v1.6.3.jar:1.6.4-SNAPSHOT]
Oct 21 21:39:34 rpi4 java[177919]: at xyz.gianlu.librespot.audio.cdn.CdnManager$Streamer.request(CdnManager.java:335) ~[librespot-java-api-v1.6.3.jar:1.6>
Oct 21 21:39:34 rpi4 java[177919]: at xyz.gianlu.librespot.audio.cdn.CdnManager$Streamer.request(CdnManager.java:328) ~[librespot-java-api-v1.6.3.jar:1.6>
Oct 21 21:39:34 rpi4 java[177919]: at xyz.gianlu.librespot.audio.cdn.CdnManager$Streamer.requestChunk(CdnManager.java:318) ~[librespot-java-api-v1.6.3.ja>
Oct 21 21:39:34 rpi4 java[177919]: ... 5 more
I use Spocon with Owntone and have been have been trying to track down why it's randomly pausing.
Do you think this issue is the same? https://github.com/spocon/spocon/issues/62
I posted a log and there are some failed CDN things in there.