Recordings won't complete

[cythrault_gmail.com]

Server Version#: 1.14.1.5488

Hi,

I’ve been using the DVR functionality for a few weeks now. There’s a rather annoying issue that comes back every few days: One or two recording will hang at 100% (even if transcoding is disabled) and will never complete unless I restart the plexmediaserver.

I see a bunch of folders under “.grab” but they are all empty. The recordings don’t appear under their respective folder either.

From the screenshot below, there are recordings that were completed more than 24h ago.

I’m on Ubuntu 18.04.1. I don’t see anything in the logs. No errors in the Plex Tuner log. what do I need to check to get to the bottom of this? What’s the trigger and why is plex not failing one particular recording only? This is really bad for the WAF.

Cheers,
Martin

[ZeroFux]

I’m new to Linux but maybe you’re access to the library directories is getting messed up and you’re losing write access to the directory (so the finished recording isn’t able to right).

Just a thought. You could also turn on Debugging (not verbose) and check out the log file when one of the recordings doesn’t complete.

Just a suggestion.

[cythrault_gmail.com]

Hi ZeroFux,

Thanks for the suggestions! I’ve enabled debug logging and awaiting the next event. I’ve also reset the ownership and security of the structure where the recordings are stored.

Cheers!
Martin

[cythrault_gmail.com]

The symptom manifested itself again tonight. Twice. The first time, two recordings hung near completion until I issued a restart of the service.

I’m not sure if it was the case the last time as I did not check before restarting the service but, this time, files were present under the .grab folder.

While I was waiting for the restart to complete on the service, I noticed in the Activity that both recordings completed and the files were moved to their destination. However, they were only partial.

Unfortunatly, I did not take the time to check the logs until later in the evening. By then, they had overwritten themselves.

However, I noticed another recording was hung and I was able to observe that the post-processing of the file seems to never complete. In the example below, the recording stopped at 22:00 and I restarted the service at 22:15:

