Some Spotify songs doesn't play until the end and the it clears the playlist in Owntone!

[stephane77777]

Hi, I create a playlist in Spotify. No issues with spotify web site (in Chrome) or Spotify app on Windows 11 PC and the same with iPhone 13 spotify app on iOS 17. Issue occurs only in Owntone; it stops about 15-20 seconds before the first song finish (What Took You So Long) and most of the time it clears the playlist so I don't have a chance to listen the other songs. Some other times, it skips before the end (about 15 seconds) and goes to then next song (Gimme! Gimme! Gimme! 2k24). This issues occurs with "real" speakers (Logitech UE Air - Airplay 1 speakers) or with "virtual" speakers Shairport that creates virtual Airplay speakers to redirect audio to my Windows 11 PC (shairport is installed on Windows 11).

The issue occurs 100% of the time with this playlist! https://open.spotify.com/playlist/1CgxqqpCEWkv5YTBfl7plF?si=a17f818ec13f4b13

Raspberry Pi 3 Model B (aarch64) with DietPi v9.2.1 (based on Debian) Owntone Version 28.9 (Docker); I tried Owntone version 28.8 and 28.7 (same issue).

If you just add the first song (What Took You So Long) without a playlist then you get same problem! I believe it happens on other songs. To my knowledge, theses songs are pretty new.

I'm suspecting this issue starts after Spotify made upgrade to their apps and web site... Maybe they change the API...

I see this error in the log but this track is not on my plalist? spotify: Track not available for playback: 'Duck Sauce' - 'Barbra Streisand - Radio Edit'

I see this error in the log too, which is believe it has something to do with AirPlay. mDNS init failed

Regards, Stephane owntone.log

[hacketiwack]

I also have difficulties with this playlist (but not only this one actually). My log looks a bit different though:

[2024-03-29 02:12:44] [  LOG]    cache: DAAP cache updated
[2024-03-29 02:14:37] [  LOG]  spotify: Track not available for playback: 'Trance Wax' - 'Open Up The Night - X-Coast Remix' (spotify:track:3ehVl9NZhGa1YiORJvaWxh) (restrictions: { "reason": "market" })
[2024-03-29 02:14:37] [  LOG]  spotify: Unexpected JSON: error processing item at index 22 '{ "added_at": "2024-03-24T20:51:42Z", "added_by": { "external_urls": { "spotify": "https:\/\/open.spotify.com\/user\/stephanechampoux" }, "href": "https:\/\/api.spotify.com\/v1\/users\/stephanechampoux", "id": "stephanechampoux", "type": "user", "uri": "spotify:user:stephanechampoux" }, "is_local": false, "primary_color": null, "track": { "restrictions": { "reason": "market" }, "preview_url": null, "is_playable": false, "explicit": false, "type": "track", "episode": false, "track": true, "album": { "is_playable": true, "type": "album", "album_type": "single", "href": "https:\/\/api.spotify.com\/v1\/albums\/0fQpW2er88psARpgcgXPgy", "id": "0fQpW2er88psARpgcgXPgy", "images": [ { "height": 640, "url": "https:\/\/i.scdn.co\/image\/ab67616d0000b2731083f593fa98675b853220e7", "width": 640 }, { "height": 300, "url": "https:\/\/i.scdn.co\/image\/ab67616d00001e021083f593fa98675b853220e7", "width": 300 }, { "height": 64, "url": "https:\/\/i.scdn.co\/image\/ab67616d000048511083f593fa98675b853220e7", "width": 64 } ], "name": "Open Up The Night (X-Coast Remix)", "release_date": "2024-03-22", "release_date_precision": "day", "uri": "spotify:album:0fQpW2er88psARpgcgXPgy", "artists": [ { "external_urls": { "spotify": "https:\/\/open.spotify.com\/artist\/28Rn5KfDspTUHLpPfPF8EE" }, "href": "https:\/\/api.spotify.com\/v1\/artists\/28Rn5KfDspTUHLpPfPF8EE", "id": "28Rn5KfDspTUHLpPfPF8EE", "name": "Trance Wax", "type": "artist", "uri": "spotify:artist:28Rn5KfDspTUHLpPfPF8EE" }, { "external_urls": { "spotify": "https:\/\/open.spotify.com\/artist\/5QUHrSea6F2nhn9veAq4wQ" }, "href": "https:\/\/api.spotify.com\/v1\/artists\/5QUHrSea6F2nhn9veAq4wQ", "id": "5QUHrSea6F2nhn9veAq4wQ", "name": "X-COAST", "type": "artist", "uri": "spotify:artist:5QUHrSea6F2nhn9veAq4wQ" } ], "external_urls": { "spotify": "https:\/\/open.spotify.com\/album\/0fQpW2er88psARpgcgXPgy" }, "total_tracks": 2 }, "artists": [ { "external_urls": { "spotify": "https:\/\/open.spotify.com\/artist\/28Rn5KfDspTUHLpPfPF8EE...
[2024-03-29 02:30:28] [  LOG]   player: Error reading source 'spotify:track:33ZZmexIbp5RgZqIpfSkuS' (id=9999999)
[2024-03-29 02:30:28] [  LOG]   player: Error reading from source
[2024-03-29 02:30:30] [  LOG]  airplay: Could not fetch queue item
[2024-03-29 02:30:30] [  LOG]     raop: Could not fetch queue item
[2024-03-29 02:30:30] [  LOG]   stream: Could not fetch queue item id 2266313 for new metadata
[2024-03-29 02:32:35] [  LOG]   player: Source is not providing sufficient data, temporarily suspending playback (deficit=266204/264600 bytes)

