Explain this image [TRANSODER/SYNC BUG] - FIXED in 0.9.17.3

Can someone explain to me why Plex continues to report that the transcoder is running (according to PlexPy at 7.6x) for a file that appears to already be 100% transcoded? It will report this (speed of 7.6) for the duration of the stream.

I ask because this happens a lot and anytime it shows that speed anything above 0 it will cause background transcodes (mobile syncs, media optimizing) to either pause or drastically slow down even though my CPU is hardly being taxed. The kicker is, it’s def. not actually transcoding while it’s reporting that it is because I’m watching the Plex New Transcoder process in ‘top’ (linux) an it’s doing basically nothing.

No explanation can be given without seeing the Plex Media Server.log file with time stamps from the beginning of the playback (seek for lines starting with MDE:)

Also, a mediainfo XML of the video in question would be useful.

Be also advised that the detail view within PlexPy is sometimes different from the one you can see in Plex Web / Activity - Now Playing. Compare the two.

Do you have Prioritize streaming transcodes enabled?

Prioritize streaming transcodes
This option lets you choose how to handle background transcoding tasks. “Background transcoding” would be transcode jobs for Mobile Sync, Cloud Sync, or Media Optimizer. So, when you have someone actively streaming and the stream requires transcoding, you can choose to have the background transcoding tasks paused by choosing to prioritize the streaming transcodes.
For low-powered systems (such as many NAS devices), pausing background transcoding tasks is recommended so as to not overburden the CPU.
Tip!: Background transcoding tasks are run as a lower priority process by default so that they'll have less of an impact on normal usage, but they can still affect things on low-powered systems.

@OttoKerner said:
No explanation can be given without seeing the Plex Media Server.log file with time stamps from the beginning of the playback (seek for lines starting with MDE:)

Also, a mediainfo XML of the video in question would be useful.

Be also advised that the detail view within PlexPy is sometimes different from the one you can see in Plex Web / Activity - Now Playing. Compare the two.

Logs will be forthcoming soon. But Plex Web / Activity does not show details about transcode speed/throttling. All it show is whether or not the stream is a transcode, direct play or direct stream. In this case it shows it’s a Transcode.

@hthighway said:
Do you have Prioritize streaming transcodes enabled?

Prioritize streaming transcodes
This option lets you choose how to handle background transcoding tasks. “Background transcoding” would be transcode jobs for Mobile Sync, Cloud Sync, or Media Optimizer. So, when you have someone actively streaming and the stream requires transcoding, you can choose to have the background transcoding tasks paused by choosing to prioritize the streaming transcodes.
For low-powered systems (such as many NAS devices), pausing background transcoding tasks is recommended so as to not overburden the CPU.
Tip!: Background transcoding tasks are run as a lower priority process by default so that they'll have less of an impact on normal usage, but they can still affect things on low-powered systems.

Nope, that’s always been disabled for me since I have 16 CPU threads to work with.

OK just tested this again this is what I noticed. Until the transcoding get to 100%, it will transcode for a bit then throttle down to 0.0 at which point my background transcodes will resume. But once it gets to 100%, it get stuck transcoding at a specific speed and it never stops until the file stream ends and thus my background transcodes slow to a craw until the stream is done.

Will get some logs and media info soon.

@IamSpartacus said:
Logs will be forthcoming soon. But Plex Web / Activity does not show details about transcode speed/throttling. All it show is whether or not the stream is a transcode, direct play or direct stream. In this case it shows it’s a Transcode.

It also shows a little (i) icon. Click it.

@OttoKerner said:

@IamSpartacus said:
Logs will be forthcoming soon. But Plex Web / Activity does not show details about transcode speed/throttling. All it show is whether or not the stream is a transcode, direct play or direct stream. In this case it shows it’s a Transcode.

It also shows a little (i) icon. Click it.

The (i) does not show detailed info. Collecting logs now, will post shortly once transcode reaches 100%.

Ok here is the log from when the video first played to about 1 minute after it hit 100% and starting reporting that it was transcoding at 13.2x speed in PlexPy as well as the media info for this particular file (though this happens with many). What’s weird is that it showed the transcoder was throttled for about 90% of the video playback but as soon as it hits 100% it starts reporting that it’s transcoding.

EDIT: I can also confirm that if I PAUSE the video, Plex still reports that it’s transcoding and thus my background transcodes just sit there playing the waiting game. This is a real killer because if a remote uses starts streaming one of these files and then pauses for an extended period of time, they are essentially pausing my background transcodes until they unpause and finish the stream.

Judging from that mediainfo, it will definitely be transcoded when playing on a lot of clients. (XViD vs AVC video codec).

Question 1: did you restart PMS after toggling the ‘priority checkbox’?
Question 2: are you running PMS virtualised or normally in the host OS?

@OttoKerner said:
Judging from that mediainfo, it will definitely be transcoded when playing on a lot of clients. (XViD vs AVC video codec).

Question 1: did you restart PMS after toggling the ‘priority checkbox’?