Plex Media Server.1.log:Feb 07, 2019 22:15:15.458 [0x7fd05a7f7700] DEBUG - [MI] Opening input file: "/myth2/plex/.grab/f0cf0601940d5d9f8179e8f4cb9c1420d698ac2c/Enquete - S12E17 - Episode 17.ts"
Plex Media Server.1.log:Feb 07, 2019 22:15:15.459 [0x7fd05a7f7700] DEBUG - [FFMPEG] - Opening '/myth2/plex/.grab/f0cf0601940d5d9f8179e8f4cb9c1420d698ac2c/Enquete - S12E17 - Episode 17.ts' for reading
Plex Media Server.1.log:Feb 07, 2019 22:15:15.500 [0x7fd05a7f7700] DEBUG - [MI]  *  [mpegts mpeg2video/ac3] Duration: 3386040ms, 1280x720 (1.777778) 59.940fps, bitrate=19133kbps, audio channels=6, optimizedForStreaming=0 ("/myth2/plex/.grab/f0cf0601940d5d9f8179e8f4cb9c1420d698ac2c/Enquete - S12E17 - Episode 17.ts")
Plex Media Server.1.log:Feb 07, 2019 22:15:15.501 [0x7fd05a7f7700] DEBUG - [MI] Closing input file: "/myth2/plex/.grab/f0cf0601940d5d9f8179e8f4cb9c1420d698ac2c/Enquete - S12E17 - Episode 17.ts"
Plex Media Server.1.log:Feb 07, 2019 22:15:15.508 [0x7fd083bff700] DEBUG - DVR:Grabber: Moving "/myth2/plex/.grab/f0cf0601940d5d9f8179e8f4cb9c1420d698ac2c/Enquete - S12E17 - Episode 17.ts" to "/myth2/plex/Enquête/Season 12/Enquete - S12E17 - Episode 17.ts"
Plex Media Server.5.log:Feb 07, 2019 21:00:00.107 [0x7fd07d7ff700] DEBUG - DVR:Grabber: Saving recording to "/myth2/plex/.grab/f0cf0601940d5d9f8179e8f4cb9c1420d698ac2c"
Plex Media Server.5.log:Feb 07, 2019 21:00:00.140 [0x7fd07d7ff700] DEBUG - Job running: EAE_ROOT='/tmp/pms-15d35769-aa5a-4084-87f2-267dfdac4cf0/EasyAudioEncoder' FFMPEG_EXTERNAL_LIBS='/var/lib/plexmediaserver/Library/Application\ Support/Plex\ Media\ Server/Codecs/531e313-1328-linux-ubuntu-x86_64/' XDG_CACHE_HOME='/var/lib/plexmediaserver/Library/Application Support/Plex Media Server/Cache' XDG_DATA_HOME='/usr/lib/plexmediaserver/Resources' X_PLEX_TOKEN='xxxxxxxxxxxxxxxxxxxx' '/usr/lib/plexmediaserver/Plex Transcoder' '-codec:0' 'mpeg2video' '-noaccurate_seek' '-live_start_index' '0' '-probesize' '10000000' '-i' 'http://127.0.0.1:32400/livetv/sessions/0de09175-f01f-4049-aa91-9ac346a40187/7f81fea4-a30b-49b8-add4-ad8202342c98/index.m3u8?offset=278.835735&X-Plex-Token=xxxxxxxxxxxxxxxxxxxx' '-map' '0:0' '-codec:0' 'copy' '-map' '0:1' '-metadata:s:1' 'language=fre' '-codec:1' 'copy' '-copypriorss:1' '0' '-map' '0:2' '-metadata:s:2' 'language=frm' '-codec:2' 'copy' '-copypriorss:2' '0' '-f' 'mpegts' '-map_metadata' '-1' '-map_chapters' '-1' '/myth2/plex/.grab/f0cf0601940d5d9f8179e8f4cb9c1420d698ac2c/Enquete - S12E17 - Episode 17.ts' '-y' '-nostats' '-loglevel' 'quiet' '-loglevel_plex' 'error' '-xioerror' '-progressurl' 'http://127.0.0.1:32400/video/:/transcode/session/7f81fea4-a30b-49b8-add4-ad8202342c98/a81dfeb8-13ec-4b74-8cd2-4e07fd876ddb/progress'

The file that was moved was supposed to be an hour long but it had only 56 minutes. Looks like that post-processing job hangs on corrupted recordings.

Btw, I just want to re-iterate that I’ve not enabled transcoding or commercial sklpping.

Any idea where to take it from here?

Thanks!
Martin

[WCTschumy]

Are you using commercial skipping? The only time I’ve seen this kind of behavior when plex commercial skipper is being used and it’s hung…

[cythrault_gmail.com]

Nope!

Nor do I use transcoding:

[WCTschumy]

hmm… If you go to the .grab directory, are the recordings there? If yes, then killing PMS / rebooting the machine should trigger Plex to move them from .grab to the final location of the media. At least it does on Windows

[cythrault_gmail.com]

Yes, recordings were present under the .grab folder and they moved when I restarted the plexmediaserver service.

Those were partial recordings so my theory is that post-processing is failing on some corrupted recordings. Unfortunatly, all other recordings made afterward are queued and never complete until a restart of the service.

When it happens, all those recordings that are pending completion are not available to the clients either in the Live TV or Recordings library.

(I use the LG app and when the recording is being recorded, it’s available in the ‘Live TV’ tab. Once completed, they are available in the Recordings library I’ve setup.)

I am wondering what next steps I can take to troubleshoot or resolve this.

[cythrault_gmail.com]

I checked the Beta update channel, and it looks like version 1.15.0.659 has this change listed. Interesting!