And then near the end of the song, it's stuck and OwnTone becomes unresponsive for quite some time.

[ejurgensen]

I can reproduce the issue. Also with a testing program I use, which will make it easier to debug. There is unexpected track data from Spotify towards the end of the track, which causes OwnTone to fail. I have to dive deeper into what exactly that is and how to fix.

I couldn't reproduce the JSON error you get @hacketiwack, and since the log message is truncated it is difficult to test it. Any chance you can set a breakpoint and get the full JSON?

[ejurgensen]

The cause of this seems to be that when owntone requests the last chunk of file data Spotify either disconnects or returns bad data. So I expect there is something wrong with the request. I have some ideas, but I'm a bit busy with other stuff, so it might not be before May.

[hacketiwack]

@ejurgensen unfortunately, I don't have the setup to debug this. Is there a way to have the full message (JSON) by making the logging more verbose?

[ejurgensen]

Yeah, I think the truncation happens here: https://github.com/owntone/owntone-server/blob/master/src/logger.c#L155

So if you just increase the 2048 I think you can get the whole message. Maybe try with 32k or something like that.

[hacketiwack]

Thanks. I will do that then :-)

[hacketiwack]

This is the full message I receive in the logs:

[2024-04-04 11:49:49] [  LOG]  spotify: Unexpected JSON: error processing item at index 22 '{ "added_at": "2024-03-24T20:51:42Z", "added_by": { "external_urls": { "spotify": "https:\/\/open.spotify.com\/user\/stephanechampoux" }, "href": "https:\/\/api.spotify.com\/v1\/users\/stephanechampoux", "id": "stephanechampoux", "type": "user", "uri": "spotify:user:stephanechampoux" }, "is_local": false, "primary_color": null, "track": { "restrictions": { "reason": "market" }, "preview_url": null, "is_playable": false, "explicit": false, "type": "track", "episode": false, "track": true, "album": { "is_playable": true, "type": "album", "album_type": "single", "href": "https:\/\/api.spotify.com\/v1\/albums\/0fQpW2er88psARpgcgXPgy", "id": "0fQpW2er88psARpgcgXPgy", "images": [ { "height": 640, "url": "https:\/\/i.scdn.co\/image\/ab67616d0000b2731083f593fa98675b853220e7", "width": 640 }, { "height": 300, "url": "https:\/\/i.scdn.co\/image\/ab67616d00001e021083f593fa98675b853220e7", "width": 300 }, { "height": 64, "url": "https:\/\/i.scdn.co\/image\/ab67616d000048511083f593fa98675b853220e7", "width": 64 } ], "name": "Open Up The Night (X-Coast Remix)", "release_date": "2024-03-22", "release_date_precision": "day", "uri": "spotify:album:0fQpW2er88psARpgcgXPgy", "artists": [ { "external_urls": { "spotify": "https:\/\/open.spotify.com\/artist\/28Rn5KfDspTUHLpPfPF8EE" }, "href": "https:\/\/api.spotify.com\/v1\/artists\/28Rn5KfDspTUHLpPfPF8EE", "id": "28Rn5KfDspTUHLpPfPF8EE", "name": "Trance Wax", "type": "artist", "uri": "spotify:artist:28Rn5KfDspTUHLpPfPF8EE" }, { "external_urls": { "spotify": "https:\/\/open.spotify.com\/artist\/5QUHrSea6F2nhn9veAq4wQ" }, "href": "https:\/\/api.spotify.com\/v1\/artists\/5QUHrSea6F2nhn9veAq4wQ", "id": "5QUHrSea6F2nhn9veAq4wQ", "name": "X-COAST", "type": "artist", "uri": "spotify:artist:5QUHrSea6F2nhn9veAq4wQ" } ], "external_urls": { "spotify": "https:\/\/open.spotify.com\/album\/0fQpW2er88psARpgcgXPgy" }, "total_tracks": 2 }, "artists": [ { "external_urls": { "spotify": "https:\/\/open.spo
\/artist\/28Rn5KfDspTUHLpPfPF8EE" }, "href": "https:\/\/api.spotify.com\/v1\/artists\/28Rn5KfDspTUHLpPfPF8EE", "id": "28Rn5KfDspTUHLpPfPF8EE", "name": "Trance Wax", "type": "artist", "uri": "spotify:artist:28Rn5KfDspTUHLpPfPF8EE" }, { "external_urls": { "spotify": "https:\/\/open.spotify.com\/artist\/5QUHrSea6F2nhn9veAq4wQ" }, "href": "https:\/\/api.spotify.com\/v1\/artists\/5QUHrSea6F2nhn9veAq4wQ", "id": "5QUHrSea6F2nhn9veAq4wQ", "name": "X-COAST", "type": "artist", "uri": "spotify:artist:5QUHrSea6F2nhn9veAq4wQ" } ], "disc_number": 1, "track_number": 1, "duration_ms": 169374, "external_ids": { "isrc": "NLF712400956" }, "external_urls": { "spotify": "https:\/\/open.spotify.com\/track\/3ehVl9NZhGa1YiORJvaWxh" }, "href": "https:\/\/api.spotify.com\/v1\/tracks\/3ehVl9NZhGa1YiORJvaWxh", "id": "3ehVl9NZhGa1YiORJvaWxh", "name": "Open Up The Night - X-Coast Remix", "popularity": 34, "uri": "spotify:track:3ehVl9NZhGa1YiORJvaWxh", "is_local": false }, "video_thumbnail": { "url": null } }' (API endpoint: 'https://api.spotify.com/v1/playlists/1CgxqqpCEWkv5YTBfl7plF/tracks')

