Plex Sync Failing (GarminSdkError:0)

[cjhesse]

Syncing with Plex currently fails and gives GarminSdkError:0. When I run Test Server, it gets to "Inlog OK" and seems to stay that way indefinitely.

Here are the details:

• I'm using a Fenix 7S Sapphire Solar.
• Plex is running in a Docker container on an Unraid Server.
• I'm accessing Plex via a reverse proxy (Nginx Proxy Manager).
• DDNS is via DuckDNS and Google Domains is used to create my subdomains.
• My router is configured to forward ports 80 and 443 to Nginx.
• Nginx forwards requests from https://plex.[domain].[tld] to Plex's IP address and port (http://[servername]:32400).
• Nginx is using valid certificates from Let's Encrypt.
• I attempted to set ssl_protocols and ssl_ciphers per Sync not possible (GarminSdkError 0) while Server test is okay #42, but Nginx configuration fails because they are duplicate directives.
• I'm not certain how to override the default ssl_protocol or ssl_ciphers in Nginx Proxy Manager. Options I can enable (but haven't) are: Force SSL, HSTS Enabled, HTTP/2 Support, and HSTS Subdomains.

Edit: Looks like the defaults for ssl_protocol and ssl_ciphers for Nginx Proxy Manager are here: https://github.com/NginxProxyManager/nginx-proxy-manager/blob/master/docker/rootfs/etc/nginx/conf.d/include/ssl-ciphers.conf. ssl_protocol is the same as #42 but ssl_ciphers definitely is not.

[memen45]

Note that Test Server option connects through the connected phone, so it is not handling the SSL ciphers on the watch. If Test Server fails, the cause is most likely something else.

Are you able to browse Playlists etc from the server or do you get an error for that as well?

[cjhesse]

I can browse playlists and the songs in them. I tried playing music too. It didn't work, but it didn't return an error message either.

Is "Test Server" eventually supposed to return an error message? It just stayed at "Inlog OK" for as long as I left it there.

[memen45]

Yes, normally Test Server should return either an error message or continue to Test Completed. The only way for it to hang is if there is an unexpected exception. I do see some errors in the crash logs for your device. I will update the SubMusic app to 0.2.8, as it contains some fixes to handle these exceptions.

A second crash I noticed is an Out of Memory error, also on your device type. This occurs in debug print statements where the server response is logged. I created an issue #69 to address this, but it will take some work to fix that.

Potential quick solution would be to decrease the response limit. Currently, the default is 20 items (20 playlists or 20 songs) per request. Do you have more than 20 playlists or songs on playlists?

[memen45]

Please note I published the 0.2.8 update just now. It skips over print statements by default, as it is not needed in production. Let me know if it solves your issue. If not, we have to debug a bit further.

[cjhesse]

With 0.2.8:

• Sync fails in the same manner: GarminSdkError:0
• Test Server still makes it to "Inlog OK", but I actually get an error this time:

GarminSdkError::-403
Error HTTP -->
GarminSdkError::NETWORK_RESPONSE_OUR_OF_MEMORY

Unfortunately I do have more than 20 playlists, and all of my playlists have more than 20 songs. I could create a shorter one to see if that makes a difference.

[memen45]

Yes, please try a shorter playlist as well.

The Plex Provider actually reduces the limit after each 403 error, so if you get a 403 error in Test Server, it means that even with limit=1 the response was too large. Do you have files with a lot of metadata?

Still, the Error: 0 is not clear. Are you able to retrieve server logs for such a failed sync?

[cjhesse]

No change using a playlist of one song. I still have more than 20 playlists, however.

As far as the logs go, I didn't see anything different around the time I initiated the sync. It was just these entries among a sea of identical ones:

DEBUG - Request: [127.0.0.1:49728 (Loopback)] GET /identity (5 live) #1bf3a Signed-in
DEBUG - Completed: [127.0.0.1:49728] 200 GET /identity (5 live) 0ms 398 bytes (pipelined: 1)

Around the time I initiated the server test, I did get something different:

DEBUG - Request: [172.17.0.5:57614 (WAN)] GET /playlists?playlistType=audio (5 live) #1bf46 Page 0-19 GZIP Signed-in Token ([username]) (Microsoft Edge)
DEBUG - Setting container serialization range to [0, 19] (total=-1)
DEBUG - Completed: [172.17.0.5:57614] 200 GET /playlists?playlistType=audio (5 live) GZIP Page 0-19 39ms 1849 bytes (pipelined: 1)
DEBUG - Request: [172.17.0.5:50908 (WAN)] GET /playlists?playlistType=audio (5 live) #1bf49 Page 20-39 GZIP Signed-in Token ([username]) (Microsoft Edge)
Feb 21, 2023 20:44:01.404 [0x14ad74407b38] DEBUG - Setting container serialization range to [20, 39] (total=-1)
Feb 21, 2023 20:44:01.407 [0x14ad783f3b38] DEBUG - Completed: [172.17.0.5:50908] 200 GET /playlists?playlistType=audio (5 live) GZIP Page 20-39 6ms 1399 bytes (pipelined: 1)