• (DVR) Plex Tuner Service now properly detects when a transcode session exited due to signal failure and releases the tuner (#9174)

[cythrault_gmail.com]

Well, this is still happening. I wonder if someone from Plex would step in to help troubleshoot this or point to the right ressource. I’m pretty much ready to ditch the DVR at this point.

[cythrault_gmail.com]

I was able to troubleshoot a bit further into this. I’m still stuck tho.

I upgraded to the latest as of today: 1.15.2.793

A particular channel is often losing lock. I’m still investigating why. It could be a hardware problem. However, when this happens, the resulting recording is not complete.

There’s a post-recording transcode job that runs on every recording. Probably to capture some information in the video. That job hangs when the lock is lost during recording. I thought that change #9174 would solve this but it did not.

I recently discovered that I don’t have to restart the service or the service. I simply have to “kill -9” the transcoding process. A simple kill won’t work.

While my hardware issue for that channel is very annoying, it’s my problem and unrelated to the fact that transcoding jobs hang and have a cascading effect on the rest of the system.

Is there any way to solve this?

Thanks!

[cythrault_gmail.com]

I discovered another piece of the puzzle yesterday. It appears that the tuner service is crashing quite often and I don’t know why.

root@teevee:/var/log# grep segfault syslog*
syslog:Mar 28 13:01:47 teevee kernel: [62286.710662] Plex Tuner Serv[17768]: segfault at 0 ip 00000000005c18f1 sp 00007fe8559632e0 error 4 in Plex Tuner Service[400000+42c000]
syslog:Mar 28 13:07:24 teevee kernel: [62623.541933] Plex Tuner Serv[15918]: segfault at 0 ip 00000000005c18f1 sp 00007f55147f72e0 error 4 in Plex Tuner Service[400000+42c000]
syslog.1:Mar 27 20:15:45 teevee kernel: [ 1925.208546] Plex Tuner Serv[1582]: segfault at 0 ip 00000000005c18f1 sp 00007ff735d722e0 error 4 in Plex Tuner Service[400000+42c000]
syslog.2:Mar 26 22:24:43 teevee kernel: [610344.174965] Plex Tuner Serv[17346]: segfault at 0 ip 00000000005c18f1 sp 00007fc362ffc2e0 error 4 in Plex Tuner Service[400000+42c000]
syslog.3:Mar 25 00:12:48 teevee kernel: [444031.926852] Plex Tuner Serv[5550]: segfault at 0 ip 00000000005c18f1 sp 00007f278a2132e0 error 4 in Plex Tuner Service[400000+42c000]
syslog.3:Mar 25 00:27:59 teevee kernel: [444942.763828] Plex Tuner Serv[16969]: segfault at 0 ip 00000000005c18f1 sp 00007f0a9b7fd2e0 error 4 in Plex Tuner Service[400000+42c000]
syslog.7:Mar 21 18:04:19 teevee kernel: [162728.356936] Plex Tuner Serv[30889]: segfault at 0 ip 00000000005c18f1 sp 00007f5b193db2e0 error 4 in Plex Tuner Service[400000+42c000]
syslog.7:Mar 21 18:07:00 teevee kernel: [162889.432040] Plex Tuner Serv[8180]: segfault at 0 ip 00000000005c18f1 sp 00007f4056ffc2e0 error 4 in Plex Tuner Service[400000+42c000]
syslog.7:Mar 21 18:08:21 teevee kernel: [162969.816204] Plex Tuner Serv[9128]: segfault at 0 ip 00000000005c18f1 sp 00007f70837fd2e0 error 4 in Plex Tuner Service[400000+42c000]

Again, I was wondering if anyone from Plex would be able to guide me troubleshooting this?

[cythrault_gmail.com]

So… I still talking to myself here and actually spending more time trying to understand the issue than enjoying any content.

I don’t expect immediate help or the exact solution to my problem, just some help and pointers troubleshooting this… especially from Plex employees. Am I expecting too much?

The only replies I got were from fellow users…

[cythrault_gmail.com]

Running 1.15.3.835 and I had to kill -9 two failed recordings today.

[cythrault_gmail.com]

Running 1.15.4.919 and I had to kill -9 two failed recordings today. I almost thought that had been fixed.