Synced items unavailable via API after service restart unless manually refreshed

Plex Media Server Desktops & Laptops
1

Since upgrading to 1.13.4.5271 on Ubuntu 16.04.4 LTS last week (and persisting in 1.13.5.5291 today), I’ve been encountering an issue with the server showing synced items in an unknown state immediately after service restart until the Refresh button is manually clicked

This results in those items, although playable on the device it’s synced to, being unreadable to other systems that interact with the API.

When trying to access http://[pms ip]:32400/sync/items/[item id]?X-Plex-Token=[TOKEN] prior to clicking the refresh button in Web UI > Activity > Sync the server throws a 404. After clicking refresh the synced item XML renders as expected.

This is super annoying when using a service like Tautulli to notify on stream playback status as it effectively breaks connectivity until PMS is manually refreshed server-side. Shouldn’t the sync item refresh occur automatically on service restart?

2

Hopefully you know what I’m going to ask for next? :slight_smile:

  1. Please verify DEBUG logging is enabled, VERBOSE Is disabled
  2. Recreate it
  3. Wait 15 seconds
  4. Gather the logs (Settings - Server - Help -Download Logs)
  5. Attach the ZIP so I can see what’s happening
3

I restarted PMS, verified in Activity > Sync > [Device] that the synced item had a question mark.
I verified that /sync/items/27866712 was throwing a 404 and started playing the same item on my device. PMS Activity showed it playing but API access failed due to the aforementioned 404. I then stopped playback, then clicked the refresh button in Activity > Sync and verified that the item banner appeared correctly and /sync/items/27866712 was again accessible. Started playback again on device and API access was properly functioning again.

Plex Media Server Logs_2018-07-26_14-31-43.zip (2.6 MB)

4

Several issues.

  1. Database corruption. (Power fail / abrupt power off? )
  2. Extreme database fragmentation. (Automatic optimization and autobackup enabled in Scheduled Tasks which run while the system is known to be running?)
  3. Downstream errors are the aforementioned Sync errors

Choices:

  1. Revert to a previous database backup, force scan and refresh metadata for all libary sections, delete and regenerating all sync lists if the corruption is further back than database records retain.
  2. Erase /var/lib/plexmediaserver/Library and setup as a fresh server
Jul 26, 2018 14:29:40.937 [0x7fd71b7ff700] DEBUG - EPG[onconnect]: Purging 0 airings which completed in the past.
Jul 26, 2018 14:29:40.941 [0x7fd7143fe700] DEBUG - Activity: registered new activity b1c03c59-2476-4dc6-a87a-de2a7caaad83 - Processing subscriptions
Jul 26, 2018 14:29:40.961 [0x7fd71affe700] DEBUG - EPG[onconnect]: Next thing to start/end is at 2018-07-26 18:30:00 (in 21 seconds)
Jul 26, 2018 14:29:41.212 [0x7fd70bfff700] WARN - SLOW QUERY: It took 370.000000 ms to retrieve 30 items.
Jul 26, 2018 14:29:41.212 [0x7fd70bfff700] DEBUG - HTTP requesting GET https://plex.tv/api/v2/features?X-Plex-Token=xxxxxxxxxxxxxxxxxxxx
Jul 26, 2018 14:29:41.212 [0x7fd6fe3ff700] ERROR - Sync: could not get sync list 21181592, sync item 25491394 to update status
Jul 26, 2018 14:29:41.212 [0x7fd6fe3ff700] ERROR - Sync: could not get sync list 21181592, sync item 25491426 to update status
Jul 26, 2018 14:29:41.212 [0x7fd6fe3ff700] ERROR - Sync: could not get sync list 21181592, sync item 25509546 to update status
Jul 26, 2018 14:29:41.212 [0x7fd6fe3ff700] ERROR - Sync: could not get sync list 21181592, sync item 25509576 to update status
Jul 26, 2018 14:29:41.212 [0x7fd6fe3ff700] ERROR - Sync: could not get sync list 21181592, sync item 25509609 to update status
Jul 26, 2018 14:29:41.213 [0x7fd6fe3ff700] ERROR - Sync: could not get sync list 21181592, sync item 25509651 to update status
Jul 26, 2018 14:29:41.213 [0x7fd6fe3ff700] ERROR - Sync: could not get sync list 22796347, sync item 27866712 to update status
Jul 26, 2018 14:29:41.213 [0x7fd6fe3ff700] ERROR - Sync: could not get sync list 10091843, sync item 27935172 to update status
Jul 26, 2018 14:29:41.213 [0x7fd6fe3ff700] ERROR - Sync: could not get sync list 10091843, sync item 27935194 to update status
Jul 26, 2018 14:29:41.213 [0x7fd6fe3ff700] ERROR - Sync: could not get sync list 10091843, sync item 27935210 to update status
Jul 26, 2018 14:29:41.213 [0x7fd6fe3ff700] ERROR - Sync: could not get sync list 10091843, sync item 27935227 to update status
Jul 26, 2018 14:29:41.213 [0x7fd6fe3ff700] ERROR - Sync: could not get sync list 10091843, sync item 27935235 to update status
Jul 26, 2018 14:29:41.213 [0x7fd6fe3ff700] ERROR - Sync: could not get sync list 10091843, sync item 27935255 to update status
Jul 26, 2018 14:29:41.213 [0x7fd6fe3ff700] ERROR - Sync: could not get sync list 10091843, sync item 27935260 to update status
Jul 26, 2018 14:29:41.213 [0x7fd6fe3ff700] ERROR - Sync: could not get sync list 10091843, sync item 27935293 to update status
Jul 26, 2018 14:29:41.213 [0x7fd6fe3ff700] ERROR - Sync: could not get sync list 10091843, sync item 27936511 to update status
Jul 26, 2018 14:29:41.213 [0x7fd6fe3ff700] ERROR - Sync: could not get sync list 10091843, sync item 27938401 to update status
Jul 26, 2018 14:29:41.213 [0x7fd6fe3ff700] ERROR - Sync: could not get sync list 10091843, sync item 27938910 to update status
Jul 26, 2018 14:29:41.213 [0x7fd6fe3ff700] ERROR - Sync: could not get sync list 10091843, sync item 27940094 to update status
Jul 26, 2018 14:29:41.213 [0x7fd6fe3ff700] ERROR - Sync: could not get sync list 10091843, sync item 27940493 to update status
Jul 26, 2018 14:29:41.213 [0x7fd6fe3ff700] ERROR - Sync: could not get sync list 10091843, sync item 27940726 to update status
Jul 26, 2018 14:29:41.213 [0x7fd6fe3ff700] ERROR - Sync: could not get sync list 10091843, sync item 27941689 to update status
Jul 26, 2018 14:29:41.213 [0x7fd6fe3ff700] ERROR - Sync: could not get sync list 10091843, sync item 27942044 to update status
Jul 26, 2018 14:29:41.213 [0x7fd6fe3ff700] ERROR - Sync: could not get sync list 10091843, sync item 27942592 to update status
Jul 26, 2018 14:29:41.213 [0x7fd6fe3ff700] ERROR - Sync: could not get sync list 10091843, sync item 28333833 to update status
Jul 26, 2018 14:29:41.213 [0x7fd6fe3ff700] ERROR - Sync: could not get sync list 10091843, sync item 28333848 to update status
Jul 26, 2018 14:29:41.213 [0x7fd6fe3ff700] ERROR - Sync: could not get sync list 10091843, sync item 28374143 to update status
Jul 26, 2018 14:29:41.213 [0x7fd6fe3ff700] ERROR - Sync: could not get sync list 10091843, sync item 28407985 to update status
Jul 26, 2018 14:29:41.213 [0x7fd6fe3ff700] ERROR - Sync: could not get sync list 10091843, sync item 28975171 to update status
Jul 26, 2018 14:29:41.213 [0x7fd6fe3ff700] ERROR - Sync: could not get sync list 10091843, sync item 28975216 to update status
Jul 26, 2018 14:29:41.243 [0x7fd706bff700] WARN - Waited one whole second for a busy database.
Jul 26, 2018 14:29:41.314 [0x7fd71dbfe700] ERROR - SQLITE3:0x10, 11, database corruption at line 59437 of [fc49f556e4]
Jul 26, 2018 14:29:41.314 [0x7fd71dbfe700] ERROR - SQLITE3:0x10, 11, database corruption at line 59479 of [fc49f556e4]
Jul 26, 2018 14:29:41.314 [0x7fd71dbfe700] ERROR - SQLITE3:0x10, 11, statement aborts at 13: [DROP TABLE IF EXISTS ldata_77_wc1;] database disk image is malformed
Jul 26, 2018 14:29:41.316 [0x7fd722bff700] DEBUG - HTTP 200 response from GET https://plex.tv/media/providers?X-Plex-Token=xxxxxxxxxxxxxxxxxxxx```
5