Yes, I’ve rebooted my server many times since I’ve toggled the priority option.

Question 2: are you running PMS virtualised or normally in the host OS?

Running Plex in docker.

According to your log transcoding started at

May 10, 2016 12:49:53 [0x7f2e34fff700] DEBUG - Job running:

ended at:

May 10, 2016 13:09:58 [0x7f2e40fff700] DEBUG - Completed: [127.0.0.1:45508] PUT /video/:/transcode/session/9m3zg0zcn03qf0ih724wa02j4i/progress?progress=100.0&size=304574353&speed=13.2&remaining=0 (11 live) 1ms 289 bytes 206

So according to your log it took about 20 minutes for the transcode to finish and the entire log ends at 13:11 which means it is transcoding almost the full length of the playback. Doing a count for ‘Idle’ in your log reveals 592 matches meaning the transcoder is sitting idle for a good portion for the majority of the time as is expected with the reported speed.

I believe PlexPy reads the log to report it’s information so the reason it reports the transcoding speed after transcode has completed would most likely be to it reading the transcode lines earlier and not switching over when the transcode does actually complete.

@jmckee said:
According to your log transcoding started at

May 10, 2016 12:49:53 [0x7f2e34fff700] DEBUG - Job running:

ended at:

May 10, 2016 13:09:58 [0x7f2e40fff700] DEBUG - Completed: [127.0.0.1:45508] PUT /video/:/transcode/session/9m3zg0zcn03qf0ih724wa02j4i/progress?progress=100.0&size=304574353&speed=13.2&remaining=0 (11 live) 1ms 289 bytes 206

So according to your log it took about 20 minutes for the transcode to finish and the entire log ends at 13:11 which means it is transcoding almost the full length of the playback. Doing a count for ‘Idle’ in your log reveals 592 matches meaning the transcoder is sitting idle for a good portion for the majority of the time as is expected with the reported speed.

I believe PlexPy reads the log to report it’s information so the reason it reports the transcoding speed after transcode has completed would most likely be to it reading the transcode lines earlier and not switching over when the transcode does actually complete.

Whatever the reporting issue is, it’s affecting the rest of my background transcodes. That’s the key factor here. That’s what needed to be corrected. at that 13:09:58 you referenced onwards, all my background transcodes (syncs) just sit in a paused state waiting for an opportunity to start again. And that doesn’t happened until the video stream is finished/closed.

@IamSpartacus said:
Whatever the reporting issue is, it’s affecting the rest of my background transcodes. That’s the key factor here. That’s what needed to be corrected. at that 13:09:58 you referenced onwards, all my background transcodes (syncs) just sit in a paused state waiting for an opportunity to start again. And that doesn’t happened until the video stream is finished/closed.

According to your server logs the transcode ends successfully and reports that it is no longer transcoding:

May 10, 2016 13:09:58 [0x7f2e2e7ff700] DEBUG - Universal transcode session finished reading output.
May 10, 2016 13:09:58 [0x7f2e2e7ff700] DEBUG - Finished universal transcode output thread
May 10, 2016 13:09:58 [0x7f2e2e7ff700] DEBUG - Notifying stream that data is complete.

However, the sync appears to actually be causing a failure with a specific item that starts about a minute and half in:

May 10, 2016 12:51:34 [0x7f2e26ffe700] WARN - Held transaction for too long (…/Sync/SyncItemGenerator.cpp:96): 0.120000 seconds
May 10, 2016 12:51:35 [0x7f2e26ffe700] WARN - Held transaction for too long (…/Sync/SyncItemGenerator.cpp:96): 0.200000 seconds
May 10, 2016 12:51:35 [0x7f2e26ffe700] ERROR - LPE: unknown item 27650.
May 10, 2016 12:51:35 [0x7f2e26ffe700] ERROR - Sync: failed to generate query for path library://c43009c3-96fb-4adc-b706-a8be08da8ab3/item/%2Flibrary%2Fmetadata%2F27650 in sync item 9633345
May 10, 2016 12:51:35 [0x7f2e26ffe700] ERROR - Sync: skipping items for sync list 9220584, sync item 9633345: unable to generate sync set query
May 10, 2016 12:51:35 [0x7f2e26ffe700] ERROR - LPE: unknown item 22838.
May 10, 2016 12:51:35 [0x7f2e26ffe700] ERROR - Sync: failed to generate query for path library://c43009c3-96fb-4adc-b706-a8be08da8ab3/item/%2Flibrary%2Fmetadata%2F22838 in sync item 9633346
May 10, 2016 12:51:35 [0x7f2e26ffe700] ERROR - Sync: skipping items for sync list 9220584, sync item 9633346: unable to generate sync set query
May 10, 2016 12:51:35 [0x7f2e26ffe700] WARN - Held transaction for too long (…/Sync/SyncItemGenerator.cpp:96): 0.150000 seconds

I’m pretty sure I had the Syncs paused while doing this test. I will compile another log with no items at all in the Sync/Conversion queue and see what that looks like.