Around 2 seconds after starting the test, I got this warming:
WARN - [Req#1bf4f] QueryParser: Invalid field 'having' found, ignoring.

The test ends about 6 seconds after these entries:

DEBUG - Request: [172.17.0.5:42726 (WAN)] GET /playlists/15728/items (5 live) #1bfbd Page 400-419 GZIP Signed-in Token ([username]) (Microsoft Edge)
WARN - [Req#1bfbd] QueryParser: Invalid field 'having' found, ignoring.
DEBUG - [Req#1bfbd] Setting container serialization range to [400, 419] (total=-1)
DEBUG - Completed: [172.17.0.5:42726] 200 GET /playlists/15728/items (5 live) GZIP Page 400-419 8ms 3044 bytes (pipelined: 1)

And a few seconds after the test fails, the log returns to the same two entries I mentioned at the beginning. I didn't see anything clearly marked as an error, at least within Plex Media Server.log.

As far as a large amount of metadata is concerned, I don't think so? Most of my files have embedded lyrics and your typical metadata otherwise. All (or almost all) of my files don't even have embedded artwork, as I maintain separate files for that anyway.

[memen45]

Thanks a lot for your detailed logs! Apart from the stream of /identity requests, it looks quite okay.

I see the last request for Test Server having 419 entries, that is quite a lot and might cause Out of Memory errors if there is a lot of metadata. Not sure why you get a -403 error, since I do not see requests with a smaller than 20 limit. I would expect SubMusic to lower the limit on -403, and only fail when limit=1.

[memen45]

Is the log from a Start Sync any different?

Potential solutions to fix the Test Server Out of Memory issue in SubMusic:

• add ranged functions to the (Plex, Ampache, Subsonic)Provider, this way we can prevent accumulation of all pages in memory at once.
• make the Test only load the first song, instead of all of them

For the Start Sync, the list of songs could be retrieved per page instead of all at once. That could solve an Out of Memory error.

A crash is the only way to find out the limit, so an arbitrary limit has to be set. Also, for browsing, the menu's need to become paged as well, as mentioned here

I will look into it when I find time!

[cjhesse]

The logs look essentially the same as before.

During a server test, I get this again (repeatedly, but this is the last example):

DEBUG - Request: [172.17.0.5:59182 (WAN)] GET /playlists/15728/items (2 live) #115b2 Page 420-439 GZIP Signed-in Token ([username]) (Microsoft Edge)
WARN - [Req#115b2] QueryParser: Invalid field 'having' found, ignoring.
DEBUG - [Req#115b2] Setting container serialization range to [420, 439] (total=-1)
DEBUG - Completed: [172.17.0.5:59182] 200 GET /playlists/15728/items (2 live) #115b2 GZIP Page 420-439 8ms 2972 bytes (pipelined: 1)

And this is what I get during sync:

DEBUG - Request: [172.17.0.5:39900 (WAN)] GET /playlists?playlistType=audio (2 live) #115fe Page 0-19 GZIP Signed-in Token ([username]) (Microsoft Edge)
DEBUG - Setting container serialization range to [0, 19] (total=-1)
DEBUG - Completed: [172.17.0.5:39900] 200 GET /playlists?playlistType=audio (2 live) #115fe GZIP Page 0-19 44ms 1874 bytes (pipelined: 1)
DEBUG - Request: [172.17.0.5:39912 (WAN)] GET /playlists?playlistType=audio (2 live) #11601 Page 20-39 GZIP Signed-in Token ([username]) (Microsoft Edge)
DEBUG - Setting container serialization range to [20, 39] (total=-1)
DEBUG - Completed: [172.17.0.5:39912] 200 GET /playlists?playlistType=audio (2 live) #11601 GZIP Page 20-39 7ms 1324 bytes (pipelined: 1)

Before and after that, it's just repeating loopback requests every 5 seconds or so. It seems odd that it's trying to return something on the range of [20, 39] because only one playlist is configured to sync, and that one playlist has a single song.

[paulshemrock]

Seems I run into the very same issue and error code. And yes, also with playlists with few songs.

[memen45]

Sorry for the delay. Are you sure about the logs during sync @cjhesse? These requests (/playlists?playlistType=audio) should not be received during a sync, since we already know the playlists we need for sync. Therefore, there should only be /playlists/{id}/items requests to retrieve all the songs on the playlist.