I posted about my experience with this issue and testing in this thread.
@kinoCharlino Thanks for pointing me to your troubleshooting thread. I have ordered a Mohu Sky. Should be here next week.
I have found much better luck with 1.9.3 and now only occasionally have issues so maybe I’m just left with a weak signal from time to time.
I have been having identical symptoms on my WinTV-dualHD running on Plex 1.9.x (I’ve tried them all) on my Debian 9 system. I have a massive signal booster and while recording on Plex am watching the same station on another TV in the house… visually there appears to be no loss of signal.
What would be helpful to troubleshoot the problem?
@LogicallyRogue said:
I have been having identical symptoms on my WinTV-dualHD running on Plex 1.9.x (I’ve tried them all) on my Debian 9 system. I have a massive signal booster and while recording on Plex am watching the same station on another TV in the house… visually there appears to be no loss of signal.What would be helpful to troubleshoot the problem?
A video sample would be helpful. It’s possible that the booster is introducing corruption into the signal, particularly if its a more powerful one.
Well you are in luck… after about 14 minutes of recording the latest “The Orville” the recording stopped. I have the .TS file (all 500mb of it) and can collect whatever logs you like.
Just so I’m not accused of pirating - is there a Plex Employee file drop you can PM me so I can send it to you?
One other thing … as I was scanning through log files - I found something in syslog which appears to be at the same time “The Orville” stopped recording. Does this make sense to anyone?
Oct 5 21:14:20 nas kernel: [362870.376222] general protection fault: 0000 [#1] SMP
Oct 5 21:14:20 nas kernel: [362870.376257] Modules linked in: softdog veth xt_nat xt_tcpudp ipt_MASQUERADE nf_nat_masquerade_ipv4 nf_conntrack_netlink nfnetlink xfrm_user xfrm_algo iptable_nat nf_conntrack_ipv4 nf_defrag_ipv4 nf_nat_ipv4 xt_addrtype xt_conntrack nf_nat nf_conntrack br_netfilter bridge stp llc overlay binfmt_misc rc_hauppauge em28xx_rc rc_core si2157 lgdt3306a i2c_mux em28xx_dvb dvb_core iptable_filter intel_powerclamp coretemp ipmi_ssif kvm_intel kvm irqbypass crct10dif_pclmul em28xx crc32_pclmul tveeprom gpio_ich v4l2_common joydev input_leds videodev mgag200 ipmi_si ttm ghash_clmulni_intel pcbc wmi aesni_intel drm_kms_helper media ipmi_devintf i7core_edac drm aes_x86_64 dcdbas shpchp i2c_algo_bit fb_sys_fops syscopyarea sysfillrect sysimgblt crypto_simd snd_pcsp snd_pcm glue_helper snd_timer ioatdma acpi_power_meter
Oct 5 21:14:20 nas kernel: [362870.376508] dca cryptd intel_cstate serio_raw snd soundcore edac_core ipmi_msghandler lpc_ich evbug mac_hid nfsd auth_rpcgss nfs_acl lockd grace sunrpc ip_tables x_tables autofs4 usbmouse usbkbd uas usb_storage btrfs raid10 raid456 async_raid6_recov async_memcpy async_pq async_xor async_tx xor hid_generic raid6_pq libcrc32c usbhid raid1 hid raid0 multipath linear psmouse megaraid_sas bnx2 [last unloaded: cpuid]
Oct 5 21:14:20 nas kernel: [362870.376644] CPU: 2 PID: 800 Comm: kdvb-ad-0-fe-0 Tainted: G I 4.11.0-14-generic #20~16.04.1-Ubuntu
Oct 5 21:14:20 nas kernel: [362870.376677] Hardware name: Dell Inc. PowerEdge R410/01V648, BIOS 1.12.0 07/30/2013
Oct 5 21:14:20 nas kernel: [362870.376705] task: ffff9f77cba49540 task.stack: ffffb83161a7c000
Oct 5 21:14:20 nas kernel: [362870.376734] RIP: 0010:dvb_frontend_should_wakeup+0x10/0x70 [dvb_core]
Oct 5 21:14:20 nas kernel: [362870.376759] RSP: 0018:ffffb83161a7fe68 EFLAGS: 00010296
Oct 5 21:14:20 nas kernel: [362870.376778] RAX: 0000000000000000 RBX: 0000000000000000 RCX: ffff9f77cba49540
Oct 5 21:14:20 nas kernel: [362870.376803] RDX: e6e2ca650b824331 RSI: 0000000000000296 RDI: ffff9f6fc83e3010
Oct 5 21:14:20 nas kernel: [362870.376828] RBP: ffffb83161a7fe68 R08: 00014a0757df676c R09: 0000000000000000
Oct 5 21:14:20 nas kernel: [362870.376853] R10: ffffb83161a7fe78 R11: 000000000000269c R12: ffff9f6fc83e3010
Oct 5 21:14:20 nas kernel: [362870.376877] R13: ffff9f77c79acde0 R14: 0000000000000000 R15: ffff9f77c79acc00
Oct 5 21:14:20 nas kernel: [362870.376903] FS: 0000000000000000(0000) GS:ffff9f77efc40000(0000) knlGS:0000000000000000
Oct 5 21:14:20 nas kernel: [362870.376930] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033
Oct 5 21:14:20 nas kernel: [362870.376951] CR2: 0000000001d27468 CR3: 0000000900209000 CR4: 00000000000006e0
Oct 5 21:14:20 nas kernel: [362870.376976] Call Trace:
Oct 5 21:14:20 nas kernel: [362870.376994] dvb_frontend_thread+0x1ce/0x710 [dvb_core]
Oct 5 21:14:20 nas kernel: [362870.377018] ? wake_atomic_t_function+0x60/0x60
Oct 5 21:14:20 nas kernel: [362870.377039] kthread+0x109/0x140
Oct 5 21:14:20 nas kernel: [362870.377056] ? dtv_set_frontend+0x410/0x410 [dvb_core]
Oct 5 21:14:20 nas kernel: [362870.377076] ? kthread_create_on_node+0x70/0x70
Oct 5 21:14:20 nas kernel: [362870.377096] ret_from_fork+0x25/0x30
Oct 5 21:14:20 nas kernel: [362870.377111] Code: c7 c7 ac ee 84 c0 48 89 d6 e8 f4 fa 16 dd eb a4 66 2e 0f 1f 84 00 00 00 00 00 90 66 66 66 66 90 48 8b 97 28 03 00 00 55 48 89 e5 <8b> b2 08 02 00 00 85 f6 75 43 8b 8f 14 05 00 00 b8 01 00 00 00
Oct 5 21:14:20 nas kernel: [362870.377195] RIP: dvb_frontend_should_wakeup+0x10/0x70 [dvb_core] RSP: ffffb83161a7fe68
Oct 5 21:14:20 nas kernel: [362870.377223] —[ end trace 3c06201a2e1bb5cc ]—
This problem started for me about 2 weeks ago. That’s probably the last time I restarted the Docker container and grabbed the latest. I downgraded way back to 1.6.1.
Finally cancelling cable and would like this to be stable.
(DVR) Setups with multiple HDHomeRun tuners now properly tune on both (#7417)
Patch Testing & Sample Media
Greetings! We’re knee-deep in our investigation with this issue and would like to make a call out for additional sample media where the issue is successfully reproduced, or “caught in the act.” Additionally, we’d like to put together a small group of users who would be willing to install a patch to test the potential fix. For this testing we’re going to focus only on the Mac platform with HDHomeRun tuners, though we know the issue exists on other others (the final fix will go out to all platforms). If you meet the following requirements, please read on for how to provide us with appropriate sample media and logs.
Requirements
- OS: macOS Sierra or High Sierra
- PMS. v1.9.4 (latest Plex Pass release)
- HDHomeRun Connect, Prime, or Extend
- OTA (over-the-air) transmission only
- If using an Extend, disable on-device transcoding
- You can consistently reproduce the issue
- Basic knowledge of the command-line interface
- All regions welcome
Steps for providing sample media
Please follow these steps in the order provided.
- Restart your server, and allow the EPG to load (if it’s been ~18 hours since a server restart)
- If you had the EPG reload, then restart your server again (this keeps the logs clean, as there won’t be the EPG refresh this time) - otherwise you can skip this step
- While the show you want to use for testing is airing, launch Terminal and run the following command. This will begin recording a raw feed from your tuner. If you are not sure what the URL is, generate PMS logs, open
Plex Media Server.log, and search forfinal URL is.
curl http://tunerip:port/auto/channel > /users/outputpath/plexSamples/samplefile.ts- e.g.:
curl http://10.0.1.20:5004/auto/v40.1 > /users/kinoCharlino/desktop/samplefile.ts
- Record the same show in Plex Web by going to Program Guide -> Watch Now (filter the “Discover” dropdown), then find the show and click the small record button at the bottom of the poster art
- With the same show on the same channel being recording using 2 tuners (raw feed + Plex), wait for the recording to fail
- Once the recording has failed, stop the recording in Plex Web
- Stop the raw feed recording by pressing Control + C in Terminal. The .ts file will then complete saving to your selected location
- Generate PMS logs in Plex Web by going to Settings -> Server -> Help
- Upload your logs and sample media to your favorite file hosting/sharing service (such as Dropbox or Google Drive) and PM @kinoCharlino with the download links
Testing the patch
Once we have received sample media and logs verifying the same issue from several users, I’ll reach out about installing a special patch to test the potential fix.
Edit
If you’re having difficulty locating locating the tuner URL for the Curl command, try recording a few minutes of the problematic challenge and then create the logs. You can then use the URL from that log to record for creating your test sample.
I’m on Version 1.9.6.4337 and I am seeing an issue with 1 show consistently getting hung at 100%. It is the Today Show. It has done it each of the last couple of days.
I don’t have debugging turned on in the logging (Did a rebuild and clean install and didn’t turn it back on)
One thing I did just notice is that there are 3 recordings going on but only 2 tuners.
I switched back to 1.9.4 and everything seems to be working well. Going to stay here for a while.
I’m now see this problem too. When I looked at Plex this morning I see 7 recordings that are stuck at 100% from last night.
Running Plex 1.9.5.4339 on Windows 7 and using a HDHomeRun Connect
After I restarted Plex some of the recordings show up as complete. But they are all 3 seconds long and all have recorded from the wrong channel. 3 of recordings have the same 3 seconds (recorded 3 seconds from the same channel).
Next time it happens, check the HDHomeRun Log and see if you are getting a “watchdog reset.” For me, even though Plex says there are multiple shows still recoding, when you look in HDHomeRun interface, none of the tuners are doing anything.
Don’t know what’s going on to cause this, but to me it seems to indicate some sort of networking issue between PMS and the tuner.
I did not think to check the HDHomerun log, I’ll check that next time. I did notice in the plex logs that they are setting a timer with negative seconds for the 7 records that never ended. I could see how that might cause the HDHomeRun to stop recording. But I’m sure the Plex developers are well aware of this:
56396 63:Oct 19, 2017 03:11:59.984 [6088] DEBUG - DVR:Grabber: Setting timer to stop grab of ‘The Goldbergs - E4 - Revenge o’ the Nerds’ in -24119 seconds.
56398 63:Oct 19, 2017 03:11:59.984 [6088] DEBUG - DVR:Grabber: Setting timer to stop grab of ‘Modern Family - E4 - ■■■, Lies & Kickball’ in -20459 seconds.
56400 63:Oct 19, 2017 03:11:59.985 [6088] DEBUG - DVR:Grabber: Setting timer to stop grab of ‘SEAL Team - E4 - Ghosts of Christmas Future’ in -18719 seconds.
56402 63:Oct 19, 2017 03:11:59.985 [6088] DEBUG - DVR:Grabber: Setting timer to stop grab of ‘Survivor - E4 - I Don’t Like Having Snakes Around’ in -21719 seconds.
56404 63:Oct 19, 2017 03:11:59.986 [6088] DEBUG - DVR:Grabber: Setting timer to stop grab of ‘Designated Survivor - E4 - Equilibrium’ in -15119 seconds.
56406 63:Oct 19, 2017 03:11:59.986 [6088] DEBUG - DVR:Grabber: Setting timer to stop grab of ‘American Housewife - E4 - The Lice Storm’ in -18719 seconds.
56408 63:Oct 19, 2017 03:11:59.986 [6088] DEBUG - DVR:Grabber: Setting timer to stop grab of ‘The Blacklist - E4 - The Endling’ in -22319 seconds.
@wazkaren@gmail.com said:
I did not think to check the HDHomerun log, I’ll check that next time. I did notice in the plex logs that they are setting a timer with negative seconds for the 7 records that never ended. I could see how that might cause the HDHomeRun to stop recording. But I’m sure the Plex developers are well aware of this:56396 63:Oct 19, 2017 03:11:59.984 [6088] DEBUG - DVR:Grabber: Setting timer to stop grab of ‘The Goldbergs - E4 - Revenge o’ the Nerds’ in -24119 seconds.
56398 63:Oct 19, 2017 03:11:59.984 [6088] DEBUG - DVR:Grabber: Setting timer to stop grab of ‘Modern Family - E4 - ****, Lies & Kickball’ in -20459 seconds.
56400 63:Oct 19, 2017 03:11:59.985 [6088] DEBUG - DVR:Grabber: Setting timer to stop grab of ‘SEAL Team - E4 - Ghosts of Christmas Future’ in -18719 seconds.
56402 63:Oct 19, 2017 03:11:59.985 [6088] DEBUG - DVR:Grabber: Setting timer to stop grab of ‘Survivor - E4 - I Don’t Like Having Snakes Around’ in -21719 seconds.
56404 63:Oct 19, 2017 03:11:59.986 [6088] DEBUG - DVR:Grabber: Setting timer to stop grab of ‘Designated Survivor - E4 - Equilibrium’ in -15119 seconds.
56406 63:Oct 19, 2017 03:11:59.986 [6088] DEBUG - DVR:Grabber: Setting timer to stop grab of ‘American Housewife - E4 - The Lice Storm’ in -18719 seconds.
56408 63:Oct 19, 2017 03:11:59.986 [6088] DEBUG - DVR:Grabber: Setting timer to stop grab of ‘The Blacklist - E4 - The Endling’ in -22319 seconds.
In which log is this information?
Plex Media Server.log
It seems that I was watching/transcoding a show when my last 100% failure occured on pms.
ct 17, 2017 22:01:03.882 [0x7f5941be7700] DEBUG - Request: [127.0.0.1:33416 (Loopback)] PUT /video/:/transcode/session/70c88873-b60e-498c-a7cf-c836c07386f2/a86ffef1-496f-4c15-81fa-2aa0fcebaf8e/progress?progress=-1.0&size=4654467152&remaining=-1&speed=0.8 (18 live) Signed-in Token (Kurnon)
Oct 17, 2017 22:01:03.883 [0x7f59777ff700] DEBUG - Completed: [127.0.0.1:33416] 206 PUT /video/:/transcode/session/70c88873-b60e-498c-a7cf-c836c07386f2/a86ffef1-496f-4c15-81fa-2aa0fcebaf8e/progress?progress=-1.0&size=4654467152&remaining=-1&speed=0.8 (18 live) 1ms 326 bytes
Oct 17, 2017 22:01:03.885 [0x7f5967c00700] DEBUG - Jobs: ‘/usr/lib/plexmediaserver/Plex Transcoder’ exit code for process 10322 is 0
Oct 17, 2017 22:01:03.885 [0x7f5967c00700] DEBUG - Jobs: ‘/usr/lib/plexmediaserver/Plex Transcoder’ exit code for process 10322 is 0
Oct 17, 2017 22:01:03.886 [0x7f59507fd700] DEBUG - Jobs: ‘/usr/lib/plexmediaserver/Plex Transcoder’ exit code for process 10322 is 0
Oct 17, 2017 22:01:03.886 [0x7f59507fd700] DEBUG - DVR:Recorder: Asked to stop recording ‘This Is Us - E4 - Still There’.
Oct 17, 2017 22:01:03.886 [0x7f59507fd700] DEBUG - DVR:Recorder: Stopping transcode session.
Oct 17, 2017 22:01:03.886 [0x7f59507fd700] DEBUG - Killing job.
Oct 17, 2017 22:01:03.886 [0x7f59507fd700] DEBUG - Signalling job ID 10312 with 9
Oct 17, 2017 22:01:03.886 [0x7f59507fd700] DEBUG - Job was already killed, not killing again.
Oct 17, 2017 22:01:03.886 [0x7f59507fd700] DEBUG - Stopping transcode session b42c085a-254e-41d2-bc59-fb5683c570d6
Oct 17, 2017 22:01:03.889 [0x7f5967c00700] DEBUG - JobManager: child process killed by signal: 9 (Killed)
Oct 17, 2017 22:01:03.889 [0x7f5967c00700] DEBUG - Jobs: ‘/usr/lib/plexmediaserver/Plex Transcoder’ exit code for process 10312 is -9
Oct 17, 2017 22:01:03.889 [0x7f59507fd700] DEBUG - DVR:Grabber: Freed a tuner (now 2 available)
Oct 17, 2017 22:01:03.889 [0x7f59507fd700] DEBUG - DVR:Grabber: Recording for ‘This Is Us - E4 - Still There’ stopped with status complete.
Oct 17, 2017 22:01:03.890 [0x7f59507fd700] DEBUG - DVR:Grabber: Using recording status.
Oct 17, 2017 22:01:03.890 [0x7f59507fd700] DEBUG - Activity: updated activity 53c44a66-21e1-419a-acf9-b2f94daf9a4e - completed 100% - Recording
Oct 17, 2017 22:01:03.890 [0x7f59507fd700] DEBUG - DVR:Grabber: Scheduling ‘This Is Us - E4 - Still There’ for assimilation.
Oct 17, 2017 22:01:04.382 [0x7f594f7fb700] DEBUG - DVR:Recorder: Asked to stop recording ‘This Is Us - E4 - Still There’.
Oct 17, 2017 22:04:04.865 [0x7f5965bff700] DEBUG - Shutting down idle session b42c085a-254e-41d2-bc59-fb5683c570d6 (idle time is 180 seconds)
Oct 17, 2017 22:04:04.866 [0x7f5965bff700] DEBUG - Job was already killed, not killing again.
Oct 17, 2017 22:04:04.866 [0x7f5965bff700] DEBUG - Job was already killed, not killing again.
Oct 17, 2017 22:04:04.866 [0x7f5965bff700] DEBUG - Whacked session b42c085a-254e-41d2-bc59-fb5683c570d6, 5 remaining.
Oct 17, 2017 22:04:04.866 [0x7f5965bff700] DEBUG - Killed 1 idle sessions out of a total of 6.
I’ve got more now that I have upgraded to 1.9.6.4385. I had stayed on the 1.9.4 release for a while and did not see any issues with that build.
Files in the Grab folder.
I hadn’t been watching this as closely so I don’t have fresh logs to submit. I will watch this tonight and see if it happens again and will add logs then.
I think things are stable enough that I am going to close out this thread. I would say my fixes were installing a new antenna (Mohu sky 60) and upgrading to at least 1.9.4.x. The most recent builds seem to be handling things very well (1.10.x and later).
It seems to me like Plex-Media-Server-1.10.0.4523-648bc61d4.exe was the best version so far with DVR reliability.
The two versions since it have had the 100% bug where I never even had it before, you have to kill plextransoder.exe’s to get the 100%'s to go to failed/errored once it does this.
WIth using npvr do you have to deal with device sharing? I have four tuners, but wouldn’t want to split it into 2 for tuning and 2 for dvr. Does it have around 2 week programdata where you can browse all upcoming shows/movies, set tv series auto recording on new episodes?
