Reproducible Voodoo: I can make my HD-PVR halt on demand

[martin]

I found that I can cause a halt error on demand by pressing power on my HD200 remote while two HD-PVRs are recording. In the attached log file I booted my SageTV server at ~7:00pm and it started two manual recordings. I left SageTV Client running on my desktop and you can see it reestablish a connection at “Sun 11/29 19:02:29.072”. At time 19:05:00 I pressed the power button on my HD200 remote to automatically connect to the server. Within several seconds the bling lights went out on both HD-PVRs. At “Sun 11/29 19:06:40.339” the halt message popped up on the screen that my HD200 was connected to. At “Sun 11/29 19:07:09.211” I stopped the Sage TV service to end logging debug info.

Now tell me "IT'S THE HARDWARE STUPID"

I have attached the log file in the hope someone sees a clue that helps figure out the cause of the halt error. Any ideas are appreciated.

[toricred]

It could still be hardware, just not likely to be the HD-PVR. It could be a shortage of JVM heap as turning on the HD200 would cause a slight jump in this when it starts. It might also have something to do with the hard drive. (I've resolved all my HD-PVR problems by improving throughput of the HDD.)

[martin]

I thought it might be a disruption in I/O, but I can't see anything in perfmon. It's currently using two brand new Western Digital 500GB Caviar Black hard drives with 32MB Cache. Each has 342GB of free space. One of the files that it was recording to (SmashingPumpkinsTheFillmoreResidency-5545406-2.ts) at the time of the halt has 211 fragments according to DiskKeeper.

[jerryt]

Use your list and see if one of these will fix the halt;
I think only 6, 10, 11 1nd 13 would make a difference with network traffic.

Can you run HDTach on the recording drive? and report the numbers?

1. Do a clean install of the drivers
2. Revert to 1.0.5.301 drivers after using hwclear
3. Keep the HD-PVR cool
4. Don’t use SPDIF for audio, use RCA
5. Don’t use hardware versions earlier than E1
6. Defragment your hard drives
7. Lock component output to 720p
8. Use a NEC PCIe USB card
9. Filter power through a UPS
10. Increase Java memory
11. Isolate the HDPVR on its own physical controller
12. Use ferrite beads on the USB cables
13. Upgrade firmware running HcwDriverInstall.exe separately for each HD-PVR

[Chriscic]

Originally Posted by martin

Now tell me "IT'S THE HARDWARE STUPID"

Yes, that quote was from me : ) I have backed away since then as my formerly stable system suddenly went to heck for no apparant reason.

To be clear, are you talking about the HD-PVR lock-up specifically right? I.E. the unit will remain unresponsive until you power cycle it?

Interesting. I'll see if I can reproduce via my setup.

[martin]

I've tried all of those things, but I can do it again. I will try HDTach tonight when I have more time. Here is what I tried before this log file was created:


6. Defragment your hard drives
I moved all of my recordings to my file server last week before I installed two new 500GB drives. These new drives are being filled with recordings for the first time. This morning Sage TV System Information is reporting Used Video Diskspace: 272.10 GB and Available Video Diskspace: 725.84 GB. I will move all the recordings again and try to reproduce the bug with empty drives to eliminate fragmentation as a cause.

10. Increase Java memory
I already increased Java memory to 768MB before reproducing:
[HKEY_LOCAL_MACHINE\SOFTWARE\Frey Technologies\SageTV]
"JVMMaxHeapSizeMB"=dword:00000300
"JVMGCMaxPauseTime"=dword:00000000

In the log file MemStats are logged before and after the halt:

Sun 11/29 19:00:39.147 [Seeker@d9450b] MemStats: Used=47MB Total=71MB Max=799MB
Sun 11/29 19:00:58.048 [Seeker@d9450b] MemStats: Used=43MB Total=76MB Max=799MB
Sun 11/29 19:02:42.319 [Seeker@d9450b] MemStats: Used=48MB Total=76MB Max=799MB
Sun 11/29 19:05:22.412 [AWTThreadWatcher-001d6a4bff42@10900c8] EventThread-001d6a4bff42 Hang Detected - hang time = 3808
Sun 11/29 19:06:35.924 [FSManager@1e6a407] Async encoder halt detector found a halt; kick the Seeker so it can restart the device
Sun 11/29 19:06:35.925 [Seeker@d9450b] MemStats: Used=90MB Total=123MB Max=799MB
Sun 11/29 19:07:09.241 [Seeker@d9450b] MemStats: Used=86MB Total=123MB Max=799MB

11. Isolate the HDPVR on its own physical controller
While reproducing this bug, both HD-PVRs were plugged into an NEC PCIe USB card. I will separate them, one on the card, and the other on the motherboard to see if I can still reproduce.

13. Upgrade firmware running HcwDriverInstall.exe separately for each HD-PVR
Before I reproduced, I used hcwclear.exe and then I ran HcwDriverInstall.exe twice, each time with only one HD-PVR plugged in. I am currently running HD-PVR driver version 1.5.6.1 WHQL.

[jerryt]

Originally Posted by martin

6. Defragment your hard drives
I am currently running HD-PVR driver version 1.5.6.1 WHQL.

Did you format the drive with 64 bit blocks?

You might also try reverting to drivers 1.0.5.301

[Chriscic]

Martin,
If you can reproduce this consistently I suggest you request tech help from Sage and show them this if you haven't already. I don't think trying additional things right away is even a good idea... might you want to work with Sage and Hauppauge now to fix this? Thanks for your efforts by the way.

Jerry, why do you want him to revert back to old drivers? I thought the goal was to reproduce consistently so the bug could be squashed.

[jerryt]

Originally Posted by Chriscic

Jerry, why do you want him to revert back to old drivers?