We had this same conversation a year ago with no followup

Unfortunately I really cannot afford to lose my years of data to resolve what amounts to be a small annoyance and has no affect on functionality.
I wish I’d been able to address the supposed corruption when it occurred but there was no sign of an issue then and only came upon it by chance while looking for solutions to other issues.

6

Respectfully,
If it is such a small annoyance, unable or unwilling to effect corrective action, why did you post?

7

To be sure, you’re not trying to be respectful but to admonish me for not wanting to nuke my PMS database and rebuild from scratch something that has been cultivated for years to fix a minor bug with a simple workaround. I’ve actually made a very sensible cost benefit analysis of the situation.

But respectfully, you’ve ignored the fact that this issue only cropped up last week with the update to 1.13.4.5271 and was hitherto a non-issue despite the DB corruption you’ve claimed to be the culprit being nearly a year old, as evident in my post on these very forums when I first noticed it. That, and the fact that this issue was originally reported to the Tautulli team a week ago by others makes your diagnosis seem unlikely, unless they too have the same undetected DB corruption affecting nothing else.

In any event, I will try to rebuild my server from scratch and manually import library metadata myself when I have the time to engage in such an effort. I’ll report back if it’s successful in resolving this bug or not.

8

After a full rebuild of my library (took nearly a full week), the sync status of items in Activity > Sync still shows up as unknown after every service restart and requires manually clicking the refresh button in webUI to populate. However, the API access to those synced items does appear to be working again without going through that step. This was only a quick smoke test and I’ll update issue as resolved after a few days of real use.

9

Unfortunately @ChuckPA the issue was not resolved by a full rebuild of my PMS database.
After restarting service and starting playback of a synced Music item, the sync item XML element is again throwing 404 until manual refresh in webUI. The same errors about sync list occur, but there are no DB corruption warnings to be found:
Plex Media Server Logs_2018-08-08_09-31-58.zip (5.6 MB)
Let me know if there’s any additional troubleshooting details you require to report the issue.

10

I’ve reconfirmed that this is still an issue after a few system restarts: sync items require manual refresh in webUI before the corresponding XML page is generated.

11

This bug still exists in Version 1.13.6.5339

12

There is a timing problem in Plex Media Server that is being fixed in 1.13.8

Aug 08, 2018 09:22:43.171 [0x7f8a9a3fd700] WARN - Sync: Couldn't get sync lists without subscription.

Basically sync feature appeared as not enabled at the start

1 Like
13

Thanks so much! Very pleased to see that this was taken into consideration.

14

This topic was automatically closed 90 days after the last reply. New replies are no longer allowed.