Plex Hang for 1.9.0

I have been having Plex hang even with the new 1.9.0 version. I have a HDHomeRun Prime with many shows being recorded. I am running with a Synology 1515+ and got a hang with DEBUG logs. To recover the hang, I had to stop Plex in DSM and that still didn’t kill it. I logged into my NAS and killed plex manually. Once I got Plex fully killed I could restart it.

In the case I hit it appears that I had 3 shows finishing up around the same time that 1 or more shows was going to start recording.

Looking at Plex Media Server.2.log there is something interesting that I saw but I don’t know if it is related to the hang but the log ends shortly after this:

Sep 12, 2017 16:00:00.218 [0x7ff3a57ff700] DEBUG - DVR:Grabber: Cancelling operation for ‘Star Trek: The Next Generation - E21 - The Drumhead’ with status complete.
Sep 12, 2017 16:00:00.218 [0x7ff3a57ff700] DEBUG - DVR:Grabber: Operation was active, stopping recorder.
Sep 12, 2017 16:00:00.218 [0x7ff3a6055700] DEBUG - DVR:Grabber: Cancelling operation for ‘Chopped - E8 - Champions’ Tournament: Part 2’ with status complete.
Sep 12, 2017 16:00:00.218 [0x7ff3a6055700] DEBUG - DVR:Grabber: Operation was active, stopping recorder.
Sep 12, 2017 16:00:00.218 [0x7ff39dbff700] DEBUG - DVR:Grabber: Cancelling operation for ‘Mickey Mouse Clubhouse - E8 - Goofy’s Hat’ with status complete.
Sep 12, 2017 16:00:00.218 [0x7ff39dbff700] DEBUG - DVR:Grabber: Operation was active, stopping recorder.

From what I can gather from this data, is that I had 3 shows being recorded that all needed to terminate around 4PM. Then one job terminated:

Sep 12, 2017 16:00:00.587 [0x7ff3aecf3700] DEBUG - Jobs: ‘/volume1/@appstore/Plex Media Server/Plex Transcoder’ exit code for process 8485 is 0
Sep 12, 2017 16:00:00.587 [0x7ff37ee6b700] DEBUG - Jobs: ‘/volume1/@appstore/Plex Media Server/Plex Transcoder’ exit code for process 8485 is 0
Sep 12, 2017 16:00:00.588 [0x7ff37ee6b700] DEBUG - DVR:Recorder: Asked to stop recording ‘Chopped - E8 - Champions’ Tournament: Part 2’.
Sep 12, 2017 16:00:00.588 [0x7ff3aecf3700] DEBUG - Jobs: ‘/volume1/@appstore/Plex Media Server/Plex Transcoder’ exit code for process 8485 is 0
Sep 12, 2017 16:00:00.588 [0x7ff37ee6b700] DEBUG - DVR:Recorder: Stopping transcode session.
Sep 12, 2017 16:00:00.588 [0x7ff3a6055700] DEBUG - Jobs: ‘/volume1/@appstore/Plex Media Server/Plex Transcoder’ exit code for process 8485 is 0

And something caused another of the the transcode jobs to be kill with SIGKILL:

Sep 12, 2017 16:00:00.588 [0x7ff37ee6b700] DEBUG - Killing job.
Sep 12, 2017 16:00:00.588 [0x7ff37ee6b700] DEBUG - Signalling job ID 8431 with 9
Sep 12, 2017 16:00:00.588 [0x7ff37ee6b700] DEBUG - Job was already killed, not killing again.
Sep 12, 2017 16:00:00.588 [0x7ff37ee6b700] DEBUG - Stopping transcode session 8065087e-88e4-4580-918e-bb225aa7522b
Sep 12, 2017 16:00:00.609 [0x7ff3aecf3700] DEBUG - JobManager: child process killed by signal: 9 (Killed)
Sep 12, 2017 16:00:00.609 [0x7ff3aecf3700] DEBUG - Jobs: ‘/volume1/@appstore/Plex Media Server/Plex Transcoder’ exit code for process 8431 is -9