If it is solid with the 1.0.5.301 drivers (my experience) then it would suggest the problem is a change in the 1.5.6.x drivers.

@Martin, if the HD-PVR's are recording under the Arcsoft application, does the HD200 powering up still halt the recordings? I wonder if the SageTV software scans capture devices when the HD200 powers up?

[martin]

Toricred indicates that delays caused by Java memory management could be significant enough to disrupt recording. Looking at the log file MemStats records I see that Used memory increased from 40MB before the halt to 90MB after. Total memory increased from 76MB to 123MB, so perhaps some garbage collection occurred too.

While creating this log file I used a program called mTail to watch the log file grow in real time. The last time I reproduced the bug, the logging paused while writing the record with timestamp “Sun 11/29 19:05:22.053” for several seconds. The previous time I reproduced the bug it also paused at the same place on the image file "ScrollVBar.png". Logging resumed, but no records were lost; SageTV quickly wrote a whole bunch of logging records to catch up.

I also noticed there is a SageTV registry key named "JVMGCMaxPauseTime" and it is set to zero. If it works like "JVMMaxHeapSizeMB" then it will be ignored. Has anyone used this key? What are the units? What would a reasonable value be? Its name would seem to be “Java Virtual Machine Garbage Collection Maximum Pause Time”. If I set this limit to a low value will it prevent Java Garbage Collection from disrupting recording?

[Opus4]

Is the HD200 anywhere near the HD-PVRs? There have been comments that covering the IR receiver on the HD-PVR seemed to help stability.

- Andy

[martin]

Originally Posted by Opus4

Is the HD200 anywhere near the HD-PVRs? There have been comments that covering the IR receiver on the HD-PVR seemed to help stability.

- Andy

Yes everthing is in the same room. If I'm powering off my HD-PVRs then I will be really embarassed.


UPDATE: I'm able to reproduce the bug without using the remote. If I plug in the power cable to the HD200 in the same room it still creates a halt error. I tried another HD200 in a different room with the remote and it also created a halt error. Regardless, my IR ports are covered with duct tape now, just like a professional home theatre installer would use.

[martin]

Originally Posted by jerryt

Did you format the drive with 64 bit blocks?

You might also try reverting to drivers 1.0.5.301

Yes, Allocation unit size 64K was used during formatting both of the new drives.

[Chriscic]

I was unable to get a HD-PVR lock-up following the steps you provided. Not saying it doesn't work for you, but my units kept recording happily. My HD200 is in a different room.

[jerryt]

My server has the VooDoo virus?

Found my rock solid HD-PVR today with the bling light on, odd, I thought since I was not recording anything. Checked playback in Sage and it failed. Had to reboot and recycle power to get everything back up...

[Chriscic]

Originally Posted by jerryt

My server has the VooDoo virus?

Found my rock solid HD-PVR today with the bling light on, odd, I thought since I was not recording anything. Checked playback in Sage and it failed. Had to reboot and recycle power to get everything back up...

Cover the IR port
(yes that was good-natured sarcasm)

[toricred]

If I remember correctly the setting of 300 (Hex) for the memory size is only about 768MB. I've always found it to need 1024MB, but then again I'm using 4 HD extenders and 4 HD-PVRs.

[martin]

After reverting to 1.0.5.301 drivers after using hwclear the bug has clearly gone away. Time will tell if all halt errors are gone forever, but I can't reproduce it anymore by powering on one or more of my HD200s. In fact nothing I do can make a halt error on demand now. With all four tuners recording and three clients playing back simultaneously it hasn't created any errors yet.

So this leaves the question: how was booting the HD200 able to cause an error in recording? Have I proven anything other than the HD-PVR driver version 1.5.6.1 sucks?

[sic0048]

I saw something weird last night that might be similar in nature. I was watching "live" tv through my HD-100 on a channel coming through the HD-PVR. I was also working on my WHS via RDP (the WHS also acts as my SageTV server). I had logged out for a while and when I logged back in, it caused the HD-PVR to lock up.

Now I've logged in and out of that machine many, many times without any issues (even several times earlier yesterday evening). I suspect the WHS was balancing the drives at the time, so perhaps i/o speed to the diskdrive was different from normal.

But something about logging in via RDP cause the HD-PVR to lock up. The HD-100 had buffered a couple seconds of video, so it took a couple seconds before I saw the black screen with "No Signal", but I would bet money the timing actually occured when I logged in.

I guess this just proves that there are weird situations where you can lock up the HD-PVR. Perhaps it is related to Disk read/write times, perhaps not.

I'm on the .301 firmware and normally don't see any lockups. I certainly would not call this episode random however, and therefore I am not too worried about it.

[martin]

My system hasn't had any errors for the last three weeks after reverting to 1.0.5.301 drivers after using hwclear. I decided to add a third HD-PVR to my system today, so I ran HcwDriverInstall.exe to flash it's firmware to ensure there are no differences between them. I noticed the blue, red and amber LEDs did not come on during the flash process like I recalled. I continued anyway and tried to record three shows simultaneously. Within minutes I started getting halt errors on the new HD-PVR.

Suspecting it wasn't flashed correctly, I connected the new HD-PVR to my laptop and ran hwclear. I then ran HcwDriverInstall.exe using the 1.5.6.1 drivers downloaded from Hauppauge's support web site. This time the LEDs lit up. Then I ran hwclear, rebooted and then ran HcwDriverInstall.exe from my driver CD to downgrade to 1.0.5.301 drivers and firmware. After plugging the downgraded HD-PVR back into my Sage system, everything seems to be working again.

I just thought I would share this tip in case anyone else did not flash correctly. It seems to be necessary to upgrade, then downgrade to get to the 1.0.5.301 drivers and firmware to work properly.