Movie playback delayed by 15-20 seconds, TV shows start right away. Same result applies to View XML!

Plex Media Server NAS & Devices
,
1

Server Version#: 1.31.2.6810
Player Version#: Plex Web Version 4.103.2

I’ve been troubleshooting this for a few days assuming it was some thing with my environment. Now I’m jumping down a different rat hole. I have a 15 to 25 or 30 second delay when I start a movie playback. I’ve been checking transcode settings analyze the library, removed, extras, messing with my transcodes, Looking at other people having the same thread. I’m past the hardware transcode issue with the newest release and Nvidia drivers.

What’s really interesting is that the same result happens when I look at the XML. I have two different movie libraries in two different TV show libraries and get the same results on sources from either one.

I’ve optimized, refreshed metadata, cleared codecs, cleared cache, checked perms, I’ve done a full db reload and import using the dbrepair.sh script.

Can anyone confirm similar results on inspection of the XML files, maybe is due to a difference in the schema? I had opened the XML file looking to see the media ID in order to look through my verbose logs. That’s when I noticed that I had the delay even on a movie.

I’m getting ready to start yet another thread on why movie playback spins and takes longer, lots of people have worked on that before, and I’ve tried it from the Windows player, my iPhone, my Roku, turned off subtitles, tried to make sure it was a low bit rate simple file with simple audio and still have a delay. I did playback of a h264 AAC 2 hour TV show and movie and had same results.

2

Movie xml request 14 seconds Vs 1 second for TV show

Mar 17, 2023 13:01:56.290 [0x151d68ba7b38] DEBUG - Request: [192.168.7.143:35447 (Allowed Network (Subnet))] GET /library/metadata/150676?checkFiles=1&includeAllConcerts=1&includeBandwidths=1&includeChapters=1&includeChildren=1&includeConcerts=1&includeExtras=1&includeFields=1&includeGeolocation=1&includeLoudnessRamps=1&includeMarkers=1&includeOnDeck=1&includePopularLeaves=1&includePreferences=1&includeRelated=1&includeRelatedCount=1&includeReviews=1&includeStations=1 (14 live) #17dc9 TLS GZIP Signed-in Token (esilberberg) (Chrome)

Mar 17, 2023 13:01:56.361 [0x151d68ba7b38] DEBUG - [Req#17dc9] We’re going to try to auto-select an audio stream for account 1.

Mar 17, 2023 13:01:56.361 [0x151d68ba7b38] DEBUG - [Req#17dc9] Selecting best audio stream for part ID 362265 (language: en)

Mar 17, 2023 13:01:56.361 [0x151d68ba7b38] DEBUG - [Req#17dc9] Audio Stream: 919452, Subtitle Stream: -1

Mar 17, 2023 13:02:09.127 [0x151d68ba7b38] DEBUG - [Req#17dc9] It took 10.000000 ms to retrieve 134 items.

Mar 17, 2023 13:02:09.136 [0x151d68ba7b38] DEBUG - [Req#17dc9] It took 0.000000 ms to retrieve 113 items.

Mar 17, 2023 13:02:09.168 [0x151d68ba7b38] DEBUG - [Req#17dc9] We’re going to try to auto-select an audio stream for account 1.

Mar 17, 2023 13:02:09.168 [0x151d68ba7b38] DEBUG - [Req#17dc9] Selecting best audio stream for part ID 1710 (language: en)

Mar 17, 2023 13:02:09.168 [0x151d68ba7b38] DEBUG - [Req#17dc9] Audio Stream: 114300, Subtitle Stream: -1

Mar 17, 2023 13:02:09.173 [0x151d6dbf6b38] DEBUG - Completed: [192.168.7.143:35447] 200

TV xml request

Mar 17, 2023 13:13:01.017 [0x151d6a4b9b38] DEBUG - Request: [192.168.7.143:35873 (Allowed Network (Subnet))] GET /library/metadata/139514?checkFiles=1&includeAllConcerts=1&includeBandwidths=1&includeChapters=1&includeChildren=1&includeConcerts=1&includeExtras=1&includeFields=1&includeGeolocation=1&includeLoudnessRamps=1&includeMarkers=1&includeOnDeck=1&includePopularLeaves=1&includePreferences=1&includeRelated=1&includeRelatedCount=1&includeReviews=1&includeStations=1 (11 live) #180a8 TLS GZIP Signed-in Token (esilberberg) (Chrome)

Mar 17, 2023 13:13:01.059 [0x151d6a4b9b38] DEBUG - [Req#180a8] We’re going to try to auto-select an audio stream for account 1.

Mar 17, 2023 13:13:01.059 [0x151d6a4b9b38] DEBUG - [Req#180a8] Selecting best audio stream for part ID 302644 (language: en)

Mar 17, 2023 13:13:01.059 [0x151d6a4b9b38] DEBUG - [Req#180a8] Audio Stream: 761792, Subtitle Stream: -1

Mar 17, 2023 13:13:01.068 [0x151d6dbf6b38] DEBUG - Completed: [192.168.7.143:35873] 200 GET

3

Mounted the same movie library inside of a VM and the XML renders immediately and the movie playback starts immediately. I kind of like to troubleshoot instead of just deleting and going nuclear. It’s just the movie portion of the database. Thought it might be useful in case this is related to other people who have had the 15 to 30 sec delay before movie playback

4

I also tried deleting one of the movie libraries and re-adding. The speed increased a hair but not much.

5

I may have found it!

2 days of log analysis under verbose showed me some delays but no answer, websocket waiting etc.
So I played with the xml queries directly. Learned stuff many of you web developers already know but new to me. The logs made it clear as a client server interface it comes in via http request and you get what you ask for.

So I learned just change the metadata id key to get a movie or tv show by id. Then saw all the include https://myserver.plex.direct:32400/library/metadata/126830?checkFiles=1&includeAllConcerts=1&includeBandwidths=1&includeChapters=1&includeChildren=1&includeConcerts=1&includeExtras=1&includeFields=1&includeGeolocation=1&includeLoudnessRamps=1&includeMarkers=1&includeOnDeck=1&includePopularLeaves=1&includePreferences=1&includeRelated=1&includeRelatedCount=1&includeReviews=1&includeStations=1&X-Plex-Token=NunYaBusiness

Changed out my ids to confirm the delay on a movie versus a TV show. Then started changing with the included elements. Had been changing one at a time setting one to zero. But that was taking too long so I did a global search and replace and changed all of them and it came up instantly. So then I started changing the zero back to one to see what caused the delay. It was the include related.

Then I did a compare on the resulting XML between a fast load and a slow load and the main difference was the label and tag stuff that had come in from my plex meta manager groups.

I’ll have to wait till the weekend to figure out how to reduce or strip that information. But I think I just added too much metadata and too many relationships and individual movie lookups were clobbering the database. I’m not gonna mark this as solved but even having a good sense of where the problem was coming from makes me feel a lot better.

6

yup when I set includeRelated to 0 the movie loads instantly.
Is that tags due to and labels?

7

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