I’m sorry but what I’m seeing here just isn’t acceptable. I have a single person “transcoding” an MKV even though my CPU is basically idle and the Transcoder is not actually doing anything. But because Plex seems to think it’s still transcoding, my background transcodes are just sitting there doing nothing until the entire stream (and the next one, and the next one) finishes.

At this point I might as well not even have Sync or Optimized Versions because I can’t use them during any of the hours I’m actually awake.

"Transcoded" stream

Media Info of MKV being "transcoded"

CPU Sitting Idle because there’s no actual transcoding happening

Optimized versions doing nothing even though CPU is idle

But yet, as long as that grey bar doesn’t hit 100%, transcoder is throttled and background syncs resume [Pulls hair out!].

I haven’t looked at your logs but what you describe sounds like the intended behavior.

When you start playback, PMS transcodes for a full minute to build up a reserve, once this is done, it will go idle. Depending on how much it processed in that time, there may be enough time for the background processes to kick in. PMS only wants to transcode ahead of playback by a small margin, so once the transcoder kicks back on, it may only be active for a second, then be off until the next segment is needed which may only be a few seconds later. This isn’t enough time for the back-ground processes to really get going, so they will be idle until the transcoder is done with the file being played.

@MovieFan.Plex said:
I haven’t looked at your logs but what you describe sounds like the intended behavior.

When you start playback, PMS transcodes for a full minute to build up a reserve, once this is done, it will go idle. Depending on how much it processed in that time, there may be enough time for the background processes to kick in. PMS only wants to transcode ahead of playback by a small margin, so once the transcoder kicks back on, it may only be active for a second, then be off until the next segment is needed which may only be a few seconds later. This isn’t enough time for the back-ground processes to really get going, so they will be idle until the transcoder is done with the file being played.

Did you look at my last post? The transcoder isn’t doing anything. I watch the CPU very closely once PlexPy shows the grey bar (what I believe to be the amount of the file that’s been transcoded) is at 100%, it just sits there idle. That is my problem. No transcoding is actually taking place yet it’s putting a hold on all background transcodes. This behavior makes zero logical sense.

I don’t know what PlexPy shows, but I have a hard time believing the transcoder processed 64% of the file while still at 7% playback. Do you have the PMS log for this time frame?

It’s a 350MB file and I have 16 CPU threads. I have no doubt my CPU can transcode that far ahead when it’s the only things running. I don’t have the log for this one but I will reproduce the same scenario with a clean log and post it later this evening.

@MovieFan.Plex’s point is easy to understand when you figure out how transcoding works.

First off, there’s a switch in the settings that determines how far ahead the transcoder will try to stay in front of the video that is currently streaming. This is found at Settings > Transcoder > Transcoder default throttle buffer.

It’s used to tell Plex how many seconds in advance you want Plex to transcode, in relation to the current playback spot. (sort of.) What really happens is the client requests the next “block” and the server transcodes the next block or two + the time in this setting to stay ahead of your playing.

While you are watching ANYTHING that requires transcoding, until the stream is done, the transcoder is “tied” up or in use. At least this has been my experiences with it and the OM feature. The only time the transcoder isn’t considered in use, is when you Direct Play something while you are streaming. Then the OM feature can make as many files as it can, until you start transcoding a different video again.

There isn’t really an easy way to get around all of this, if your media is stored in file containers or codecs that will require transcoding on some or all of your clients. Short of doing a conversion outside of Plex itself, as long as you have a stream open which requires transcoding, then the OM versions can’t be made, whether the transcoder is actually running on the media or not. (At least that has been my personal observations on my own media.)

Conversion scripts, apps like HandBrake or similar can be used to do conversions as well as the built in OM feature, and are likely to produce a higher quality conversion. They are going to require more efforts on your part to make sure it all happens. But the quality differences are worth the efforts to get things set up IMO.

I personally use @cayars conversion scripts on any media I have prior to adding it to a Plex library. The reason is pretty simple, actually… The media starts its life in my library already in the best format available to Direct Play. Now the only times my server transcodes is when the stored bitrate is higher than the client is set to, the levels are not 4.0 or 4.1, or I have something set up wrong on a client app.

Also keep in mind that even though PlexPy is using the API for getting most of its data from the server, it’s not always showing something exactly as it is on the server. It does a pretty good job, but it’s not 100%. Until more calls for the API are added, the best PlexPy can do on some things is an educated guess. And it’s been my experience that the transcode bar on the playing stream is one of those “educated guess” situations. Until PlexPy is built into PMS and the Web App itself, or until more calls are made in the API, this is the best you can expect from a 3rd party tool.

Don’t get me wrong! This tool is GREAT for the historical information it provides ALONE! But it’s not going to give you the information that Plex itself could give, if the Web App had the interface to allow this type of reporting.

If all of this is still “unacceptable” well, I’m sorry. There is always a difference between expectations and reality. And the reality is, this is what we have. What we all want is something built by the Plex Team, using Plex’s own tools built into the Plex Web App itself. Until we get that, we have to face it, we gets what we gets.