Hang Detected

[sflamm]

For some reason my system is suddenly slow... and in the log files I see these "Hang Detected":

Fri 1/27 16:41:38.250 [EventRouter-0023a5000f91@1702a49] About to go to screen My TV
Fri 1/27 16:41:38.251 [EventRouter-0023a5000f91@1702a49] Launching screen My TV
Fri 1/27 16:41:38.269 [EventRouter-0023a5000f91@1702a49] setUI(sage.cb@15959ef[My TV]) histIdx=1 uiHistory=[sage.cb@ba2eb5[Dynamic Menu by nielm], sage.cb@15959ef[My TV]] redo=false
Fri 1/27 16:41:40.321 [EventRouter-0023a5000f91@1702a49] setUI(sage.cb@3b5bb7[Recorded TV]) histIdx=2 uiHistory=[sage.cb@ba2eb5[Dynamic Menu by nielm], sage.cb@15959ef[My TV], sage.cb@3b5bb7[Recorded TV]] redo=false
Fri 1/27 16:41:41.199 [BGLoader2-0023a5000f91@700883] Loading JPEG to VIDEO surface for MetaImage[C:\Program Files (x86)\SageTV\SageTV\GeneratedThumbnails\nasRecordedTVBeatBobbyFlayS10E08CountryBoysintheBigCity68831410ts.jpg#0 512x288 javaImage=false javaMem=0 jref=0]
Fri 1/27 16:41:41.200 [BGLoader2-0023a5000f91@700883] Allocating a high-res surface of size 512x288
Fri 1/27 16:41:41.221 [BGLoader2-0023a5000f91@700883] Loading 512x288 image from file C:\Program Files (x86)\SageTV\SageTV\GeneratedThumbnails\nasRecordedTVBeatBobbyFlayS10E08CountryBoysintheBigCity68831410ts.jpg
Fri 1/27 16:41:41.231 [BGLoader2-0023a5000f91@700883] Successfully loaded YUV image of RawImage[512x288 alpha=false stride=1024 bufferCapacity=294912]
Fri 1/27 16:41:41.232 [BGLoader2-0023a5000f91@700883] About to start loading the YUV image into the video plane...
Fri 1/27 16:41:41.533 [BGLoader2-0023a5000f91@700883] Done loading the YUV image into the video plane (4834600)...
Fri 1/27 16:41:41.717 [EventRouter-0023a5000f91@1702a49] setUI(sage.cb@1df4f93[TV SubGroup]) histIdx=3 uiHistory=[sage.cb@ba2eb5[Dynamic Menu by nielm], sage.cb@15959ef[My TV], sage.cb@3b5bb7[Recorded TV], sage.cb@1df4f93[TV SubGroup]] redo=false
Fri 1/27 16:41:43.104 [AWTThreadWatcher-0023a5000f91@762107] EventThread-0023a5000f91 Hang Detected - hang time = 766
Fri 1/27 16:41:43.869 [AWTThreadWatcher-0023a5000f91@762107] EventThread-0023a5000f91 Hang Detected - hang time = 1531
Fri 1/27 16:41:44.619 [AWTThreadWatcher-0023a5000f91@762107] EventThread-0023a5000f91 Hang Detected - hang time = 2281
Fri 1/27 16:41:45.385 [AWTThreadWatcher-0023a5000f91@762107] EventThread-0023a5000f91 Hang Detected - hang time = 3047
Fri 1/27 16:41:46.150 [AWTThreadWatcher-0023a5000f91@762107] EventThread-0023a5000f91 Hang Detected - hang time = 3812
Fri 1/27 16:41:46.916 [AWTThreadWatcher-0023a5000f91@762107] EventThread-0023a5000f91 Hang Detected - hang time = 4578
Fri 1/27 16:41:47.682 [AWTThreadWatcher-0023a5000f91@762107] EventThread-0023a5000f91 Hang Detected - hang time = 5344
Fri 1/27 16:41:48.447 [AWTThreadWatcher-0023a5000f91@762107] EventThread-0023a5000f91 Hang Detected - hang time = 6109
Fri 1/27 16:41:49.213 [AWTThreadWatcher-0023a5000f91@762107] EventThread-0023a5000f91 Hang Detected - hang time = 6875
Fri 1/27 16:41:49.963 [AWTThreadWatcher-0023a5000f91@762107] EventThread-0023a5000f91 Hang Detected - hang time = 7625
Fri 1/27 16:41:50.729 [AWTThreadWatcher-0023a5000f91@762107] EventThread-0023a5000f91 Hang Detected - hang time = 8391
Fri 1/27 16:41:51.494 [AWTThreadWatcher-0023a5000f91@762107] EventThread-0023a5000f91 Hang Detected - hang time = 9156
Fri 1/27 16:41:52.260 [AWTThreadWatcher-0023a5000f91@762107] EventThread-0023a5000f91 Hang Detected - hang time = 9922
Fri 1/27 16:41:53.010 [AWTThreadWatcher-0023a5000f91@762107] EventThread-0023a5000f91 Hang Detected - hang time = 10672
Fri 1/27 16:41:53.262 [BGLoader2-0023a5000f91@700883] Loading JPEG to VIDEO surface for MetaImage[C:\Program Files (x86)\SageTV\SageTV\GeneratedThumbnails\nasRecordedTVBeatBobbyFlayS11E04TooBiggstoFail77243880ts.jpg#0 512x288 javaImage=false javaMem=0 jref=0]
Fri 1/27 16:41:53.263 [BGLoader2-0023a5000f91@700883] Allocating a high-res surface of size 512x288
Fri 1/27 16:41:53.286 [BGLoader2-0023a5000f91@700883] Loading 512x288 image from file C:\Program Files (x86)\SageTV\SageTV\GeneratedThumbnails\nasRecordedTVBeatBobbyFlayS11E04TooBiggstoFail77243880ts.jpg
Fri 1/27 16:41:53.296 [BGLoader2-0023a5000f91@700883] Successfully loaded YUV image of RawImage[512x288 alpha=false stride=1024 bufferCapacity=294912]
Fri 1/27 16:41:53.297 [BGLoader2-0023a5000f91@700883] About to start loading the YUV image into the video plane...
Fri 1/27 16:41:53.531 [BGLoader2-0023a5000f91@700883] Done loading the YUV image into the video plane (4834936)...
Fri 1/27 16:41:56.244 [AWTThreadWatcher-0023a5000f91@762107] EventThread-0023a5000f91 Hang Detected - hang time = 765
Fri 1/27 16:41:57.010 [AWTThreadWatcher-0023a5000f91@762107] EventThread-0023a5000f91 Hang Detected - hang time = 1531
Fri 1/27 16:41:57.775 [AWTThreadWatcher-0023a5000f91@762107] EventThread-0023a5000f91 Hang Detected - hang time = 2296
Fri 1/27 16:41:58.541 [AWTThreadWatcher-0023a5000f91@762107] EventThread-0023a5000f91 Hang Detected - hang time = 3062
Fri 1/27 16:41:59.307 [AWTThreadWatcher-0023a5000f91@762107] EventThread-0023a5000f91 Hang Detected - hang time = 3828
Fri 1/27 16:42:00.072 [AWTThreadWatcher-0023a5000f91@762107] EventThread-0023a5000f91 Hang Detected - hang time = 4593
Fri 1/27 16:42:00.838 [AWTThreadWatcher-0023a5000f91@762107] EventThread-0023a5000f91 Hang Detected - hang time = 5359
Fri 1/27 16:42:01.604 [AWTThreadWatcher-0023a5000f91@762107] EventThread-0023a5000f91 Hang Detected - hang time = 6125
Fri 1/27 16:42:02.369 [AWTThreadWatcher-0023a5000f91@762107] EventThread-0023a5000f91 Hang Detected - hang time = 6890
Fri 1/27 16:42:03.135 [AWTThreadWatcher-0023a5000f91@762107] EventThread-0023a5000f91 Hang Detected - hang time = 7656
Fri 1/27 16:42:03.900 [AWTThreadWatcher-0023a5000f91@762107] EventThread-0023a5000f91 Hang Detected - hang time = 8421
Fri 1/27 16:42:04.650 [AWTThreadWatcher-0023a5000f91@762107] EventThread-0023a5000f91 Hang Detected - hang time = 9171

Any ideas on how to solve this?

[stuckless]

What's you server and client and STV ui in this case?

[sflamm]

In this case it is the SageTV Native UI... that client is the client on the server (though it happens on HD300 clients as well)

[stuckless]

What is the server? I've seen similar issues like this, on unRAID, when the drives are set to spin down. the Hang time is the time it's taking for the drives to spin back up.

[sflamm]

Server is Windows 2012R2 (8-core Xeon) with a dedicated Adaptec 8805 card running RAID6 which never spins down...

[mgpaulus]

I just noticed the same thing on my Sagetv system. Running V9 on Windows 7 64 bit, and the disks are not set to spin down. (This is in my sagetvclient_0.txt file)

Thu 2/2 19:05:15.853 [AWTThreadWatcher-SAGETV_PROCESS_LOCAL_UI@1a4fdf0] EventThread-SAGETV_PROCESS_LOCAL_UI Hang Detected - hang time = 48002 UILocker=Thread[AWT-EventQueue-0,6,main]
Thu 2/2 19:05:16.603 [AWTThreadWatcher-SAGETV_PROCESS_LOCAL_UI@1a4fdf0] EventThread-SAGETV_PROCESS_LOCAL_UI Hang Detected - hang time = 48752 UILocker=Thread[AWT-EventQueue-0,6,main]
Thu 2/2 19:05:17.353 [AWTThreadWatcher-SAGETV_PROCESS_LOCAL_UI@1a4fdf0] EventThread-SAGETV_PROCESS_LOCAL_UI Hang Detected - hang time = 49502 UILocker=Thread[AWT-EventQueue-0,6,main]
Thu 2/2 19:05:18.103 [AWTThreadWatcher-SAGETV_PROCESS_LOCAL_UI@1a4fdf0] EventThread-SAGETV_PROCESS_LOCAL_UI Hang Detected - hang time = 50252 UILocker=Thread[AWT-EventQueue-0,6,main]
Thu 2/2 19:05:18.853 [AWTThreadWatcher-SAGETV_PROCESS_LOCAL_UI@1a4fdf0] EventThread-SAGETV_PROCESS_LOCAL_UI Hang Detected - hang time = 51002 UILocker=Thread[AWT-EventQueue-0,6,main]
Thu 2/2 19:05:19.603 [AWTThreadWatcher-SAGETV_PROCESS_LOCAL_UI@1a4fdf0] EventThread-SAGETV_PROCESS_LOCAL_UI Hang Detected - hang time = 51752 UILocker=Thread[AWT-EventQueue-0,6,main]
Thu 2/2 19:05:20.353 [AWTThreadWatcher-SAGETV_PROCESS_LOCAL_UI@1a4fdf0] EventThread-SAGETV_PROCESS_LOCAL_UI Hang Detected - hang time = 52502 UILocker=Thread[AWT-EventQueue-0,6,main]
Thu 2/2 19:05:21.103 [AWTThreadWatcher-SAGETV_PROCESS_LOCAL_UI@1a4fdf0] EventThread-SAGETV_PROCESS_LOCAL_UI Hang Detected - hang time = 53252 UILocker=Thread[AWT-EventQueue-0,6,main]
Thu 2/2 19:05:21.853 [AWTThreadWatcher-SAGETV_PROCESS_LOCAL_UI@1a4fdf0] EventThread-SAGETV_PROCESS_LOCAL_UI Hang Detected - hang time = 54002 UILocker=Thread[AWT-EventQueue-0,6,main]
Thu 2/2 19:05:22.603 [AWTThreadWatcher-SAGETV_PROCESS_LOCAL_UI@1a4fdf0] EventThread-SAGETV_PROCESS_LOCAL_UI Hang Detected - hang time = 54752 UILocker=Thread[AWT-EventQueue-0,6,main]

Also seeing a whole bunch of these in my sagetvclient_0.txt:

Thu 2/2 19:11:24.343 [BGLoader2-SAGETV_PROCESS_LOCAL_UI@72f010] Error getting file size for wait data testing:java.net.BindException: Address already in use: connect
Thu 2/2 19:11:24.352 [BGLoader2-SAGETV_PROCESS_LOCAL_UI@72f010] Error getting file size for wait data testing:java.net.BindException: Address already in use: connect
Thu 2/2 19:11:24.358 [FinalRender-SAGETV_PROCESS_LOCAL_UI@15c5e67] DX9Renderer NATIVE WARNING (non-FAILURE) line 579 hr=0x8876086a
Thu 2/2 19:11:24.358 [FinalRender-SAGETV_PROCESS_LOCAL_UI@15c5e67] DX9Renderer creation failed. Wait and then try again, it worked before...size 1920x1080
Thu 2/2 19:11:24.359 [BGLoader2-SAGETV_PROCESS_LOCAL_UI@72f010] Error getting file size for wait data testing:java.net.BindException: Address already in use: connect
Thu 2/2 19:11:24.366 [BGLoader2-SAGETV_PROCESS_LOCAL_UI@72f010] Error getting file size for wait data testing:java.net.BindException: Address already in use: connect
Thu 2/2 19:11:24.373 [BGLoader2-SAGETV_PROCESS_LOCAL_UI@72f010] Error getting file size for wait data testing:java.net.BindException: Address already in use: connect
Thu 2/2 19:11:24.380 [BGLoader2-SAGETV_PROCESS_LOCAL_UI@72f010] Error getting file size for wait data testing:java.net.BindException: Address already in use: connect
Thu 2/2 19:11:24.386 [BGLoader2-SAGETV_PROCESS_LOCAL_UI@72f010] Error getting file size for wait data testing:java.net.BindException: Address already in use: connect
Thu 2/2 19:11:24.393 [BGLoader2-SAGETV_PROCESS_LOCAL_UI@72f010] Error getting file size for wait data testing:java.net.BindException: Address already in use: connect
Thu 2/2 19:11:24.400 [BGLoader2-SAGETV_PROCESS_LOCAL_UI@72f010] Error getting file size for wait data testing:java.net.BindException: Address already in use: connect
Thu 2/2 19:11:24.407 [BGLoader2-SAGETV_PROCESS_LOCAL_UI@72f010] Error getting file size for wait data testing:java.net.BindException: Address already in use: connect
Thu 2/2 19:11:24.414 [BGLoader2-SAGETV_PROCESS_LOCAL_UI@72f010] Error getting file size for wait data testing:java.net.BindException: Address already in use: connect
Thu 2/2 19:11:24.420 [BGLoader2-SAGETV_PROCESS_LOCAL_UI@72f010] Error getting file size for wait data testing:java.net.BindException: Address already in use: connect
Thu 2/2 19:11:24.427 [BGLoader2-SAGETV_PROCESS_LOCAL_UI@72f010] Error getting file size for wait data testing:java.net.BindException: Address already in use: connect
Thu 2/2 19:11:24.434 [BGLoader2-SAGETV_PROCESS_LOCAL_UI@72f010] Error getting file size for wait data testing:java.net.BindException: Address already in use: connect

[Evil_Attorney]

I'm getting the same thing. I've been keeping a close eye on my logs because I can't seem to track down why Sage loses connection to my NAS sometimes during recordings. I ruled out my network and my drives are not set to spin down.

Mon 3/6 20:20:55.130 [FinalRender-0023a5000263@1d529c4] Allocated image-5 for images/tvicon_anim7.png width=46 height=46 ptr=4756328
Mon 3/6 20:20:55.237 [FinalRender-0023a5000263@1d529c4] Loading RawImage of size 46x46 for images/tvicon_anim0.png fileSize=10746
Mon 3/6 20:20:55.238 [FinalRender-0023a5000263@1d529c4] Loading 46x46 image from file C:\Users\CHARL_~1\AppData\Local\Temp\stv4320878861800166300.img
Mon 3/6 20:20:55.244 [FinalRender-0023a5000263@1d529c4] Allocated image-5 for images/tvicon_anim0.png width=46 height=46 ptr=4756384
Mon 3/6 20:20:55.514 [AWTThreadWatcher-0023a5000263@f5c4be] EventThread-0023a5000263 Hang Detected - hang time = 2254 UILocker=Thread[EventRouter-0023a5000263,5,main]
Mon 3/6 20:20:56.265 [AWTThreadWatcher-0023a5000263@f5c4be] EventThread-0023a5000263 Hang Detected - hang time = 3005 UILocker=Thread[EventRouter-0023a5000263,5,main]
Mon 3/6 20:20:57.016 [AWTThreadWatcher-0023a5000263@f5c4be] EventThread-0023a5000263 Hang Detected - hang time = 3756 UILocker=Thread[EventRouter-0023a5000263,5,main]
Mon 3/6 20:20:57.768 [AWTThreadWatcher-0023a5000263@f5c4be] EventThread-0023a5000263 Hang Detected - hang time = 4508 UILocker=Thread[EventRouter-0023a5000263,5,main]
Mon 3/6 20:20:58.520 [AWTThreadWatcher-0023a5000263@f5c4be] EventThread-0023a5000263 Hang Detected - hang time = 5260 UILocker=Thread[EventRouter-0023a5000263,5,main]

[Narflex]

If you set the property "ui/thread_hang_delay_to_dump" to some non-zero value, then if the hang is longer than that in milliseconds when it happens it'll dump all the Java thread states to the log file. Sometimes then it's sort of obvious where it's stuck (like in a filesystem/network access call)...other times it takes someone knowledgeable of the SageTV code to figure it out.

[Evil_Attorney]

Thanks, I will try that setting.