Shortly after this point, I can see another session starting to record:

Sep 12, 2017 16:00:00.835 [0x7ff3a7da1700] DEBUG - DVR:Grabber: Starting operation for ‘Chopped - E9 - Champions’ Tournament: Part 3’.
Sep 12, 2017 16:00:00.838 [0x7ff3a7da1700] DEBUG - Activity: registered new activity 04ceeea3-9b2a-44d3-a6c2-812058731d46 - Recording
Sep 12, 2017 16:00:00.839 [0x7ff3a7da1700] DEBUG - DVR:Grabber: HDHomerun starting a media grab on device device://tv.plex.grabbers.hdhomerun/13267907 (Silicondust HDHomeRun PRIME, supported) tuner 0.
Sep 12, 2017 16:00:00.841 [0x7ff3a77c5700] DEBUG - DVR:Grabber: Starting operation for ‘Teen Titans - E1 - Final Exam’.
Sep 12, 2017 16:00:00.845 [0x7ff3a77c5700] DEBUG - Activity: registered new activity c3a0ba6a-4e2a-4089-98f4-5449a1ba9014 - Recording
Sep 12, 2017 16:00:00.845 [0x7ff3a7da1700] DEBUG - DVR:Subscription: Resolved subscription to library item ‘Chopped’ (33389)
Sep 12, 2017 16:00:00.846 [0x7ff3a77c5700] DEBUG - DVR:Grabber: HDHomerun starting a media grab on device device://tv.plex.grabbers.hdhomerun/13267907 (Silicondust HDHomeRun PRIME, supported) tuner 2.

The log ends within about 10 milliseconds.

@philippehebert said:
I have been having Plex hang even with the new 1.9.0 version. I have a HDHomeRun Prime with many shows being recorded. I am running with a Synology 1515+ and got a hang with DEBUG logs. To recover the hang, I had to stop Plex in DSM and that still didn’t kill it. I logged into my NAS and killed plex manually. Once I got Plex fully killed I could restart it.

In the case I hit it appears that I had 3 shows finishing up around the same time that 1 or more shows was going to start recording.

Looking at Plex Media Server.2.log there is something interesting that I saw but I don’t know if it is related to the hang but the log ends shortly after this:

Sep 12, 2017 16:00:00.218 [0x7ff3a57ff700] DEBUG - DVR:Grabber: Cancelling operation for ‘Star Trek: The Next Generation - E21 - The Drumhead’ with status complete.
Sep 12, 2017 16:00:00.218 [0x7ff3a57ff700] DEBUG - DVR:Grabber: Operation was active, stopping recorder.
Sep 12, 2017 16:00:00.218 [0x7ff3a6055700] DEBUG - DVR:Grabber: Cancelling operation for ‘Chopped - E8 - Champions’ Tournament: Part 2’ with status complete.
Sep 12, 2017 16:00:00.218 [0x7ff3a6055700] DEBUG - DVR:Grabber: Operation was active, stopping recorder.
Sep 12, 2017 16:00:00.218 [0x7ff39dbff700] DEBUG - DVR:Grabber: Cancelling operation for ‘Mickey Mouse Clubhouse - E8 - Goofy’s Hat’ with status complete.
Sep 12, 2017 16:00:00.218 [0x7ff39dbff700] DEBUG - DVR:Grabber: Operation was active, stopping recorder.

From what I can gather from this data, is that I had 3 shows being recorded that all needed to terminate around 4PM. Then one job terminated:

Sep 12, 2017 16:00:00.587 [0x7ff3aecf3700] DEBUG - Jobs: ‘/volume1/@appstore/Plex Media Server/Plex Transcoder’ exit code for process 8485 is 0
Sep 12, 2017 16:00:00.587 [0x7ff37ee6b700] DEBUG - Jobs: ‘/volume1/@appstore/Plex Media Server/Plex Transcoder’ exit code for process 8485 is 0
Sep 12, 2017 16:00:00.588 [0x7ff37ee6b700] DEBUG - DVR:Recorder: Asked to stop recording ‘Chopped - E8 - Champions’ Tournament: Part 2’.
Sep 12, 2017 16:00:00.588 [0x7ff3aecf3700] DEBUG - Jobs: ‘/volume1/@appstore/Plex Media Server/Plex Transcoder’ exit code for process 8485 is 0
Sep 12, 2017 16:00:00.588 [0x7ff37ee6b700] DEBUG - DVR:Recorder: Stopping transcode session.
Sep 12, 2017 16:00:00.588 [0x7ff3a6055700] DEBUG - Jobs: ‘/volume1/@appstore/Plex Media Server/Plex Transcoder’ exit code for process 8485 is 0

And something caused another of the the transcode jobs to be kill with SIGKILL:

Sep 12, 2017 16:00:00.588 [0x7ff37ee6b700] DEBUG - Killing job.
Sep 12, 2017 16:00:00.588 [0x7ff37ee6b700] DEBUG - Signalling job ID 8431 with 9
Sep 12, 2017 16:00:00.588 [0x7ff37ee6b700] DEBUG - Job was already killed, not killing again.
Sep 12, 2017 16:00:00.588 [0x7ff37ee6b700] DEBUG - Stopping transcode session 8065087e-88e4-4580-918e-bb225aa7522b
Sep 12, 2017 16:00:00.609 [0x7ff3aecf3700] DEBUG - JobManager: child process killed by signal: 9 (Killed)
Sep 12, 2017 16:00:00.609 [0x7ff3aecf3700] DEBUG - Jobs: ‘/volume1/@appstore/Plex Media Server/Plex Transcoder’ exit code for process 8431 is -9

Shortly after this point, I can see another session starting to record:

Sep 12, 2017 16:00:00.835 [0x7ff3a7da1700] DEBUG - DVR:Grabber: Starting operation for ‘Chopped - E9 - Champions’ Tournament: Part 3’.
Sep 12, 2017 16:00:00.838 [0x7ff3a7da1700] DEBUG - Activity: registered new activity 04ceeea3-9b2a-44d3-a6c2-812058731d46 - Recording
Sep 12, 2017 16:00:00.839 [0x7ff3a7da1700] DEBUG - DVR:Grabber: HDHomerun starting a media grab on device device://tv.plex.grabbers.hdhomerun/13267907 (Silicondust HDHomeRun PRIME, supported) tuner 0.
Sep 12, 2017 16:00:00.841 [0x7ff3a77c5700] DEBUG - DVR:Grabber: Starting operation for ‘Teen Titans - E1 - Final Exam’.
Sep 12, 2017 16:00:00.845 [0x7ff3a77c5700] DEBUG - Activity: registered new activity c3a0ba6a-4e2a-4089-98f4-5449a1ba9014 - Recording
Sep 12, 2017 16:00:00.845 [0x7ff3a7da1700] DEBUG - DVR:Subscription: Resolved subscription to library item ‘Chopped’ (33389)
Sep 12, 2017 16:00:00.846 [0x7ff3a77c5700] DEBUG - DVR:Grabber: HDHomerun starting a media grab on device device://tv.plex.grabbers.hdhomerun/13267907 (Silicondust HDHomeRun PRIME, supported) tuner 2.

The log ends within about 10 milliseconds.

The logs were captured at 19:35 on 12th Sep. I can see you restarted Plex Media Server at 19:14 and a crash report was uploaded to the crash reporting server. So I suspect that there was a crash of Plex Media Server. The last log entry before the restart was at 16:00:00 so the crash was probably then and uploaded when you restarted the server at 19:14

I am referring the crash report to the development team

Thanks! I am seeing a similar behavior on multiple releases. I am having to restart Plex even on 1.6.1.