I am getting Plex playback errors on my Roku Ultra 4640 in random places on mkv movies used to play without errors previously. I can get the error 20 seconds in or up to 10 minutes. The Ultra uses optical out to connect to my receiver and it must transcode audio to EAC3. Plex server is running on a dedicated Pi4 with a USB HD . Appears to me that the first occurrence of an error is the “EAE timeout! EAE not running, or wrong folder” followed by “Transcoder - error reading output” “Audio Encoding failed”. I haven’t made any changes on the Server other than adding a few movies to the library. Pi4 never exceeds 20% cpu while transcoding so it does not appear to be getting taxed.
Plex server log playing Abominable transcoding from TrueHD 7.1
Mar 19, 2021 19:43:46.262 [0x9c7fb430] DEBUG - [Transcode/da2a97c4-9e7c-4d19-ae2a-a93c018cf55d-877] Asked for segment 706 from session.
Mar 19, 2021 19:43:46.262 [0x9c7fb430] DEBUG - [Transcode/da2a97c4-9e7c-4d19-ae2a-a93c018cf55d-877] Returning segment 706 from session
Mar 19, 2021 19:43:46.262 [0x9c7fb430] DEBUG - Content-Length of /var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Cache/Transcode/Sessions/plex-transcode-da2a97c4-9e7c-4d19-ae2a-a93c018cf55d-877-b55c169d-b73b-41ea-a140-423ec4c8e82d/media-00706.ts is 2938252 (of total: 2938252).
Mar 19, 2021 19:43:46.357 [0xb0cfe430] DEBUG - Completed: [192.168.1.119:33748] 200 GET /video/:/transcode/universal/session/da2a97c4-9e7c-4d19-ae2a-a93c018cf55d-877/base/00706.ts?protocol=hls&mediaIndex=0&waitForSegments=1 (7 live) 95ms 2938252 bytes (pipelined: 609)
Mar 19, 2021 19:43:46.357 [0xb0cfe430] DEBUG - Removed transcode data consumer, active count 1 => 0
Mar 19, 2021 19:43:46.738 [0xa4ef8430] ERROR - [Transcoder] [eac3_eae @ 0x17d5120] error reading output
Mar 19, 2021 19:43:46.738 [0x9cffc430] DEBUG - Play progress on 27163 ‘Abominable’ - got played 667000 ms by account 1!
Mar 19, 2021 19:43:46.738 [0x9cffc430] DEBUG - [Now] User is sample.email@gmail.com (ID: 1)
Mar 19, 2021 19:43:46.739 [0x9cffc430] DEBUG - [Now] Device is Roku (Roku Ultra).
Mar 19, 2021 19:43:46.739 [0x9cffc430] DEBUG - [Now] Profile is Roku-7.x
Mar 19, 2021 19:43:46.739 [0x9cffc430] DEBUG - [Now] Updated play state for /library/metadata/27163.
Mar 19, 2021 19:43:46.739 [0x9cffc430] DEBUG - Statistics: (0fd20eaf6764828fbae1ff8d9f43852b) Reporting active playback in state 0 of type 1 (scrobble: 0) for account 1
Mar 19, 2021 19:43:46.746 [0x9c7fb430] ERROR - [Transcoder] Audio encoding failed
Mar 19, 2021 19:43:46.749 [0xb14ff430] DEBUG - Completed: [192.168.1.119:33751] 200 GET /:/timeline?playbackTime=667419&time=667000&state=playing&ratingKey=27163&key=%2Flibrary%2Fmetadata%2F27163&col=0&row=0&context=home%3Ahub.home.continue&duration=5832832&playQueueItemID=6695 (7 live) GZIP 815ms 789 bytes (pipelined: 63)
Mar 19, 2021 19:43:46.915 [0xb32ff430] DEBUG - Jobs: ‘/usr/lib/plexmediaserver/Plex Transcoder’ exit code for process 6459 is 1 (failure)
Mar 19, 2021 19:43:46.939 [0xb0cfe430] DEBUG - Auth: authenticated user 1 as sample.email@gmail.com
Mar 19, 2021 19:43:46.939 [0xa6efc430] DEBUG - Request: [192.168.1.1:64395 (Subnet)] GET /status/sessions (6 live) TLS GZIP Signed-in Token (sample.email@gmail.com)
Mar 19, 2021 19:43:46.939 [0xa6efc430] DEBUG - [Now] Adding 1 sessions.
Mar 19, 2021 19:43:47.309 [0xad2ff430] DEBUG - Streaming Resource: Terminated session 0xb1bd93a0:0fd20eaf6764828fbae1ff8d9f43852b with reason Conversion failed. The transcoder exited due to an error.
Mar 19, 2021 19:43:47.309 [0xad2ff430] DEBUG - Killing job.
Mar 19, 2021 19:43:47.309 [0xad2ff430] DEBUG - Signalling job ID 6459 with 9
Mar 19, 2021 19:43:47.309 [0xad2ff430] DEBUG - Job was already killed, not killing again.
Mar 19, 2021 19:43:47.309 [0xad2ff430] DEBUG - Stopping transcode session da2a97c4-9e7c-4d19-ae2a-a93c018cf55d-877
Plex server log playing Rise of Skywalker transcoding from DTS 5.1
Mar 19, 2021 21:26:31.426 [0xa5bf8430] DEBUG - [Transcode/da2a97c4-9e7c-4d19-ae2a-a93c018cf55d-1202] Asked for segment 575 from session.
Mar 19, 2021 21:26:31.427 [0xa5bf8430] DEBUG - [Transcode/da2a97c4-9e7c-4d19-ae2a-a93c018cf55d-1202] Returning segment 575 from session
Mar 19, 2021 21:26:31.427 [0xa5bf8430] DEBUG - Content-Length of /var/lib/plexmediaserver/tmp/Transcode/Sessions/plex-transcode-da2a97c4-9e7c-4d19-ae2a-a93c018cf55d-1202-20099fc6-3a76-4a75-a492-3733f6b3fc87/media-00575.ts is 4801332 (of total: 4801332).
Mar 19, 2021 21:26:31.634 [0xb17fe430] DEBUG - Completed: [192.168.1.119:34043] 200 GET /video/:/transcode/universal/session/da2a97c4-9e7c-4d19-ae2a-a93c018cf55d-1202/base/00575.ts?protocol=hls&mediaIndex=0&waitForSegments=1 (10 live) 208ms 4801332 bytes (pipelined: 103)
Mar 19, 2021 21:26:31.635 [0xb17fe430] DEBUG - Removed transcode data consumer, active count 1 => 0
Mar 19, 2021 21:26:32.000 [0xa43f5430] ERROR - [Transcoder] [eac3_eae @ 0x1b77db0] EAE timeout! EAE not running, or wrong folder? Could not read ‘/tmp/pms-1bed0561-acc0-4d7c-abca-911070797ac1/EasyAudioEncoder/Convert to Dolby Digital Plus (High Quality - 384 kbps)/da2a97c4-9e7c-4d19-ae2a-a93c018cf55d-1202_1120-0-142.ec3’
Mar 19, 2021 21:26:33.348 [0xb17fe430] DEBUG - Auth: authenticated user 1 as sample.email@gmail.com
Mar 19, 2021 21:26:33.348 [0x9d2f6430] DEBUG - Request: [192.168.1.119:34043 (Subnet)] GET /video/:/transcode/universal/session/da2a97c4-9e7c-4d19-ae2a-a93c018cf55d-1202/base/00576.ts?protocol=hls&mediaIndex=0&waitForSegments=1 (10 live) Signed-in Token (sample.email@gmail.com)
Mar 19, 2021 21:26:33.348 [0x9d2f6430] DEBUG - [Transcode/da2a97c4-9e7c-4d19-ae2a-a93c018cf55d-1202] Asked for segment 576 from session.
Mar 19, 2021 21:26:33.349 [0x9d2f6430] DEBUG - [Transcode/da2a97c4-9e7c-4d19-ae2a-a93c018cf55d-1202] Returning segment 576 from session
Mar 19, 2021 21:26:33.349 [0x9d2f6430] DEBUG - Content-Length of /var/lib/plexmediaserver/tmp/Transcode/Sessions/plex-transcode-da2a97c4-9e7c-4d19-ae2a-a93c018cf55d-1202-20099fc6-3a76-4a75-a492-3733f6b3fc87/media-00576.ts is 5040844 (of total: 5040844).
Mar 19, 2021 21:26:33.561 [0xb1fff430] DEBUG - Completed: [192.168.1.119:34043] 200 GET /video/:/transcode/universal/session/da2a97c4-9e7c-4d19-ae2a-a93c018cf55d-1202/base/00576.ts?protocol=hls&mediaIndex=0&waitForSegments=1 (10 live) 213ms 5040844 bytes (pipelined: 104)
Mar 19, 2021 21:26:33.561 [0xb1fff430] DEBUG - Removed transcode data consumer, active count 1 => 0
Mar 19, 2021 21:26:34.292 [0xb1fff430] DEBUG - Auth: authenticated user 1 as sample.email@gmail.com
Mar 19, 2021 21:26:34.292 [0xa5bf8430] DEBUG - Request: [192.168.1.119:34043 (Subnet)] GET /video/:/transcode/universal/session/da2a97c4-9e7c-4d19-ae2a-a93c018cf55d-1202/base/00577.ts?protocol=hls&mediaIndex=0&waitForSegments=1 (10 live) Signed-in Token (sample.email@gmail.com)
Mar 19, 2021 21:26:34.293 [0xa5bf8430] DEBUG - [Transcode/da2a97c4-9e7c-4d19-ae2a-a93c018cf55d-1202] Asked for segment 577 from session.
Mar 19, 2021 21:26:34.293 [0xa5bf8430] DEBUG - [Transcode/da2a97c4-9e7c-4d19-ae2a-a93c018cf55d-1202] Returning segment 577 from session
Mar 19, 2021 21:26:34.293 [0xa5bf8430] DEBUG - Content-Length of /var/lib/plexmediaserver/tmp/Transcode/Sessions/plex-transcode-da2a97c4-9e7c-4d19-ae2a-a93c018cf55d-1202-20099fc6-3a76-4a75-a492-3733f6b3fc87/media-00577.ts is 4577048 (of total: 4577048).
Mar 19, 2021 21:26:34.523 [0xb1fff430] DEBUG - Completed: [192.168.1.119:34043] 200 GET /video/:/transcode/universal/session/da2a97c4-9e7c-4d19-ae2a-a93c018cf55d-1202/base/00577.ts?protocol=hls&mediaIndex=0&waitForSegments=1 (10 live) 230ms 4577048 bytes (pipelined: 105)
Mar 19, 2021 21:26:34.523 [0xb1fff430] DEBUG - Removed transcode data consumer, active count 1 => 0
Mar 19, 2021 21:26:35.294 [0xb17fe430] DEBUG - Auth: authenticated user 1 as sample.email@gmail.com
Mar 19, 2021 21:26:35.294 [0x9d2f6430] DEBUG - Request: [192.168.1.119:34043 (Subnet)] GET /video/:/transcode/universal/session/da2a97c4-9e7c-4d19-ae2a-a93c018cf55d-1202/base/00578.ts?protocol=hls&mediaIndex=0&waitForSegments=1 (9 live) Signed-in Token (sample.email@gmail.com)
Mar 19, 2021 21:26:35.294 [0x9d2f6430] DEBUG - [Transcode/da2a97c4-9e7c-4d19-ae2a-a93c018cf55d-1202] Asked for segment 578 from session.
Mar 19, 2021 21:26:35.295 [0x9d2f6430] DEBUG - [Transcode/da2a97c4-9e7c-4d19-ae2a-a93c018cf55d-1202] Returning segment 578 from session
Mar 19, 2021 21:26:35.295 [0x9d2f6430] DEBUG - Content-Length of /var/lib/plexmediaserver/tmp/Transcode/Sessions/plex-transcode-da2a97c4-9e7c-4d19-ae2a-a93c018cf55d-1202-20099fc6-3a76-4a75-a492-3733f6b3fc87/media-00578.ts is 5049304 (of total: 5049304).
Mar 19, 2021 21:26:35.312 [0xb1fff430] DEBUG - Auth: authenticated user 1 as sample.email@gmail.com
Mar 19, 2021 21:26:35.313 [0xa43f5430] DEBUG - Request: [192.168.1.119:34054 (Subnet)] GET /video/:/transcode/universal/session/da2a97c4-9e7c-4d19-ae2a-a93c018cf55d-1202/base/00579.ts?protocol=hls&mediaIndex=0&waitForSegments=1 (9 live) Signed-in Token (sample.email@gmail.com)
Mar 19, 2021 21:26:35.313 [0xa43f5430] DEBUG - [Transcode/da2a97c4-9e7c-4d19-ae2a-a93c018cf55d-1202] Asked for segment 579 from session.
Mar 19, 2021 21:26:35.313 [0xa43f5430] DEBUG - [Transcode/da2a97c4-9e7c-4d19-ae2a-a93c018cf55d-1202] Returning segment 579 from session
Mar 19, 2021 21:26:35.314 [0xa43f5430] DEBUG - Content-Length of /var/lib/plexmediaserver/tmp/Transcode/Sessions/plex-transcode-da2a97c4-9e7c-4d19-ae2a-a93c018cf55d-1202-20099fc6-3a76-4a75-a492-3733f6b3fc87/media-00579.ts is 5311000 (of total: 5311000).
Mar 19, 2021 21:26:35.585 [0xb1fff430] DEBUG - Completed: [192.168.1.119:34043] 200 GET /video/:/transcode/universal/session/da2a97c4-9e7c-4d19-ae2a-a93c018cf55d-1202/base/00578.ts?protocol=hls&mediaIndex=0&waitForSegments=1 (9 live) 291ms 5049304 bytes (pipelined: 106)
Mar 19, 2021 21:26:35.585 [0xb1fff430] DEBUG - Removed transcode data consumer, active count 2 => 1
Mar 19, 2021 21:26:36.054 [0xb17fe430] DEBUG - Completed: [192.168.1.119:34054] 200 GET /video/:/transcode/universal/session/da2a97c4-9e7c-4d19-ae2a-a93c018cf55d-1202/base/00579.ts?protocol=hls&mediaIndex=0&waitForSegments=1 (9 live) 741ms 5311000 bytes (pipelined: 14)
Mar 19, 2021 21:26:36.054 [0xb17fe430] DEBUG - Removed transcode data consumer, active count 1 => 0
Mar 19, 2021 21:26:36.407 [0xb1fff430] DEBUG - Auth: authenticated user 1 as sample.email@gmail.com
Mar 19, 2021 21:26:36.407 [0x9e2f8430] DEBUG - Request: [192.168.1.1:52451 (Subnet)] GET /status/sessions (9 live) TLS GZIP Signed-in Token (sample.email@gmail.com)
Mar 19, 2021 21:26:36.407 [0x9e2f8430] DEBUG - [Now] Adding 1 sessions.
Mar 19, 2021 21:26:36.418 [0xb1fff430] DEBUG - Completed: [192.168.1.1:52451] 200 GET /status/sessions (9 live) TLS GZIP 11ms 8093 bytes (pipelined: 18)
Mar 19, 2021 21:26:36.721 [0x9caf5430] DEBUG - Client [0fd20eaf6764828fbae1ff8d9f43852b] reporting timeline state playing, progress of 547000/8513024ms for guid=, playbackTime=112067ms ratingKey=26844 url=, key=/library/metadata/26844, containerKey=, metadataId=26844, source=
Mar 19, 2021 21:26:36.731 [0xa7bfc430] ERROR - [Transcoder] [eac3_eae @ 0x1b77db0] error reading output
Mar 19, 2021 21:26:36.733 [0x9caf5430] DEBUG - Play progress on 26844 ‘Star Wars: The Rise of Skywalker’ - got played 547000 ms by account 1!
Mar 19, 2021 21:26:36.733 [0xa43f5430] ERROR - [Transcoder] Audio encoding failed
Mar 19, 2021 21:26:36.733 [0x9caf5430] DEBUG - [Now] User is sample.email@gmail.com (ID: 1)
Mar 19, 2021 21:26:36.733 [0x9caf5430] DEBUG - [Now] Device is Roku (Roku Ultra).
Mar 19, 2021 21:26:36.734 [0x9caf5430] DEBUG - [Now] Profile is Roku-7.x
Mar 19, 2021 21:26:36.734 [0x9caf5430] DEBUG - [Now] Updated play state for /library/metadata/26844.
Mar 19, 2021 21:26:36.734 [0x9caf5430] DEBUG - Statistics: (0fd20eaf6764828fbae1ff8d9f43852b) Reporting active playback in state 0 of type 1 (scrobble: 0) for account 1
Mar 19, 2021 21:26:36.736 [0x9daf7430] DEBUG - Play progress on 26844 ‘Star Wars: The Rise of Skywalker’ - got played 537000 ms by account 1!
Mar 19, 2021 21:26:36.743 [0x9daf7430] DEBUG - [Now] User is sample.email@gmail.com (ID: 1)
Mar 19, 2021 21:26:36.743 [0x9daf7430] DEBUG - [Now] Device is Roku (Roku Ultra).
Mar 19, 2021 21:26:36.743 [0x9daf7430] DEBUG - [Now] Profile is Roku-7.x
Mar 19, 2021 21:26:36.743 [0x9daf7430] DEBUG - [Now] Updated play state for /library/metadata/26844.
Mar 19, 2021 21:26:36.744 [0x9daf7430] DEBUG - Statistics: (0fd20eaf6764828fbae1ff8d9f43852b) Reporting active playback in state 0 of type 1 (scrobble: 0) for account 1
Mar 19, 2021 21:26:36.749 [0xb1fff430] DEBUG - Completed: [192.168.1.119:34056] 200 GET /:/timeline?playbackTime=112067&time=547000&state=playing&ratingKey=26844&key=%2Flibrary%2Fmetadata%2F26844&col=1&row=1&context=source%3Acontent.library&duration=8513024&playQueueItemID=6709 (9 live) GZIP 6253ms 782 bytes (pipelined: 2)
Mar 19, 2021 21:26:36.761 [0xb1fff430] DEBUG - Completed: [192.168.1.119:34044] 200 GET /:/timeline?playbackTime=101663&time=537000&state=playing&ratingKey=26844&key=%2Flibrary%2Fmetadata%2F26844&col=1&row=1&context=source%3Acontent.library&duration=8513024&playQueueItemID=6709 (9 live) GZIP 16694ms 782 bytes (pipelined: 11)
Mar 19, 2021 21:26:37.394 [0xb17fe430] DEBUG - Auth: authenticated user 1 as sample.email@gmail.com
Mar 19, 2021 21:26:37.394 [0x9d2f6430] DEBUG - Request: [192.168.1.119:34043 (Subnet)] GET /video/:/transcode/universal/session/da2a97c4-9e7c-4d19-ae2a-a93c018cf55d-1202/base/00580.ts?protocol=hls&mediaIndex=0&waitForSegments=1 (8 live) Signed-in Token (sample.email@gmail.com)
Mar 19, 2021 21:26:37.394 [0x9d2f6430] DEBUG - [Transcode/da2a97c4-9e7c-4d19-ae2a-a93c018cf55d-1202] Asked for segment 580 from session.
Mar 19, 2021 21:26:37.395 [0x9d2f6430] DEBUG - [Transcode/da2a97c4-9e7c-4d19-ae2a-a93c018cf55d-1202] Returning segment 580 from session
Mar 19, 2021 21:26:37.395 [0x9d2f6430] DEBUG - Content-Length of /var/lib/plexmediaserver/tmp/Transcode/Sessions/plex-transcode-da2a97c4-9e7c-4d19-ae2a-a93c018cf55d-1202-20099fc6-3a76-4a75-a492-3733f6b3fc87/media-00580.ts is 4674432 (of total: 4674432).
Mar 19, 2021 21:26:37.413 [0xb17fe430] DEBUG - Auth: authenticated user 1 as sample.email@gmail.com
Mar 19, 2021 21:26:37.413 [0xa5bf8430] DEBUG - Request: [192.168.1.119:34054 (Subnet)] GET /video/:/transcode/universal/session/da2a97c4-9e7c-4d19-ae2a-a93c018cf55d-1202/base/00581.ts?protocol=hls&mediaIndex=0&waitForSegments=1 (8 live) Signed-in Token (sample.email@gmail.com)
Mar 19, 2021 21:26:37.413 [0xa5bf8430] DEBUG - [Transcode/da2a97c4-9e7c-4d19-ae2a-a93c018cf55d-1202] Asked for segment 581 from session.
Mar 19, 2021 21:26:37.414 [0xa5bf8430] DEBUG - [Transcode/da2a97c4-9e7c-4d19-ae2a-a93c018cf55d-1202] Returning segment 581 from session
Mar 19, 2021 21:26:37.414 [0xa5bf8430] DEBUG - Content-Length of /var/lib/plexmediaserver/tmp/Transcode/Sessions/plex-transcode-da2a97c4-9e7c-4d19-ae2a-a93c018cf55d-1202-20099fc6-3a76-4a75-a492-3733f6b3fc87/media-00581.ts is 5447676 (of total: 5447676).
Mar 19, 2021 21:26:37.626 [0xb32ff430] DEBUG - Jobs: ‘/usr/lib/plexmediaserver/Plex Transcoder’ exit code for process 1120 is 1 (failure)
Mar 19, 2021 21:26:37.629 [0xaa5f9430] DEBUG - Notifying consumer that data is complete.
Mar 19, 2021 21:26:37.629 [0xaa5f9430] DEBUG - Notifying consumer that data is complete.
Mar 19, 2021 21:26:37.629 [0xaa5f9430] DEBUG - Streaming Resource: Terminated session 0xa94b1a28:0fd20eaf6764828fbae1ff8d9f43852b with reason Conversion failed. The transcoder exited due to an error.
Mar 19, 2021 21:26:37.629 [0xb1fff430] ERROR - Session 0xa94b1a28 terminated
Mar 19, 2021 21:26:37.629 [0xaa5f9430] DEBUG - Killing job.
Mar 19, 2021 21:26:37.629 [0xaa5f9430] DEBUG - Signalling job ID 1120 with 9
Mar 19, 2021 21:26:37.629 [0xaa5f9430] DEBUG - Job was already killed, not killing again.
Mar 19, 2021 21:26:37.629 [0xaa5f9430] DEBUG - Stopping transcode session da2a97c4-9e7c-4d19-ae2a-a93c018cf55d-1202
