@sa2000 any news from the Dev-Team on this issue?
OK - as the problem is reproducible for you - we will do this and also get detailed transcoder diagnostics - the amount of data captured will be big and you will need to zip each set and upload to external location eg google drive etc and send me a link by private message
Suggest that you do this as a separate exercise to repro the problem and not try to use the server for other activities at the time
We will be setting a number of extra diagnostics for this and you will need to remove them after the test.
The diagnostics to collect will be the server logs (with verbose logging enabled) and the procmon PML saving all events captured and also the transcoder temp sessions directories / files.
Before the test -
Whilst the server is running, go to sever settings / general / advanced settings and enable both verbose and debug logging levels
Then make these registry edits - these could impact the performance of the server so do it just before the test
Shutdown Plex Media Server so next launch will be with all the extra diagnostics
add these settings to the server in the registry
Regedit, Selecting
HKEY_CURRENT_USER\Software\Plex, Inc.\Plex Media Server
Right Click on Plex Media Server and select New and then for each of the following 4 setting
type `DWORD (32-bit) value
TranscoderPersistSessionDirs set value to be 1
TranscoderInputTracing set value to be 1
TranscoderPruneBuffer set value to be 0
TranscoderLivePruneBuffer set value to be 0
LogNumFiles set value to decimal 10
and then New → String Value adding
TranscoderLogLevel set value to trace
Know where the transcoder temp directories are
From previous logs - it was in this path
D:\Plex\Transcoder\Transcode\Sessions
With the above settings, logging in PMS and Transcoder will be very detailed and also all transcoder temporary files for streaming / recording will be retained and not purged until the server is restarted
Download procmon from Process Monitor - Sysinternals | Microsoft Learn
launch PMS
Before starting your recording test into a new test library, launch process monitor
(note that leaving it running for too long could exhaust windows system resources)
start procmon event capture - with default filters
see that the count is incrementing - you could disable auto scrolling if enabled
Reproduce the problem - where recording ends after few seconds
Capture the diagnostics:
Stop Procmon capture
Save All Events to a PML file
zip the PML file
Copy out the contents of the transcoder sessions files - copying out all of
D:\Plex\Transcoder\Transcode\Sessions
and zipping the copy
Download the server logs zip
Note down details of what was being recorded / when and what happened
upload all diagnostics to external location and send me a link by PM
Unset all the extra diagnostics
Server settings / advanced / general - disable verbose logging leaving only debug enabled
shut down plex media server
Regedit, Selecting
HKEY_CURRENT_USER\Software\Plex, Inc.\Plex Media Server
Delete these entries
TranscoderPersistSessionDirs
TranscoderInputTracing
TranscoderPruneBuffer
TranscoderLivePruneBuffer
LogNumFiles
TranscoderLogLevel
Logging will now go back to default
Launch PMS - it will now purge all the previous transcoder sessions files
I am sorry I do not have any update. The more users seen to have this issue the higher priority it gets. At the moment I only have your diagnostics and I also had evidence of it from @olli a long time ago.
The most recordings on regular SD channels are OK.
There are still sporadic failures on some TV shows on HD channels.
Filesize is between some KB to 1 MB
sometimes the recording breaks when switching (maybe resolution change) from the pre-comercials to start of TV-Show. (after 7 min pre-recording)
PS: for example i recorded about 200 Episodes of cartoons on SD with nearly no problems while this happens on HD channels:
Only when the first recording is OK, DVR will quit trying.
Today just upgraded to 1.32.2.7100 on Synology DSM7
I ran the test and sent you the link to the results via PM. The link contains a text file describing the shows recorded, channel, times, etc.
Let me know if you need any additional information. Thanks!
Thanks for all the diagnostics - very good set.
I looked into detail into the recording for Nature Cat (2015) - S03E03 - Onward and Songward; Why Did the Turtle Cross the Road which was started at May 23, 2023 12:30:26
So we had a transcoder error failing to write to the file after about 23 seconds
The procmon capture shows a Network Error for the WRITE action - after writing successfully about 10Mb to the file
This is what procmon PML file shows
12:30:26.282 Plex Transcoder.exe WriteFile
\\MCubed\Media\Test\.grab\e573a7ed0eaac332792ff0dac4892df0ce79c76f-fdd61eef7d6af2e5768e7de6f052911da4d06c55\Nature Cat (2015) - S03E03 - Onward and Songward; Why Did the Turtle Cross the Road.ts
NETWORK ERROR
Offset: 10,747,904, Length: 262,144, Priority: Normal
Filtering the PML for Network Errors - it shows quite a lot of them
So it is looking to me like a networking issue between the Windows PC and the Mapped Network Drive to \\MCubed\Media
Even Microsoft MsPpEng.exe had an error
Could you see if the Windows Application and System logs have anything of relevance round the times of these NETWORK ERRORs
Could you run some extensive network file access tests between the PC and the NAS
Thanks for taking a look. I’ll see what I can dig up on the networking side. Seems weird that I can reproduce this on demand though.
One workaround I found is to extend the recording of the first show, and that will prevent the second show recording from stopping right after starting. I haven’t experimented enough to know if I need to extend the first to cover the entirety of the second show, or if I can just extend it by a few minutes.
I see the same problem sporadically. I have not yet found a way to reproduce this.
My setup is a docker container in linux with a mapped local disk, so I would rule out a network problem. It’s also not a signal problem as I can normally do a live play of the affected channel after the recording has failed.
I think the error handling an error-reporting could be better for those cases. Most of the time the recordings are marked as completed, even if only some seconds were recorded.
Latest occurrence yesterday:
Jun 02, 2023 20:13:23.351 [140063219116856] DEBUG - [Req#195523/Grabber/24b073d892683be7689252188fcf8b51aca97dca] Recorder: It took 18.6 sec to start the session for http://192.168.1.43:8001/1:0:19:1332:3EF:1:C00000:0:0:0:
Jun 02, 2023 20:13:23.351 [140063186959160] ERROR - [Req#1a38ad/Transcode/36a949ee-e049-4f26-bffc-c86a0fcecbb2/6e7c8f15-c49c-46a4-a1af-2a17b73a8484] [mpegts @ 0x7f6fabd28040] sample rate not set
Jun 02, 2023 20:13:23.352 [140063174019896] ERROR - [Req#1a38b7/Transcode/36a949ee-e049-4f26-bffc-c86a0fcecbb2/6e7c8f15-c49c-46a4-a1af-2a17b73a8484] Could not write header for output file #0 (incorrect codec parameters ?): Invalid argument
Jun 02, 2023 20:13:23.352 [140063186959160] ERROR - [Req#1a38b8/Transcode/36a949ee-e049-4f26-bffc-c86a0fcecbb2/6e7c8f15-c49c-46a4-a1af-2a17b73a8484] Error initializing output stream 0:4 –
Jun 02, 2023 20:13:23.352 [140063174019896] DEBUG - Request: [127.0.0.1:36736 (Loopback)] PUT /video/:/transcode/session/36a949ee-e049-4f26-bffc-c86a0fcecbb2/6e7c8f15-c49c-46a4-a1af-2a17b73a8484/progress?width=1920&height=1080 (10 live) #1a38b9 Signed-in Token (thomas.ha98) (range: bytes=0-)
Jun 02, 2023 20:13:23.353 [140063508421432] DEBUG - Completed: [127.0.0.1:36736] 206 PUT /video/:/transcode/session/36a949ee-e049-4f26-bffc-c86a0fcecbb2/6e7c8f15-c49c-46a4-a1af-2a17b73a8484/progress?width=1920&height=1080 (10 live) #1a38b9 0ms 355 bytes (pipelined: 15) (range: bytes=0-)
Jun 02, 2023 20:13:23.353 [140063186959160] ERROR - [Req#1a38be/Transcode/36a949ee-e049-4f26-bffc-c86a0fcecbb2/6e7c8f15-c49c-46a4-a1af-2a17b73a8484]
Jun 02, 2023 20:13:23.358 [140063510985528] DEBUG - Jobs: ‘/usr/lib/plexmediaserver/Plex Transcoder’ exit code for process 1395668 is 1 (failure)
Jun 02, 2023 20:13:23.358 [140063194925880] DEBUG - [Req#195523/Grabber/24b073d892683be7689252188fcf8b51aca97dca] Recorder: No more consumers, stopping.
Jun 02, 2023 20:13:23.358 [140063194925880] DEBUG - [Req#195523/Grabber/24b073d892683be7689252188fcf8b51aca97dca] Recorder: Asked to stop recording ‘Miss Scarlet & the Duke - E5 - Miss Scarlet & the Duke’ on channel 5fc76e325f5c74002deffb79-5fc705f9a62668002dcefda6.
Jun 02, 2023 20:13:23.358 [140063194925880] DEBUG - [Req#195523/Grabber/24b073d892683be7689252188fcf8b51aca97dca] Recorder: Stopping transcode session.
Jun 02, 2023 20:13:23.358 [140063194925880] DEBUG - [Req#195523/Grabber/24b073d892683be7689252188fcf8b51aca97dca] Killing job.
Jun 02, 2023 20:13:23.358 [140063194925880] DEBUG - [Req#195523/Grabber/24b073d892683be7689252188fcf8b51aca97dca] Signalling job ID 1395658 with 9
→ 35 seconds or so
and another one
Jun 03, 2023 01:13:00.767 [140063088986936] DEBUG - [Grabber/00db195f43d07865c9a81a2403f15a09d8489579] Starting operation for ‘Attraction (2017)’ on channel 5fc76e325f5c74002deffb79-5fc705f2ef776a002eba3c9b.
Jun 03, 2023 01:13:00.767 [140063088986936] DEBUG - [Grabber/00db195f43d07865c9a81a2403f15a09d8489579] Activity: registered new activity d59c825d-75d1-4f4c-b961-58f2d6d11f32 - “Recording”
Jun 03, 2023 01:13:00.767 [140063165537080] DEBUG - [Grabber/00db195f43d07865c9a81a2403f15a09d8489579/HCl#12ac3] HTTP requesting GET http://192.168.1.43:6084/discover.json
Jun 03, 2023 01:13:00.768 [140063088986936] DEBUG - [Grabber/00db195f43d07865c9a81a2403f15a09d8489579] Grabber: HDHomerun starting a media grab on device device://tv.plex.grabbers.hdhomerun/956F6NQH (Silicondust vuduo4kse, supported) tuner 13.
Jun 03, 2023 01:13:00.770 [140063088986936] DEBUG - [Grabber/00db195f43d07865c9a81a2403f15a09d8489579] Subscription: No existing library item movie ‘guid: plex://movie/5fc694df9a1745002d5a1138 ratingKey: plex%3A%2F%2Fmovie%2F5fc694df9a1745002d5a1138 thumb: https://metadata-static.plex.tv/2/gracenote/2e8160ef698f2c573c1f10082f8dd7a9.jpg title: Attraction type: 1 year: 2017’
Jun 03, 2023 01:13:00.771 [140063088986936] DEBUG - [Grabber/00db195f43d07865c9a81a2403f15a09d8489579] Grabber: checking for 22391 MB of available disk space in grab path and 200 MB in the transcode cache path
Jun 03, 2023 01:13:00.771 [140063088986936] DEBUG - [Grabber/00db195f43d07865c9a81a2403f15a09d8489579] Grabber: Saving recording to “/data/TV/.grab/00db195f43d07865c9a81a2403f15a09d8489579-28eaa066b537dc7bdb18f52b2d3e0a4eb0a0e165”
Jun 03, 2023 01:13:00.771 [140063088986936] DEBUG - [Grabber/00db195f43d07865c9a81a2403f15a09d8489579/HCl#12ac4] HTTP requesting GET http://192.168.1.43:6084/lineup.json
Jun 03, 2023 01:13:00.772 [140063490149176] DEBUG - [HttpClient/HCl#12ac3] HTTP/1.0 (0.0s) 200 response from GET http://192.168.1.43:6084/discover.json
Jun 03, 2023 01:13:00.772 [140063165537080] DEBUG - [Grabber/00db195f43d07865c9a81a2403f15a09d8489579/HCl#12ac5] HTTP requesting GET http://192.168.1.43:6084/lineup_status.json
Jun 03, 2023 01:13:00.868 [140063490149176] DEBUG - [HttpClient/HCl#12ac4] HTTP/1.0 (0.1s) 200 response from GET http://192.168.1.43:6084/lineup.json
Jun 03, 2023 01:13:00.868 [140063088986936] DEBUG - [Grabber/00db195f43d07865c9a81a2403f15a09d8489579] Grabber: Going to record for 8820 seconds, final URL is http://192.168.1.43:8001/1:0:19:EF15:421:1:C00000:0:0:0:Jun 03, 2023 01:13:09.468 [140063088986936] DEBUG - [Grabber/00db195f43d07865c9a81a2403f15a09d8489579/JobRunner] Jobs: Starting child process with pid 1428361
Jun 03, 2023 01:39:08.870 [140063510985528] DEBUG - Jobs: ‘/usr/lib/plexmediaserver/Plex Transcoder’ exit code for process 1428361 is 0 (success)
Jun 03, 2023 01:39:08.870 [140063132420920] DEBUG - [Grabber/00db195f43d07865c9a81a2403f15a09d8489579] Recorder: No more consumers, stopping.
Jun 03, 2023 01:39:08.870 [140063132420920] DEBUG - [Grabber/00db195f43d07865c9a81a2403f15a09d8489579] Recorder: Asked to stop recording ‘Attraction (2017)’ on channel 5fc76e325f5c74002deffb79-5fc705f2ef776a002eba3c9b.
Jun 03, 2023 01:39:08.870 [140063132420920] DEBUG - [Grabber/00db195f43d07865c9a81a2403f15a09d8489579] Recorder: Stopping transcode session.
Jun 03, 2023 01:39:08.870 [140063132420920] DEBUG - [Grabber/00db195f43d07865c9a81a2403f15a09d8489579] Killing job.
Jun 03, 2023 01:39:08.870 [140063132420920] DEBUG - [Grabber/00db195f43d07865c9a81a2403f15a09d8489579] Signalling job ID 1428351 with 9
Jun 03, 2023 01:39:08.870 [140063132420920] DEBUG - [Grabber/00db195f43d07865c9a81a2403f15a09d8489579] Job was already killed, not killing again.
Jun 03, 2023 01:39:08.870 [140063132420920] DEBUG - [Grabber/00db195f43d07865c9a81a2403f15a09d8489579] Stopping transcode session 952e2942-1d99-4e38-a581-5136c568b660
Jun 03, 2023 01:39:08.870 [140063123983160] DEBUG - [Grabber/00db195f43d07865c9a81a2403f15a09d8489579] Recording for ‘Attraction (2017)’ on channel 5fc76e325f5c74002deffb79-5fc705f2ef776a002eba3c9b stopped with status complete.
→ 26 minutes instead of 145 min → but shown as completed.
For the other one, would need to see the log lines between these two log lines
need full logs zip anyway
For the first example - can start an investigation with full logs - and see if you can also get the additional diagnostics - outlined here for windows user - need to be adapted for your docker
https://forums.plex.tv/t/dvr-records-for-a-few-seconds-then-stops/834804/62?u=sa2000
[quote="thomas_ha98, post:68, topic:834804"]
Jun 02, 2023 20:13:23.351 [140063186959160] ERROR - [Req#1a38ad/Transcode/36a949ee-e049-4f26-bffc-c86a0fcecbb2/6e7c8f15-c49c-46a4-a1af-2a17b73a8484] [mpegts @ 0x7f6fabd28040] sample rate not set
Jun 02, 2023 20:13:23.352 [140063174019896] ERROR - [Req#1a38b7/Transcode/36a949ee-e049-4f26-bffc-c86a0fcecbb2/6e7c8f15-c49c-46a4-a1af-2a17b73a8484] Could not write header for output file #0 (incorrect codec parameters ?): Invalid argument
Jun 02, 2023 20:13:23.352 [140063186959160] ERROR - [Req#1a38b8/Transcode/36a949ee-e049-4f26-bffc-c86a0fcecbb2/6e7c8f15-c49c-46a4-a1af-2a17b73a8484] Error initializing output stream 0:4 –
[/quote]This topic was automatically closed 90 days after the last reply. New replies are no longer allowed.
