Spinning circle when STOPPING playback

[Skirge01]

This issue started being discussed here, but I think it should have its own thread.

Long story short: I built a brand new server (specs below), installed Sage new under vSphere 5.0.1, and have another VM running FlexRAID for storage pooling (all recordings are stored there). Ever since I got Sage running under the VM, I get the spinning circle for 15-30 seconds when stopping playback. Playback starts just fine and is quite smooth.

So far, I've put each of the VM's listed above on separate SSD's and converted all the drives to 64k clusters. I've also run some jperf tests, but I'm not sure I know what I'm really doing there. The client PC did get an SSD installed somewhat recently, but I'm not sure whether or not that was before the server upgrade, so I can't say whether or not the new SSD was working fine with the old server. If I still have the old HDD with the OS still installed, I'll try swapping that back in to verify this.

My current plan is to revert to a stock STV (sidenote: need to figure out how to completely remove Gemstone) and see if that fixes it.

sflamm also has me wondering if I'm running the latest Java release on both the server and the client.

If anyone has additional ideas where I should be looking, please do so.

EDIT: Server Specs

Supermicro X9SAE-V-O LGA1155
Intel i7 3770T
32GB DDR3
LSI M1015 (via pass-thru)
NEC-based USB PCI card (via pass-thru)
Seagate 3TB ST3000DM001 (x6 for storage)
Plextor 128GB M5S (1 each for 2 VM's)
SanDisk Cruzer Fit 16GB (boot drive for vSphere Hypervisor)

[sflamm]

definitely start debugging with stock STV.

[Skirge01]

I added the server specs to the original post. I just installed the latest Java update (1.7.0.10) on both the server and client and also reverted to stock STV, as well as disabling most plugins. I even uninstalled Gemstone completely. Most of the remaining plugins are fanart API related. I also have some minor UI mods (e.g. back on EPG) and TVE installed.

In case it matters, the SageTV server is running under Windows XP 32-bit (4GB allotted to the VM; Sage is this VM's only job), SageTV client is Windows 7 Home 64-bit (4GB), and FlexRAID is under Windows 7 Pro 64-bit (8GB; currently FR is this VM's only job).

In the attached snippet of the debug file, I started and stopped the same file twice; once around 22:21 and again around 22:25. I see several UI hangs showing, but I don't know what the cause is.

Anyone have some ideas what might be causing the hang and how to remedy?

[sflamm]

Are all these VMs running on the same machine? How much memory is on the host itself and how much is consumed by VMs?

[Skirge01]

I said some of that above, but it may've gotten lost in my rambling. Yes, all the VM's are on one machine; the client PC is not a VM, but I think you knew that. The host has 32GB of memory and, assuming I'm looking at the charts the right way, the ACTIVE memory for the host averages 1.7GB, but shows a max ACTIVE of 4.2GB. Those numbers were showing on the chart after several instances of starting and stopping playback. If that's not the correct measurement to be looking at, let me know what I should be paying attention to. I won't pretend to be an expert on vSphere!

[gplasky]

Looks like your UI hangs are occurring after each time the VMR9 info changes.

Wed 1/2 22:25:22.496 [Thread-943@184d6fe] VMR9 info has changed width=1920 height=1080 arx=0 ary=0
Wed 1/2 22:25:22.549 [AWTThreadWatcher-SAGETV_PROCESS_LOCAL_UI@374534] EventThread-SAGETV_PROCESS_LOCAL_UI Hang Detected - hang time = 750

I would make sure you have upgraded the DirectX runtime components to the latest and see if that helps. (DirectX 9 for XP)

Gerry

[Skirge01]

Wait a second... the log file I posted was from the client PC, which is running Windows 7. Shouldn't that be using EVR? Don't tell me that somehow got switched and has been the cause of the lag all this time. I'll be doing a in short order. I'll check this out tonight.

[gplasky]

Your log says it is using EVR for presentation. But I think the Sage Player uses VMR which is where that line is coming from. I'm only going by the log.

Wed 1/2 22:21:53.887 [AWT-EventQueue-0@128a415] Creating GraphPluginHandler...
Wed 1/2 22:21:53.887 [AWT-EventQueue-0@128a415] Done creating GraphPluginHandler
Wed 1/2 22:21:53.888 [AWT-EventQueue-0@128a415] DShowPlayer setVideoRendererFilter0({FA10746C-9B63-4B6C-BC49-FC300EA5F256}) called
Wed 1/2 22:21:53.888 [AWT-EventQueue-0@128a415] Using EVR for video render
Wed 1/2 22:21:53.915 [AWT-EventQueue-0@128a415] Using 3 input pins on the EVR
Wed 1/2 22:21:53.915 [AWT-EventQueue-0@128a415] Finished with EVR configuration OK
Wed 1/2 22:21:53.915 [AWT-EventQueue-0@128a415] DShowPlayer setVideoDecoderFilter0(Microsoft DTV-DVD Video Decoder) called

You also get DirectX9 textures being created from the metafonts. All the way Sage works. So you need to make sure your DirectX 9 is healthly and updated.



Here you get your longest wait:

Sending event to server for PlaybackStopped args={UIContext=/192.168.1.100:55539, MediaTime=1325048408369, ChapterNum=0, MediaFile=MediaFile[id=12947004 A[12823703,119699,"Aliens vs. Predator: Requiem",58574@1228.00:00,120] mask=TV host=SageTV-VM encodedBy=Hauppauge HD PVR Capture Device HDPVRMax format=MPEG2-TS 1:59:51 2884 kbps [#0 Video[H.264 29.97003 fps 1920x1080 16:9 interlaced id=1011]#1 Audio[AC3 48000 Hz 2 channels 384 kbps MAIN idx=1 id=1100]{ScrapedBy=Phoenix, IMDBID=tt0758730, MediaType=Movie, ScrapedDate=1350790824345, MediaProviderDataID=tt0758730, MediaTitle=AVPR: Aliens vs Predator - Requiem, DiscNumber=0, UserRating=47, MediaProviderID=imdb}] \\W7-Server\Recordings (DVR)\AliensvsPredatorRequiem-12823703-0.ts, Seg0[Wed 12/28 0:00:00.014-Wed 12/28 1:59:51.494]], Duration=7191480, TitleNum=0}
Wed 1/2 22:22:01.905 [VideoFrame-SAGETV_PROCESS_LOCAL_UI@18f4f91] VF processing job null nPlayin=false
Wed 1/2 22:22:01.905 [VideoFrame-SAGETV_PROCESS_LOCAL_UI@18f4f91] VF thread is now waiting for 0:00:00.000
Wed 1/2 22:22:02.059 [AWT-EventQueue-0@128a415] setUI(sage.cb@151448c[TV Explorer]) histIdx=7 uiHistory=[sage.cb@1b4cf46[Main Menu], sage.cb@151448c[TV Explorer], sage.cb@102aa10[Main Menu], sage.cb@2667a2[Plugin List], sage.cb@1b4cf46[Main Menu], sage.cb@1b1cd95[Scheduled Recordings], sage.cb@1b4cf46[Main Menu], sage.cb@151448c[TV Explorer], sage.cb@1009d04[MediaPlayer OSD]] redo=true
Wed 1/2 22:22:02.059 [AWT-EventQueue-0@128a415] VideoFrame got registration of a subtitle UI component: null
Wed 1/2 22:22:02.059 [AWT-EventQueue-0@128a415] VideoFrame got registration of a cc UI component: null
Wed 1/2 22:22:02.060 [AWT-EventQueue-0@128a415] Get Imported TV Files - Start
Wed 1/2 22:22:02.060 [AWT-EventQueue-0@128a415] Display ImportedTV = true
Wed 1/2 22:22:02.060 [AWT-EventQueue-0@128a415] LimitSearchPaths = None
Wed 1/2 22:22:02.060 [AWT-EventQueue-0@128a415] TCED: Non-null TVImportFiles 222
Wed 1/2 22:22:02.061 [AWT-EventQueue-0@128a415] Get Imported TV Files - Done
Wed 1/2 22:22:02.061 [AWT-EventQueue-0@128a415] Get Recorded Files - Start
Wed 1/2 22:22:02.092 [AWT-EventQueue-0@128a415] Get Recorded Files - Done
Wed 1/2 22:22:02.093 [AWT-EventQueue-0@128a415] Get Scheduled Files - Start
Wed 1/2 22:22:02.823 [AWTThreadWatcher-SAGETV_PROCESS_LOCAL_UI@374534] EventThread-SAGETV_PROCESS_LOCAL_UI Hang Detected - hang time = 750
Wed 1/2 22:22:03.573 [AWTThreadWatcher-SAGETV_PROCESS_LOCAL_UI@374534] EventThread-SAGETV_PROCESS_LOCAL_UI Hang Detected - hang time = 1500
Wed 1/2 22:22:04.323 [AWTThreadWatcher-SAGETV_PROCESS_LOCAL_UI@374534] EventThread-SAGETV_PROCESS_LOCAL_UI Hang Detected - hang time = 2250
Wed 1/2 22:22:05.073 [AWTThreadWatcher-SAGETV_PROCESS_LOCAL_UI@374534] EventThread-SAGETV_PROCESS_LOCAL_UI Hang Detected - hang time = 3000
Wed 1/2 22:22:05.823 [AWTThreadWatcher-SAGETV_PROCESS_LOCAL_UI@374534] EventThread-SAGETV_PROCESS_LOCAL_UI Hang Detected - hang time = 3750
Wed 1/2 22:22:06.573 [AWTThreadWatcher-SAGETV_PROCESS_LOCAL_UI@374534] EventThread-SAGETV_PROCESS_LOCAL_UI Hang Detected - hang time = 4500
Wed 1/2 22:22:07.323 [AWTThreadWatcher-SAGETV_PROCESS_LOCAL_UI@374534] EventThread-SAGETV_PROCESS_LOCAL_UI Hang Detected - hang time = 5250
Wed 1/2 22:22:08.073 [AWTThreadWatcher-SAGETV_PROCESS_LOCAL_UI@374534] EventThread-SAGETV_PROCESS_LOCAL_UI Hang Detected - hang time = 6000
Wed 1/2 22:22:08.823 [AWTThreadWatcher-SAGETV_PROCESS_LOCAL_UI@374534] EventThread-SAGETV_PROCESS_LOCAL_UI Hang Detected - hang time = 6750
Wed 1/2 22:22:09.573 [AWTThreadWatcher-SAGETV_PROCESS_LOCAL_UI@374534] EventThread-SAGETV_PROCESS_LOCAL_UI Hang Detected - hang time = 7499
Wed 1/2 22:22:10.323 [AWTThreadWatcher-SAGETV_PROCESS_LOCAL_UI@374534] EventThread-SAGETV_PROCESS_LOCAL_UI Hang Detected - hang time = 8249
Wed 1/2 22:22:11.072 [AWTThreadWatcher-SAGETV_PROCESS_LOCAL_UI@374534] EventThread-SAGETV_PROCESS_LOCAL_UI Hang Detected - hang time = 8999

Notice what causes the longest wait:

Wed 1/2 22:22:02.061 [AWT-EventQueue-0@128a415] Get Imported TV Files - Done
Wed 1/2 22:22:02.061 [AWT-EventQueue-0@128a415] Get Recorded Files - Start
Wed 1/2 22:22:02.092 [AWT-EventQueue-0@128a415] Get Recorded Files - Done
Wed 1/2 22:22:02.093 [AWT-EventQueue-0@128a415] Get Scheduled Files - Start
Wed 1/2 22:22:02.823 [AWTThreadWatcher-SAGETV_PROCESS_LOCAL_UI@374534] EventThread-SAGETV_PROCESS_LOCAL_UI Hang Detected - hang time = 750
Wed 1/2 22:22:03.573 [AWTThreadWatcher-SAGETV_PROCESS_LOCAL_UI@374534] EventThread-SAGETV_PROCESS_LOCAL_UI Hang Detected - hang time = 1500
Wed 1/2 22:22:04.323 [AWTThreadWatcher-SAGETV_PROCESS_LOCAL_UI@374534] EventThread-SAGETV_PROCESS_LOCAL_UI Hang Detected - hang time = 2250
Wed 1/2 22:22:05.073 [AWTThreadWatcher-SAGETV_PROCESS_LOCAL_UI@374534] EventThread-SAGETV_PROCESS_LOCAL_UI Hang Detected - hang time = 3000
Wed 1/2 22:22:05.823 [AWTThreadWatcher-SAGETV_PROCESS_LOCAL_UI@374534] EventThread-SAGETV_PROCESS_LOCAL_UI Hang Detected - hang time = 3750
Wed 1/2 22:22:06.573 [AWTThreadWatcher-SAGETV_PROCESS_LOCAL_UI@374534] EventThread-SAGETV_PROCESS_LOCAL_UI Hang Detected - hang time = 4500
Wed 1/2 22:22:07.323 [AWTThreadWatcher-SAGETV_PROCESS_LOCAL_UI@374534] EventThread-SAGETV_PROCESS_LOCAL_UI Hang Detected - hang time = 5250
Wed 1/2 22:22:08.073 [AWTThreadWatcher-SAGETV_PROCESS_LOCAL_UI@374534] EventThread-SAGETV_PROCESS_LOCAL_UI Hang Detected - hang time = 6000
Wed 1/2 22:22:08.823 [AWTThreadWatcher-SAGETV_PROCESS_LOCAL_UI@374534] EventThread-SAGETV_PROCESS_LOCAL_UI Hang Detected - hang time = 6750
Wed 1/2 22:22:09.573 [AWTThreadWatcher-SAGETV_PROCESS_LOCAL_UI@374534] EventThread-SAGETV_PROCESS_LOCAL_UI Hang Detected - hang time = 7499
Wed 1/2 22:22:10.323 [AWTThreadWatcher-SAGETV_PROCESS_LOCAL_UI@374534] EventThread-SAGETV_PROCESS_LOCAL_UI Hang Detected - hang time = 8249
Wed 1/2 22:22:11.072 [AWTThreadWatcher-SAGETV_PROCESS_LOCAL_UI@374534] EventThread-SAGETV_PROCESS_LOCAL_UI Hang Detected - hang time = 8999
Wed 1/2 22:22:11.072 [AWTThreadWatcher-SAGETV_PROCESS_LOCAL_UI@374534] EventThread-SAGETV_PROCESS_LOCAL_UI Hang Detected - hang time = 8999
Wed 1/2 22:22:11.500 [AWT-EventQueue-0@128a415] Get Scheduled Files - Done
Wed 1/2 22:22:11.500 [AWT-EventQueue-0@128a415] Start applying filters
Wed 1/2 22:22:11.501 [AWT-EventQueue-0@128a415] Done applying filters
Wed 1/2 22:22:11.501 [AWT-EventQueue-0@128a415] Start Grouping
Wed 1/2 22:22:11.539 [AWT-EventQueue-0@128a415] Done Grouping
Wed 1/2 22:22:11.539 [AWT-EventQueue-0@128a415] Starting EpSorting
Wed 1/2 22:22:11.822 [AWTThreadWatcher-SAGETV_PROCESS_LOCAL_UI@374534] EventThread-SAGETV_PROCESS_LOCAL_UI Hang Detected - hang time = 9749

It looks like it is having a hard time reading what is scheduled to record. Also hangs sorting the episodes.


Gerry

[MattHelm]

BTW, I have your setup, but all in hardware (no VM) and don't have any issue like this. Just my $0.02.

[Skirge01]

Originally Posted by gplasky

Your log says it is using EVR for presentation. But I think the Sage Player uses VMR which is where that line is coming from. I'm only going by the log.

<huge snip>

It looks like it is having a hard time reading what is scheduled to record. Also hangs sorting the episodes.


Gerry

Got it. Thanks, Gerry. I'll check the DirectX status when I get home. Do you know if that data (i.e. scheduled and episode list) is stored on the client or the server? Could this be a wiz.bin corruption issue?

[Skirge01]

Originally Posted by MattHelm

BTW, I have your setup, but all in hardware (no VM) and don't have any issue like this. Just my $0.02.

Didn't your mother ever tell you that if you couldn't say something nice... LOL!

In all seriousness, that's precisely why I'm not blaming Sage itself. I have every reason to suspect it IS due to vSphere, but I need to be able to prove that. It would mean there's a bottleneck somewhere and I need to track it down and figure out how to alleviate--if not eliminate--it. If I need a faster processor, I'll buy one. But, none of my performance info in vSphere seems to be telling me there's an issue anywhere on the host. I'm hoping someone with more VM experience will be able to help me find it and figure out the next steps.

[sflamm]

Since all your VMs are using Windows why not run the whole thing using the MSFT hypervisor within a W2012 host (convert to existing machines to VHD). I bet that will work better.

[Skirge01]

I don't really want to switch, but would that actually work? I am running a pfSense (Linux) firewall, as well. Plus, I need the PCI passthrough, which I didn't think Hyper-V could do. Additionally, unless they changed something since my last look, Hyper-V isn't free unless you use the command line-only version.

[MattHelm]

Originally Posted by Skirge01

Didn't your mother ever tell you that if you couldn't say something nice... LOL!

In all seriousness, that's precisely why I'm not blaming Sage itself. I have every reason to suspect it IS due to vSphere, but I need to be able to prove that. It would mean there's a bottleneck somewhere and I need to track it down and figure out how to alleviate--if not eliminate--it. If I need a faster processor, I'll buy one. But, none of my performance info in vSphere seems to be telling me there's an issue anywhere on the host. I'm hoping someone with more VM experience will be able to help me find it and figure out the next steps.

I didn't mean it that way. Just adding an additional data point, since my setup is all hardware and yours is VM, but the setups match otherwise. Hope you get it figured out, and more importantly, post the fix, if you find one!!!

[sflamm]

hyper-v server 2012 is free (not W2012 with hyper-v). you can run guests that are Centos, Redhat and SUSE.

[sflamm]

http://blogs.technet.com/b/keithmaye...x#.UOXecuTAd8g

http://www.microsoft.com/en-us/serve...r/default.aspx

[Skirge01]

Originally Posted by MattHelm

I didn't mean it that way.

I know. I thought it was pretty damn funny, though.

Just adding an additional data point, since my setup is all hardware and yours is VM, but the setups match otherwise. Hope you get it figured out, and more importantly, post the fix, if you find one!!!

I definitely appreciate that and it was a very valid data point.

Originally Posted by sflamm

hyper-v server 2012 is free (not W2012 with hyper-v). you can run guests that are Centos, Redhat and SUSE.

I really don't want to change and would much rather figure out this issue. There's got to be a solution. In all seriousness, for the amount of effort it would take to switch, I'd just as soon deal with the delay instead. That said, however, while Hyper-V 2012 is free, I don't believe it does PCI passthrough or allows you to use a GUI to maintain it.

[sflamm]

There is a UI to maintain it - runs from a Windows Desktop machine (see installation instructions).

It does not support PCI passthrough - but why would you need that? Setup all your video sources as network encoders - more flexible in the long run.

I understand it is work to try given that VMWare is installed. But unless you can get the VSphere install working correctly it might be a good alternative.

Given your setup I am wondering why not just run W2012, install SageTV server and use it's built in storage services? No VMs and should run like a champ.

[BobPhoenix]

I have two SageTV servers Virtualized in ESXi 5.0, Win7 x64 and I can't say it takes very long when I stop a video. I'm on clients only right now but when I had HD200s connected I don't remember any significant slow downs on the VM servers verses the non-VM servers. The only time I notice a problem is when the video being viewed is not local to the VM. I have the "spinning circles of death" when browsing the videos as drives spin up to access the files (I assume anyway) and occasionally when I stop. But any video that is stored on drives connected to a local controller passed through to the VM seem to work fine so far for me. I do notice a problem now but I'm attributing it to the fact that I'm using a port multiplier and external cage for those local drives now instead of an SASLP-MV8 like I used to have on pass through. If the external cages with miniSAS connectors were cheaper I would use them instead and get a LSI card to pass through to the VMs. But 2-3 times the price means I will put up with delays for now.

[sflamm]

The only time I notice a problem is when the video being viewed is not local to the VM.

That should be always - why would the video not go to shared storage independent of any VM?

Sounds like you are having a serious issue.