There is, indeed, a problem with a URL being truncated in the middle:

https:\/\/open.spo
\/artist\/28Rn5KfDspTUHLpPfPF8EE" }

[ejurgensen]

Strange. Did you have the logging on DEBUG? Then there should also be the request URL. With that we could try to test directly from command line with curl.

[hacketiwack]

@ejurgensen, logging was configured with info sensitivity. With debug verbosity, I get the following:

[2024-04-04 14:57:33] [DEBUG]  spotify: Spotify API endpoint request: 'https://api.spotify.com/v1/playlists/1CgxqqpCEWkv5YTBfl7plF/tracks?market=CH'
[2024-04-04 14:57:33] [DEBUG]       db: Running query 'INSERT INTO queue (file_id, pos, shuffle_pos, data_kind, media_kind, song_length, path, virtual_path, title, artist, album_artist, album, genre, songalbumid, time_modified, artist_sort, album_sort, album_artist_sort, year, track, disc, artwork_url, queue_version, composer, songartistid, type, bitrate, samplerate, channels) VALUES (9999999, 0, 0, 2, 1, 211058, 'spotify:track:5SpFKUNS16xxxQt6cSPaLh', '/spotify:track:5SpFKUNS16xxxQt6cSPaLh', 'What Took You So Long', 'Armin van Buuren', 'Armin van Buuren', 'What Took You So Long', 'Unknown genre', 0, 0, 'Armin van Buuren', 'What Took You So Long', 'Armin van Buuren', 0, 1, 1, 'https://i.scdn.co/image/ab67616d00001e022fd4ae999271dadc40c362ed', 21157, NULL, 0, NULL, 0, 0, 0);'
[2024-04-04 14:57:33] [DEBUG]       db: Running query 'INSERT INTO queue (file_id, pos, shuffle_pos, data_kind, media_kind, song_length, path, virtual_path, title, artist, album_artist, album, genre, songalbumid, time_modified, artist_sort, album_sort, album_artist_sort, year, track, disc, artwork_url, queue_version, composer, songartistid, type, bitrate, samplerate, channels) VALUES (9999999, 1, 1, 2, 1, 155354, 'spotify:track:33ZZmexIbp5RgZqIpfSkuS', '/spotify:track:33ZZmexIbp5RgZqIpfSkuS', 'Gimme! Gimme! Gimme! 2k24', 'Teknova', 'Teknova', 'Gimme! Gimme! Gimme! 2k24', 'Unknown genre', 0, 0, 'Teknova', 'Gimme! Gimme! Gimme! 00002k00024', 'Teknova', 0, 1, 1, 'https://i.scdn.co/image/ab67616d00001e02a8e4a51999d7307c1ec01ffe', 21157, NULL, 0, NULL, 0, 0, 0);'
[2024-04-04 14:57:33] [DEBUG]       db: Running query 'INSERT INTO queue (file_id, pos, shuffle_pos, data_kind, media_kind, song_length, path, virtual_path, title, artist, album_artist, album, genre, songalbumid, time_modified, artist_sort, album_sort, album_artist_sort, year, track, disc, artwork_url, queue_version, composer, songartistid, type, bitrate, samplerate, channels) VALUES (9999999, 2, 2, 2, 1, 124137, 'spotify:track:7fyapHqzoIZosaiJ34bGdL', '/spotify:track:7fyapHqzoIZosaiJ34bGdL', 'Exited', 'MaxRiven', 'MaxRiven', 'Exited', 'Unknown genre', 0, 0, 'MaxRiven', 'Exited', 'MaxRiven', 0, 1, 1, 'https://i.scdn.co/image/ab67616d00001e0201f39d245b2a3529ad6fab3b', 21157, NULL, 0, NULL, 0, 0, 0);'
[2024-04-04 14:57:33] [DEBUG]       db: Running query 'INSERT INTO queue (file_id, pos, shuffle_pos, data_kind, media_kind, song_length, path, virtual_path, title, artist, album_artist, album, genre, songalbumid, time_modified, artist_sort, album_sort, album_artist_sort, year, track, disc, artwork_url, queue_version, composer, songartistid, type, bitrate, samplerate, channels) VALUES (9999999, 3, 3, 2, 1, 180999, 'spotify:track:4YHA0wXklru86h1N211Ywh', '/spotify:track:4YHA0wXklru86h1N211Ywh', 'Team Side Feat. RCB', 'Alan Walker', 'Alan Walker', 'Team Side Feat. RCB', 'Unknown genre', 0, 0, 'Alan Walker', 'Team Side Feat. RCB', 'Alan Walker', 0, 1, 1, 'https://i.scdn.co/image/ab67616d00001e022f85883e895538fed47f0e5f', 21157, NULL, 0, NULL, 0, 0, 0);'
[2024-04-04 14:57:33] [DEBUG]       db: Running query 'INSERT INTO queue (file_id, pos, shuffle_pos, data_kind, media_kind, song_length, path, virtual_path, title, artist, album_artist, album, genre, songalbumid, time_modified, artist_sort, album_sort, album_artist_sort, year, track, disc, artwork_url, queue_version, composer, songartistid, type, bitrate, samplerate, channels) VALUES (9999999, 4, 4, 2, 1, 136551, 'spotify:track:758KOSCLXKIf6BqMXe12pN', '/spotify:track:758KOSCLXKIf6BqMXe12pN', 'Conquest Of Paradise', 'Klaas', 'Klaas', 'Conquest Of Paradise', 'Unknown genre', 0, 0, 'Klaas', 'Conquest Of Paradise', 'Klaas', 0, 1, 1, 'https://i.scdn.co/image/ab67616d00001e02e4140895e9c6f54b658dec46', 21157, NULL, 0, NULL, 0, 0, 0);'
[2024-04-04 14:57:33] [DEBUG]       db: Running query 'INSERT INTO queue (file_id, pos, shuffle_pos, data_kind, media_kind, song_length, path, virtual_path, title, artist, album_artist, album, genre, songalbumid, time_modified, artist_sort, album_sort, album_artist_sort, year, track, disc, artwork_url, queue_version, composer, songartistid, type, bitrate, samplerate, channels) VALUES (9999999, 5, 5, 2, 1, 153103, 'spotify:track:6r5faIY6BdYJUukkkwTq5Y', '/spotify:track:6r5faIY6BdYJUukkkwTq5Y', 'Clarity', 'Roman Messer', 'Roman Messer', 'Clarity', 'Unknown genre', 0, 0, 'Roman Messer', 'Clarity', 'Roman Messer', 0, 1, 1, 'https://i.scdn.co/image/ab67616d00001e02ec88686b864142dddbfd0a07', 21157, NULL, 0, NULL, 0, 0, 0);'
[2024-04-04 14:57:33] [DEBUG]       db: Running query 'INSERT INTO queue (file_id, pos, shuffle_pos, data_kind, media_kind, song_length, path, virtual_path, title, artist, album_artist, album, genre, songalbumid, time_modified, artist_sort, album_sort, album_artist_sort, year, track, disc, artwork_url, queue_version, composer, songartistid, type, bitrate, samplerate, channels) VALUES (9999999, 6, 6, 2, 1, 175317, 'spotify:track:46EXWDiGqUirtOum62Ve3B', '/spotify:track:46EXWDiGqUirtOum62Ve3B', 'Lullaby', 'Dani Corbalan', 'Dani Corbalan', 'Lullaby', 'Unknown genre', 0, 0, 'Dani Corbalan', 'Lullaby', 'Dani Corbalan', 0, 1, 1, 'https://i.scdn.co/image/ab67616d00001e02738cefc8eb5de6e89cf9c71d', 21157, NULL, 0, NULL, 0, 0, 0);'
[2024-04-04 14:57:33] [DEBUG]       db: Running query 'INSERT INTO queue (file_id, pos, shuffle_pos, data_kind, media_kind, song_length, path, virtual_path, title, artist, album_artist, album, genre, songalbumid, time_modified, artist_sort, album_sort, album_artist_sort, year, track, disc, artwork_url, queue_version, composer, songartistid, type, bitrate, samplerate, channels) VALUES (9999999, 7, 7, 2, 1, 160704, 'spotify:track:1Rz3Xw2qOsRncTVajZR3cY', '/spotify:track:1Rz3Xw2qOsRncTVajZR3cY', 'Electricity', 'FAST BOY', 'FAST BOY', 'Electricity', 'Unknown genre', 0, 0, 'FAST BOY', 'Electricity', 'FAST BOY', 0, 1, 1, 'https://i.scdn.co/image/ab67616d00001e02d2dc26728ea25aec5b35bccc', 21157, NULL, 0, NULL, 0, 0, 0);'
[2024-04-04 14:57:33] [DEBUG]       db: Running query 'INSERT INTO queue (file_id, pos, shuffle_pos, data_kind, media_kind, song_length, path, virtual_path, title, artist, album_artist, album, genre, songalbumid, time_modified, artist_sort, album_sort, album_artist_sort, year, track, disc, artwork_url, queue_version, composer, songartistid, type, bitrate, samplerate, channels) VALUES (9999999, 8, 8, 2, 1, 152943, 'spotify:track:48cAxj7gxcTt95eOFn4i5G', '/spotify:track:48cAxj7gxcTt95eOFn4i5G', 'Every Day - Radio Mix', 'Papa Tin', 'Papa Tin', 'Every Day', 'Unknown genre', 0, 0, 'Papa Tin', 'Every Day', 'Papa Tin', 0, 2, 1, 'https://i.scdn.co/image/ab67616d00001e022629da9f943f171ae9586afe', 21157, NULL, 0, NULL, 0, 0, 0);'
[2024-04-04 14:57:33] [DEBUG]       db: Running query 'INSERT INTO queue (file_id, pos, shuffle_pos, data_kind, media_kind, song_length, path, virtual_path, title, artist, album_artist, album, genre, songalbumid, time_modified, artist_sort, album_sort, album_artist_sort, year, track, disc, artwork_url, queue_version, composer, songartistid, type, bitrate, samplerate, channels) VALUES (9999999, 9, 9, 2, 1, 231428, 'spotify:track:7sBcZd97r93u2Q3m6L6GNI', '/spotify:track:7sBcZd97r93u2Q3m6L6GNI', 'Goliath', 'Kaimo K', 'Kaimo K', 'Goliath', 'Unknown genre', 0, 0, 'Kaimo K', 'Goliath', 'Kaimo K', 0, 1, 1, 'https://i.scdn.co/image/ab67616d00001e020375fb43eadaaab14f3076d5', 21157, NULL, 0, NULL, 0, 0, 0);'
[2024-04-04 14:57:33] [DEBUG]       db: Running query 'INSERT INTO queue (file_id, pos, shuffle_pos, data_kind, media_kind, song_length, path, virtual_path, title, artist, album_artist, album, genre, songalbumid, time_modified, artist_sort, album_sort, album_artist_sort, year, track, disc, artwork_url, queue_version, composer, songartistid, type, bitrate, samplerate, channels) VALUES (9999999, 10, 10, 2, 1, 199047, 'spotify:track:1Hz5ZPQxC6esErNVN4cxr6', '/spotify:track:1Hz5ZPQxC6esErNVN4cxr6', 'Bloom At Night', 'Miss Monique', 'Miss Monique', 'Bloom At Night', 'Unknown genre', 0, 0, 'Miss Monique', 'Bloom At Night', 'Miss Monique', 0, 1, 1, 'https://i.scdn.co/image/ab67616d00001e020e6bb06994a4a44e100d33c2', 21157, NULL, 0, NULL, 0, 0, 0);'
[2024-04-04 14:57:33] [DEBUG]       db: Running query 'INSERT INTO queue (file_id, pos, shuffle_pos, data_kind, media_kind, song_length, path, virtual_path, title, artist, album_artist, album, genre, songalbumid, time_modified, artist_sort, album_sort, album_artist_sort, year, track, disc, artwork_url, queue_version, composer, songartistid, type, bitrate, samplerate, channels) VALUES (9999999, 11, 11, 2, 1, 222099, 'spotify:track:752QCKUDLEYWhDA5PYJdPf', '/spotify:track:752QCKUDLEYWhDA5PYJdPf', 'Traffic (GDJB Weekly Drive 18) - Kryder & Dave Winnel Remix', 'Tiësto', 'Markus Schulz', 'Global DJ Broadcast Weekly Drive 18', 'Unknown genre', 0, 0, 'Tiësto', 'Global DJ Broadcast Weekly Drive 00018', 'Markus Schulz', 0, 2, 1, 'https://i.scdn.co/image/ab67616d00001e024a8cd9acb38dbe0de2f957b8', 21157, NULL, 0, NULL, 0, 0, 0);'
[2024-04-04 14:57:33] [DEBUG]       db: Running query 'INSERT INTO queue (file_id, pos, shuffle_pos, data_kind, media_kind, song_length, path, virtual_path, title, artist, album_artist, album, genre, songalbumid, time_modified, artist_sort, album_sort, album_artist_sort, year, track, disc, artwork_url, queue_version, composer, songartistid, type, bitrate, samplerate, channels) VALUES (9999999, 12, 12, 2, 1, 233464, 'spotify:track:39PUFbIifKict3TE8WpIgh', '/spotify:track:39PUFbIifKict3TE8WpIgh', 'All Of Me - Uplifting Mix', 'Mhammed El Alami', 'Mhammed El Alami', 'All Of Me (Uplifting Mix / Acoustic Mix)', 'Unknown genre', 0, 0, 'Mhammed El Alami', 'All Of Me (Uplifting Mix / Acoustic Mix)', 'Mhammed El Alami', 0, 1, 1, 'https://i.scdn.co/image/ab67616d00001e02924aa3001030a2b714a981e0', 21157, NULL, 0, NULL, 0, 0, 0);'
[2024-04-04 14:57:33] [DEBUG]       db: Running query 'INSERT INTO queue (file_id, pos, shuffle_pos, data_kind, media_kind, song_length, path, virtual_path, title, artist, album_artist, album, genre, songalbumid, time_modified, artist_sort, album_sort, album_artist_sort, year, track, disc, artwork_url, queue_version, composer, songartistid, type, bitrate, samplerate, channels) VALUES (9999999, 13, 13, 2, 1, 211451, 'spotify:track:0uVxg9G8CwOt5n616PyNHr', '/spotify:track:0uVxg9G8CwOt5n616PyNHr', 'Sublimity', 'Protoculture', 'Protoculture', 'Sublimity', 'Unknown genre', 0, 0, 'Protoculture', 'Sublimity', 'Protoculture', 0, 1, 1, 'https://i.scdn.co/image/ab67616d00001e022353c165b0c8358c595f3d04', 21157, NULL, 0, NULL, 0, 0, 0);'
[2024-04-04 14:57:33] [DEBUG]       db: Running query 'INSERT INTO queue (file_id, pos, shuffle_pos, data_kind, media_kind, song_length, path, virtual_path, title, artist, album_artist, album, genre, songalbumid, time_modified, artist_sort, album_sort, album_artist_sort, year, track, disc, artwork_url, queue_version, composer, songartistid, type, bitrate, samplerate, channels) VALUES (9999999, 14, 14, 2, 1, 182686, 'spotify:track:783aw9wB5fehzSo73zlthd', '/spotify:track:783aw9wB5fehzSo73zlthd', 'Elyisum (Transmission 2024 Theme) (GDJB Weekly Drive 18)', 'Daxson', 'Markus Schulz', 'Global DJ Broadcast Weekly Drive 18', 'Unknown genre', 0, 0, 'Daxson', 'Global DJ Broadcast Weekly Drive 00018', 'Markus Schulz', 0, 4, 1, 'https://i.scdn.co/image/ab67616d00001e024a8cd9acb38dbe0de2f957b8', 21157, NULL, 0, NULL, 0, 0, 0);'
[2024-04-04 14:57:33] [DEBUG]       db: Running query 'INSERT INTO queue (file_id, pos, shuffle_pos, data_kind, media_kind, song_length, path, virtual_path, title, artist, album_artist, album, genre, songalbumid, time_modified, artist_sort, album_sort, album_artist_sort, year, track, disc, artwork_url, queue_version, composer, songartistid, type, bitrate, samplerate, channels) VALUES (9999999, 15, 15, 2, 1, 162999, 'spotify:track:0nyciuEquf1YpSYlMTArFG', '/spotify:track:0nyciuEquf1YpSYlMTArFG', 'Nocturne', 'Eximinds', 'Eximinds', 'Nocturne', 'Unknown genre', 0, 0, 'Eximinds', 'Nocturne', 'Eximinds', 0, 1, 1, 'https://i.scdn.co/image/ab67616d00001e02d4b60949aaf624c466b8aef9', 21157, NULL, 0, NULL, 0, 0, 0);'
[2024-04-04 14:57:33] [DEBUG]       db: Running query 'INSERT INTO queue (file_id, pos, shuffle_pos, data_kind, media_kind, song_length, path, virtual_path, title, artist, album_artist, album, genre, songalbumid, time_modified, artist_sort, album_sort, album_artist_sort, year, track, disc, artwork_url, queue_version, composer, songartistid, type, bitrate, samplerate, channels) VALUES (9999999, 16, 16, 2, 1, 136642, 'spotify:track:6OkWX7reYPfB1yqd8eyhCK', '/spotify:track:6OkWX7reYPfB1yqd8eyhCK', '24k Heart Of Gold', 'YouNotUs', 'YouNotUs', '24k Heart Of Gold', 'Unknown genre', 0, 0, 'YouNotUs', '00024k Heart Of Gold', 'YouNotUs', 0, 1, 1, 'https://i.scdn.co/image/ab67616d00001e02d27194f741a47cde16e24474', 21157, NULL, 0, NULL, 0, 0, 0);'
[2024-04-04 14:57:33] [DEBUG]       db: Running query 'INSERT INTO queue (file_id, pos, shuffle_pos, data_kind, media_kind, song_length, path, virtual_path, title, artist, album_artist, album, genre, songalbumid, time_modified, artist_sort, album_sort, album_artist_sort, year, track, disc, artwork_url, queue_version, composer, songartistid, type, bitrate, samplerate, channels) VALUES (9999999, 17, 17, 2, 1, 233070, 'spotify:track:5VSpaB2Gupxaz0JNrWZUcO', '/spotify:track:5VSpaB2Gupxaz0JNrWZUcO', 'Don''t Be Afraid', 'Nitrous Oxide', 'Nitrous Oxide', 'Don''t Be Afraid', 'Unknown genre', 0, 0, 'Nitrous Oxide', 'Don''t Be Afraid', 'Nitrous Oxide', 0, 1, 1, 'https://i.scdn.co/image/ab67616d00001e02bf363296d6b6307708a2f088', 21157, NULL, 0, NULL, 0, 0, 0);'
[2024-04-04 14:57:33] [DEBUG]       db: Running query 'INSERT INTO queue (file_id, pos, shuffle_pos, data_kind, media_kind, song_length, path, virtual_path, title, artist, album_artist, album, genre, songalbumid, time_modified, artist_sort, album_sort, album_artist_sort, year, track, disc, artwork_url, queue_version, composer, songartistid, type, bitrate, samplerate, channels) VALUES (9999999, 18, 18, 2, 1, 246857, 'spotify:track:7C0bzvGMXZEH6YfsjgUKny', '/spotify:track:7C0bzvGMXZEH6YfsjgUKny', 'Flow Walker (FSOE850)', 'James Dymond', 'Aly & Fila', 'FSOE 850 - Future Sound Of Egypt Episode 850', 'Unknown genre', 0, 0, 'James Dymond', 'FSOE 00850 - Future Sound Of Egypt Episode 00850', 'Aly & Fila', 0, 25, 1, 'https://i.scdn.co/image/ab67616d00001e0244f6c391c84a8e41009d697e', 21157, NULL, 0, NULL, 0, 0, 0);'
[2024-04-04 14:57:33] [DEBUG]       db: Running query 'INSERT INTO queue (file_id, pos, shuffle_pos, data_kind, media_kind, song_length, path, virtual_path, title, artist, album_artist, album, genre, songalbumid, time_modified, artist_sort, album_sort, album_artist_sort, year, track, disc, artwork_url, queue_version, composer, songartistid, type, bitrate, samplerate, channels) VALUES (9999999, 19, 19, 2, 1, 177890, 'spotify:track:6ofQ30BLZrk3Ks46wXQDX3', '/spotify:track:6ofQ30BLZrk3Ks46wXQDX3', 'Yesterday', 'Dj Sparadise', 'Dj Sparadise', 'Yesterday', 'Unknown genre', 0, 0, 'Dj Sparadise', 'Yesterday', 'Dj Sparadise', 0, 1, 1, 'https://i.scdn.co/image/ab67616d00001e026155cacb7829860d04c8632e', 21157, NULL, 0, NULL, 0, 0, 0);'
[2024-04-04 14:57:33] [DEBUG]       db: Running query 'INSERT INTO queue (file_id, pos, shuffle_pos, data_kind, media_kind, song_length, path, virtual_path, title, artist, album_artist, album, genre, songalbumid, time_modified, artist_sort, album_sort, album_artist_sort, year, track, disc, artwork_url, queue_version, composer, songartistid, type, bitrate, samplerate, channels) VALUES (9999999, 20, 20, 2, 1, 137436, 'spotify:track:1CZVSkJAmXYKnWrQOcfnLi', '/spotify:track:1CZVSkJAmXYKnWrQOcfnLi', 'Deep In Your Love - Dimitri Vegas & Like Mike, Ben Nicky & Dr Phunk Remix', 'Alok', 'Alok', 'Deep In Your Love (Dimitri Vegas & Like Mike, Ben Nicky & Dr Phunk Remix)', 'Unknown genre', 0, 0, 'Alok', 'Deep In Your Love (Dimitri Vegas & Like Mike, Ben Nicky & Dr Phunk Remix)', 'Alok', 0, 1, 1, 'https://i.scdn.co/image/ab67616d00001e02d24b584a5ec34725dad2581b', 21157, NULL, 0, NULL, 0, 0, 0);'
[2024-04-04 14:57:33] [DEBUG]       db: Running query 'INSERT INTO queue (file_id, pos, shuffle_pos, data_kind, media_kind, song_length, path, virtual_path, title, artist, album_artist, album, genre, songalbumid, time_modified, artist_sort, album_sort, album_artist_sort, year, track, disc, artwork_url, queue_version, composer, songartistid, type, bitrate, samplerate, channels) VALUES (9999999, 21, 21, 2, 1, 189318, 'spotify:track:4AwpegNwva8CwHptY89L3x', '/spotify:track:4AwpegNwva8CwHptY89L3x', 'In My Mind', 'Gabry Ponte', 'Gabry Ponte', 'In My Mind', 'Unknown genre', 0, 0, 'Gabry Ponte', 'In My Mind', 'Gabry Ponte', 0, 1, 1, 'https://i.scdn.co/image/ab67616d00001e02aa85f53e8b2cf3d08503c695', 21157, NULL, 0, NULL, 0, 0, 0);'
[2024-04-04 14:57:33] [  LOG]  spotify: Track not available for playback: 'Trance Wax' - 'Open Up The Night - X-Coast Remix' (spotify:track:3ehVl9NZhGa1YiORJvaWxh) (restrictions: { "reason": "market" })
[2024-04-04 14:57:33] [  LOG]  spotify: Unexpected JSON: error processing item at index 22 '{ "added_at": "2024-03-24T20:51:42Z", "added_by": { "external_urls": { "spotify": "https:\/\/open.spotify.com\/user\/stephanechampoux" }, "href": "https:\/\/api.spotify.com\/v1\/users\/stephanechampoux", "id": "stephanechampoux", "type": "user", "uri": "spotify:user:stephanechampoux" }, "is_local": false, "primary_color": null, "track": { "restrictions": { "reason": "market" }, "preview_url": null, "is_playable": false, "explicit": false, "type": "track", "episode": false, "track": true, "album": { "is_playable": true, "type": "album", "album_type": "single", "href": "https:\/\/api.spotify.com\/v1\/albums\/0fQpW2er88psARpgcgXPgy", "id": "0fQpW2er88psARpgcgXPgy", "images": [ { "height": 640, "url": "https:\/\/i.scdn.co\/image\/ab67616d0000b2731083f593fa98675b853220e7", "width": 640 }, { "height": 300, "url": "https:\/\/i.scdn.co\/image\/ab67616d00001e021083f593fa98675b853220e7", "width": 300 }, { "height": 64, "url": "https:\/\/i.scdn.co\/image\/ab67616d000048511083f593fa98675b853220e7", "width": 64 } ], "name": "Open Up The Night (X-Coast Remix)", "release_date": "2024-03-22", "release_date_precision": "day", "uri": "spotify:album:0fQpW2er88psARpgcgXPgy", "artists": [ { "external_urls": { "spotify": "https:\/\/open.spotify.com\/artist\/28Rn5KfDspTUHLpPfPF8EE" }, "href": "https:\/\/api.spotify.com\/v1\/artists\/28Rn5KfDspTUHLpPfPF8EE", "id": "28Rn5KfDspTUHLpPfPF8EE", "name": "Trance Wax", "type": "artist", "uri": "spotify:artist:28Rn5KfDspTUHLpPfPF8EE" }, { "external_urls": { "spotify": "https:\/\/open.spotify.com\/artist\/5QUHrSea6F2nhn9veAq4wQ" }, "href": "https:\/\/api.spotify.com\/v1\/artists\/5QUHrSea6F2nhn9veAq4wQ", "id": "5QUHrSea6F2nhn9veAq4wQ", "name": "X-COAST", "type": "artist", "uri": "spotify:artist:5QUHrSea6F2nhn9veAq4wQ" } ], "external_urls": { "spotify": "https:\/\/open.spotify.com\/album\/0fQpW2er88psARpgcgXPgy" }, "total_tracks": 2 }, "artists": [ { "external_urls": { "spotify": "https:\/\/open.spotify.com\/artist\/28Rn5KfDspTUHLpPfPF8EE" }, "href": "https:\/\/api.spotify.com\/v1\/artists\/28Rn5KfDspTUHLpPfPF8EE", "id": "28Rn5KfDspTUHLpPfPF8EE", "name": "Trance Wax", "type": "artist", "uri": "spotify:artist:28Rn5KfDspTUHLpPfPF8EE" }, { "external_urls": { "spotify": "https:\/\/open.spotify.com\/artist\/5QUHrSea6F2nhn9veAq4wQ" }, "href": "https:\/\/api.spotify.com\/v1\/artists\/5QUHrSea6F2nhn9veAq4wQ", "id": "5QUHrSea6F2nhn9veAq4wQ", "name": "X-COAST", "type": "artist", "uri": "spotify:artist:5QUHrSea6F2nhn9veAq4wQ" } ], "disc_number": 1, "track_number": 1, "duration_ms": 169374, "external_ids": { "isrc": "NLF712400956" }, "external_urls": { "spotify": "https:\/\/open.spotify.com\/track\/3ehVl9NZhGa1YiORJvaWxh" }, "href": "https:\/\/api.spotify.com\/v1\/tracks\/3ehVl9NZhGa1YiORJvaWxh", "id": "3ehVl9NZhGa1YiORJvaWxh", "name": "Open Up The Night - X-Coast Remix", "popularity": 34, "uri": "spotify:track:3ehVl9NZhGa1YiORJvaWxh", "is_local": false }, "video_thumbnail": { "url": null } }' (API endpoint: 'https://api.spotify.com/v1/playlists/1CgxqqpCEWkv5YTBfl7plF/tracks')
[2024-04-04 14:57:33] [DEBUG]       db: Running query 'INSERT INTO queue (file_id, pos, shuffle_pos, data_kind, media_kind, song_length, path, virtual_path, title, artist, album_artist, album, genre, songalbumid, time_modified, artist_sort, album_sort, album_artist_sort, year, track, disc, artwork_url, queue_version, composer, songartistid, type, bitrate, samplerate, channels) VALUES (9999999, 22, 22, 2, 1, 195776, 'spotify:track:7j7zeMX7qQkZJTspe7JUco', '/spotify:track:7j7zeMX7qQkZJTspe7JUco', 'Somewhere Over The Rainbow', 'Talla 2XLC', 'Talla 2XLC', 'Somewhere Over The Rainbow', 'Unknown genre', 0, 0, 'Talla 00002XLC', 'Somewhere Over The Rainbow', 'Talla 00002XLC', 0, 1, 1, 'https://i.scdn.co/image/ab67616d00001e02118e3d7fafd1c0f9b57a0bdb', 21157, NULL, 0, NULL, 0, 0, 0);'

