Conversion failed. The transcoder exited due to an error (Memory Allocation failures)

Raised on behalf of Christian_Hab (from ‘Temp Discourse’ on old forums)

@Christian_Hab
Since ive made a few mistakes with my first post. Here again:

Im recieving the mentioned error message when playing a movie in transcoded quality. Usually after 15-20 minutes.
Using Windows server. As far as i noticed, the movie file size / bitrate doesnt matter that much, ive got the impression that it might happen mostly with hevc files, not sure though. Bigger file sizes seem to work fine if its not hevc.
Ive tried to reinstall plex, but it didnt resolve my issue.
Heres the last few posts from the log file, a also attached the log zip folder.

Jun 20, 2018 22:25:10.509 [4468] DEBUG - Request: [192.168.178.69:53263 (Subnet)] GET /video/:/transcode/universal/session/e0cc887ce4051603-com-plexapp-android/base/01473.ts (12 live) TLS Signed-in
Jun 20, 2018 22:25:10.510 [9628] DEBUG - Completed: [192.168.178.69:53263] 404 GET /video/:/transcode/universal/session/e0cc887ce4051603-com-plexapp-android/base/01473.ts (12 live) TLS 0ms 259 bytes
Jun 20, 2018 22:25:10.622 [2776] DEBUG - Request: [192.168.178.69:53264 (Subnet)] GET /video/:/transcode/universal/session/e0cc887ce4051603-com-plexapp-android/base/01474.ts (12 live) TLS Signed-in
Jun 20, 2018 22:25:10.623 [9628] DEBUG - Completed: [192.168.178.69:53264] 404 GET /video/:/transcode/universal/session/e0cc887ce4051603-com-plexapp-android/base/01474.ts (12 live) TLS 0ms 259 bytes
Jun 20, 2018 22:25:18.753 [9832] DEBUG - NetworkServiceBrowser: SSDP arrived: 192.168.178.1 (http://192.168.178.1:49000/MediaServerDevDesc.xml)
Jun 20, 2018 22:25:18.754 [9776] DEBUG - HTTP requesting GET http://192.168.178.1:49000/MediaServerDevDesc.xml
Jun 20, 2018 22:25:18.775 [9776] DEBUG - HTTP 200 response from GET http://192.168.178.1:49000/MediaServerDevDesc.xml
Jun 20, 2018 22:25:34.805 [9636] DEBUG - Auth: authenticated user 1 as Christian_Hab
Jun 20, 2018 22:25:34.806 [8740] DEBUG - Request: [192.168.178.73:58958 (Subnet)] GET /:/websockets/notifications (7 live) TLS GZIP Signed-in Token (Christian_Hab)
Jun 20, 2018 22:25:34.806 [8740] DEBUG - WebSocket: Performing handshake from origin 
Jun 20, 2018 22:25:34.806 [8740] DEBUG - Beginning read from WebSocket
Jun 20, 2018 22:25:40.751 [9832] DEBUG - NetworkServiceBrowser: SSDP departed after not being seen for 21.980553 seconds: 192.168.178.1

Thanks for the logs. Appears to be a memory issue with the transcoder process failing to allocate memory. This shows when the problem started

Jun 20, 2018 22:24:36.692 [4468] DEBUG - Transcoder segment range: 297 - 1381
Jun 20, 2018 22:24:37.297 [8740] DEBUG - Transcoder segment range: 297 - 1382
Jun 20, 2018 22:24:37.983 [2776] DEBUG - Transcoder segment range: 297 - 1383
Jun 20, 2018 22:24:38.030 [4468] ERROR - [Transcoder] [truehd_eae @ 03a28a00] error reading output
Jun 20, 2018 22:24:38.034 [8740] ERROR - [Transcoder] Error while decoding stream #0:2: Cannot allocate memory

Could you observe the memory use by the PlexTranscoder.exe before getting the failure to see if it is getting as high as 2Gb

Is the problem repeatable with the same mkv file ? In this case it was jumanji ? Does the problem arise on a 15 minute clip from the movie ?

The memory allocation failure was about 12 minutes in.

Further to my earlier response, would like to also get more detailed logging from the transcoder. It may be a memory leak or some other issue leading to memory allocation failure

Trying to see if you get the failures with a smaller HEVC file - as the file would be needed by the development team to reproduce the issue

There is a Transcoder logging level that can be enabled by a registry edit. See TranscoderLogLevel mentioned on this support article https://support.plex.tv/articles/201105343-advanced-hidden-server-settings/

I would like you to try first with the highest level of logging trace - this needs the server verbose logging level to be enabled in addition to debug

Starting with fresh logs after plex media server restart - try and get it to fail with this error. The key is this log text Cannot allocate memory

Capture the logs zip when the error arises

If you find the trace level stops the transcoder from running - then we can repeat the test and trying TranscoderLogLevel of verbose - again this needs the server logging level to be verbose

At the end of all tests, delete the TranscoderLogLevel registry entry

Thanks

@Christian_Hab said

i’ll check the usage. yes, the crash happened at 22:24. Total ram usuage is roughly around 3,7gb, while plex takes around 1,6gb.

I also do have random short 2-3 seconds lags in between, where the cpu clocks and hard drive reads drop very drastically, but the movie continues playing after that lag. i think it might be this part of the log:

Jun 21, 2018 00:13:54.974 [8340] DEBUG - Asked for segment 346 from session.
Jun 21, 2018 00:13:55.166 [10508] DEBUG - Transcoder segment range: 325 - 346
Jun 21, 2018 00:13:55.184 [8340] DEBUG - Returning segment 346 from session: "C:\Users\Ncase M1\AppData\Local\Plex Media Server\Cache\Transcode\Sessions\plex-transcode-e0cc887ce4051603-com-plexapp-android-5e4d595b-1c4f-4e70-b2e3-291c0ea897bf\media-00346.ts"
Jun 21, 2018 00:13:55.185 [8340] DEBUG - Content-Length of C:\Users\Ncase M1\AppData\Local\Plex Media Server\Cache\Transcode\Sessions\plex-transcode-e0cc887ce4051603-com-plexapp-android-5e4d595b-1c4f-4e70-b2e3-291c0ea897bf\media-00346.ts is 451200.
Jun 21, 2018 00:13:55.200 [9628] DEBUG - Completed: [192.168.178.69:56731] 200 GET /video/:/transcode/universal/session/e0cc887ce4051603-com-plexapp-android/base/00346.ts (11 live) TLS 225ms 451200 bytes
Jun 21, 2018 00:13:55.400 [8864] DEBUG - Request: [192.168.178.69:56732 (Subnet)] GET /video/:/transcode/universal/session/e0cc887ce4051603-com-plexapp-android/base/00347.ts (11 live) TLS Signed-in
Jun 21, 2018 00:13:55.400 [8864] DEBUG - Asked for segment 347 from session.
Jun 21, 2018 00:13:55.422 [9628] DEBUG - Auth: authenticated user 1 as Christian_Hab
Jun 21, 2018 00:13:55.423 [1188] DEBUG - Request: [192.168.178.69:55859 (Subnet)] GET /:/timeline?bandwidth=5589&bufferedTime=13&containerKey=%2FplayQueues%2F7&duration=7144000&guid=com.plexapp.agents.imdb%3A%2F%2Ftt2283362%3Flang%3Den&key=%2Flibrary%2Fmetadata%2F1374&machineIdentifier=75bee92555f4d78572f1b147e73004c0a8a1e84b&playQueueItemID=6&ratingKey=1374&state=playing&time=333321&token=xxxxxxxxxxxxxxxxxxxx (10 live) TLS GZIP Signed-in Token (Christian_Hab)
Jun 21, 2018 00:13:55.423 [1188] DEBUG - Client [e0cc887ce4051603-com-plexapp-android] reporting timeline state playing, progress of 333321/7144000ms for guid=com.plexapp.agents.imdb://tt2283362?lang=en, ratingKey=1374 url=, key=/library/metadata/1374, containerKey=/playQueues/7, metadataId=1374
Jun 21, 2018 00:13:55.427 [1188] DEBUG - Play progress on 1374 'Jumanji: Welcome to the Jungle' - got played 333321 ms by account 1!
Jun 21, 2018 00:13:55.427 [1188] DEBUG - [Now] User is Christian_Hab (ID: 1)
Jun 21, 2018 00:13:55.428 [1188] DEBUG - [Now] Device is Android (SHIELD Android TV).
Jun 21, 2018 00:13:55.428 [1188] DEBUG - [Now] Profile is Android
Jun 21, 2018 00:13:55.428 [1188] DEBUG - [Now] Updated play state for /library/metadata/1374.
Jun 21, 2018 00:13:55.428 [1188] DEBUG - Statistics: (e0cc887ce4051603-com-plexapp-android) Reporting active playback in state 0 of type 1 (scrobble: 0) for account 1
Jun 21, 2018 00:13:55.431 [9636] DEBUG - Completed: [192.168.178.69:55859] 200 GET /:/timeline?bandwidth=5589&bufferedTime=13&containerKey=%2FplayQueues%2F7&duration=7144000&guid=com.plexapp.agents.imdb%3A%2F%2Ftt2283362%3Flang%3Den&key=%2Flibrary%2Fmetadata%2F1374&machineIdentifier=75bee92555f4d78572f1b147e73004c0a8a1e84b&playQueueItemID=6&ratingKey=1374&state=playing&time=333321&token=xxxxxxxxxxxxxxxxxxxx (10 live) TLS GZIP 8ms 771 bytes (pipelined: 36)
Jun 21, 2018 00:13:55.581 [10508] DEBUG - Transcoder segment range: 325 - 347
Jun 21, 2018 00:13:55.603 [8864] DEBUG - Returning segment 347 from session: "C:\Users\Ncase M1\AppData\Local\Plex Media Server\Cache\Transcode\Sessions\plex-transcode-e0cc887ce4051603-com-plexapp-android-5e4d595b-1c4f-4e70-b2e3-291c0ea897bf\media-00347.ts"
Jun 21, 2018 00:13:55.603 [8864] DEBUG - Content-Length of C:\Users\Ncase M1\AppData\Local\Plex Media Server\Cache\Transcode\Sessions\plex-transcode-e0cc887ce4051603-com-plexapp-android-5e4d595b-1c4f-4e70-b2e3-291c0ea897bf\media-00347.ts is 504404.
Jun 21, 2018 00:13:55.621 [9636] DEBUG - Completed: [192.168.178.69:56732] 200 GET /video/:/transcode/universal/session/e0cc887ce4051603-com-plexapp-android/base/00347.ts (11 live) TLS 222ms 504404 bytes
Jun 21, 2018 00:13:55.921 [1188] DEBUG - Request: [192.168.178.69:56733 (Subnet)] GET /video/:/transcode/universal/session/e0cc887ce4051603-com-plexapp-android/base/00348.ts (11 live) TLS Signed-in
Jun 21, 2018 00:13:55.922 [1188] DEBUG - Asked for segment 348 from session.
Jun 21, 2018 00:13:55.998 [8340] DEBUG - Transcoder segment range: 325 - 348
Jun 21, 2018 00:13:56.023 [1188] DEBUG - Returning segment 348 from session: "C:\Users\Ncase M1\AppData\Local\Plex Media Server\Cache\Transcode\Sessions\plex-transcode-e0cc887ce4051603-com-plexapp-android-5e4d595b-1c4f-4e70-b2e3-291c0ea897bf\media-00348.ts"
Jun 21, 2018 00:13:56.023 [1188] DEBUG - Content-Length of C:\Users\Ncase M1\AppData\Local\Plex Media Server\Cache\Transcode\Sessions\plex-transcode-e0cc887ce4051603-com-plexapp-android-5e4d595b-1c4f-4e70-b2e3-291c0ea897bf\media-00348.ts is 457216.
Jun 21, 2018 00:13:56.040 [9628] DEBUG - Completed: [192.168.178.69:56733] 200 GET /video/:/transcode/universal/session/e0cc887ce4051603-com-plexapp-android/base/00348.ts (11 live) TLS 119ms 457216 bytes
Jun 21, 2018 00:13:56.223 [10508] DEBUG - Request: [192.168.178.69:56734 (Subnet)] GET /video/:/transcode/universal/session/e0cc887ce4051603-com-plexapp-android/base/00349.ts (11 live) TLS Signed-in

@christian_hab said

Ill try to find a smaller file to reproduce this error. But that might take some time. I have the feeling those short lags might be part of the problem but still within the tolerance, so the transcoder doesnt crash completely.

Every time it lags, there are these kind of logs:

There would be separate processes - a Plex Media Server.exe process and a PlexTranscoder.exe process. The maximum for each is 2Gb - and issues may arise as it gets close to 2Gb. Normally Plex Media Server.exe process runs well below 1Gb. I am not sure about the transcoder process

You can continue for now with this same file and get the additional logging. We can look into smaller clips afterwards

@christian_hab said

Noticed, that the ram usuage of plex transcoder keeps climbing higher and higher. Added 2 screenshots. It currently reached already 3400MB.

Tryng to figure out which registry entrys to add…

@Christian_Hab said

The transcoder just crashed “Conversion failed. The transcoder exited due to an error”

At that point the ram usuage of the transcoder had reached over 3600MB. For some reason i cant attach the log though “The file failed to upload”. Is there a limit for uploads in this forum for new users ?

It is the PlexTranscoder.exe memory usage that is of interest. You would get more detail in the Performance Monitor view

Watch in Perfmon and lets get the more detailed logging

Only one registry entry
TranscoderLogLevel below HKEY_CURRENT_USER\Software\Plex, Inc.\Plex Media Server

What is the size of the zip ? If too big for forum - please upload to dropbox / google drive etc and share link

@christian_Hab said

This cant be right:

Opened up the detailed ressource monitor. Seems like the plex transcoder keeps crashing and plex is killing it and opening a new one. Had several lags, so the list is filled with plex transcoder processes, but always only one of them being aktive and being killed and removed from the list gradually.

Added the “TranscoderLogLevel” entry. Does it have to have a certain value ? “verbose” maybe ? Or is it sufficient to add the entry named “TranscoderLogLevel” ?

Activated verbose logging in plex settings and restarted.

The file size of the log file i tried to upload was smaller than the screenshots i added - 284kb

@christian_Hab said

Just copied the content of the Plex Media Server in a new .txt document. Now i was able to upload it here.

Here another log of another crash - verbose enabled but server not restarted at that point yet though.

see my first post on the subject. What i suggested:

would like you to try first with the highest level of logging trace - this needs the server verbose logging level to be enabled in addition to debug

So TranscoderLogLevel value of trace
and server debug + verbose in settings / server / general /show advanced

Log file type not permitted. Zip it to attach

@christian_Hab said

thanks, changed the reg entry value to trace.
Debugging and verbose logging in plex settings enabled.

Tried to upload as a zip, didnt work either.
Uploaded to Dropbox instead:

Thanks - do you recall what time the trace level set and transcoded streaming started ?
I do not have the record of the start

The two log files are not contingous

It appears that Plex Media Server.2.log is the log with the right level of logging

Don’t seem to have more logging from the transcoder than what we had before

Could you see if using mkvtools to pick first 20 mins gives same issue.
If it does, please upload to dropbox and will try and get the issue reproduced

@christian_Hab said

Im not that familiar with plex logs but apparently the transcoder process keeps crashing over and over again because it cant allocate the memory.

I can see the killed trancoder processes pile up in the tast manager while plex tries to open them up again to keep the transcode running, causing the lags.

For some reason i cant get any transcode running anymore at all. Even with direct playback of a different movie i do have stuttering and crashing transcoder processes in the background.

To me this sounds like my memory might be defective even though its new. Will run a few memory tests.

i dont quite understand. Record a 20 minute clip using mkvtools ?