[ejurgensen]

Those integer overflows don't look great. Never seen those myself. Also weird that it's the same value being parsed over and over. Can you open another issue for that and move the logging there?

[ejurgensen]

Can you try this:

curl -H "Authorization: Bearer <my_access_token>" "https://api.spotify.com/v1/playlists/1CgxqqpCEWkv5YTBfl7plF/tracks?market=CH"

You can find the access token in the admin table in songs3.db. So just sqlite3 songs3.db and then select * from admin.

[ejurgensen]

And just share the output here (not the access token!)

[hacketiwack]

Hereunder, the result of the curl command (sorry for the long JSON content). I think, however, that the result is correct.

{
[redacted]
}

[hacketiwack]

Those integer overflows don't look great. Never seen those myself. Also weird that it's the same value being parsed over and over. Can you open another issue for that and move the logging there?

As requested, the bug report is here.

[ejurgensen]

With regard to the "Unexpected JSON: error processing item" I think there isn't actually anything wrong, it's just the log message that is a bit misleading. What happens is what you see in the line before, which is that a track isn't available in your market. That's what causes the "Unexpected JSON", even though there isn't actually anything wrong with the JSON. I've fixed that now.

The problem with playback at track end still remains, that's more difficult to solve.

[stephane77777]

Hi,

In Spotify I notice there is an option "Crossfade songs" and "Automix - Allow seamless transitions between songs on select playlists". Could it be the reason why we have this issue on some songs / playlists?

Also, if Owntone is using Spocon instead of librespot-c or any others could it resolve this issue?

Do you have any updates about this issue?

Regards, Stephane

[ejurgensen]

I haven't had time to work on it, but hopefully will have during the next weeks

[ejurgensen]

I finally got around to this issue, but now I can no longer reproduce it. I tried with two tracks that previously errored, but they worked fine. Do you guys still have the error? If not, I suppose we might be so lucky that it was fixed on Spotify's side.

[hacketiwack]

Well, this playlist is still problematic on my side. It makes also the OwnTone server completely unresponsive. :-/

[ejurgensen]

When does it happen? Is it when the first song ("What took you so long") is ending? That's where I could reproduce it before, but not any more.

[hacketiwack]

Actually, it is not working at the beginning of the song "What took you so long". If I start the playlist with that one, OwnTone is becoming unresponsive. When I start with another track, it's working. But as soon as I get back to it, it's not working anymore. I have to restart OwnTone.

[ejurgensen]

Weird - sounds like it might be another issue then? Anything in the logs?

[hacketiwack]

I think also that's another issue. Unfortunately, there's nothing in the logs. I suspect my router doing some nasty things with the network. I had to switch router, but my ISP offers only a nasty horrible Fritz Box. That might be the problem actually. So ignore my previous messages.

[hacketiwack]

I retested properly and I will also conclude that this bug has been solved on Spotify side. My errors were related to something else.

[ejurgensen]

Ok, I will close the issue then. If it reappears I will reopen.