(Windows) Upgrade path blocked @ 9.0.8.423

[Monedeath]

Actually bothered to start updating some things on my system @home and updated the server in preparation of installing Open DCT. Only hit a snag when trying to move from a self compiled "9.0.3.3" Jar from November 2015, to the latest 9.0.13 Jar file. The server would refuse to even launch the Java portion of SageTV. I would instead get a series of 4 error prompts from Java. (included later)

Using the Windows installer instead likewise didn't change the outcome. Regressing to several couple different earlier versions also didn't result in any kind of activity from Sage(not even a log file entry).

So I reverted back to my 9.0.3.3 Jar file, confirmed everything still worked, and then worked my way forward from there until it broke. I went through the archive of updates Stuckless hosts, and the "breaking point" seems to be going from 9.0.7.369 and 9.0.8.423 at which point things break, and subsequent version produce the same results.

It should be noted the server has now been updated from Java 7 update 45 to Java 7 update 80 in the course of chasing this(doesn't change the outcome). It is a Windows 7 32 bit system. Currently running 9.0.7.369 without major issue so far, but I would like to get it progressed past that point. Help is more than welcome.

[jusjoken]

Have you tried the newest installer and then run it a second time and select repair?

k

[wnjj]

Spartan had the same issue here https://forums.sagetv.com/forums/showthread.php?t=63853.

Not sure if he ever got it going but there are some things Narflex suggested to look at that might work for you.

[Fuzzy]

If you replaced any of the original files (like the .jar you put in), the v9 updater won't replace them in normal mode, only in repair mode. That's why you need to run it once, then run it again in 'repair' so everything gets brought up to the proper version.

[Monedeath]

Originally Posted by jusjoken

Have you tried the newest installer and then run it a second time and select repair?

Yes the installer was run twice, the second time after disabling the SageTV service and rebooting the server. It did run in repair mode.

[Monedeath]

Originally Posted by wnjj

Spartan had the same issue here https://forums.sagetv.com/forums/showthread.php?t=63853.

Not sure if he ever got it going but there are some things Narflex suggested to look at that might work for you.

Registry seems fully convinced I'm running Java 1.7 update 80. Screenshots below.

Now to figure out why the SageTV server is also refusing to acknowledge my SageTV Registration as valid for getting EPG data while on 9.0.7.369, going to try to find a solution on that rather than track down where it unbreaks in the repo.

[Monedeath]

Ok, Narflex's last post in the other thread potentially nailed what the problem likely was. Haven't fully tested it yet with a newer jar file yet. But there has been a noted oddity where SageTV on the system information screen would continually insist that the server was running Java 1.6.0 for some reason even though we could find no trace of it anywhere.

Turns out it was residing in a "jre" folder within the SageTV install directory.

Moved that folder outside of the Sage directory tree, and system information now claims 1.7.0_80 for the Java Version.

Now to see if I can update it, and then start chasing SageTV no longer recognizing my registration key, and it rejecting my efforts to input it through the UI in 9.0.7.369(first step: stop running 7.369)

Edit: SageTV v9.0.13.536 now seems to be running on the server. Now comes the fun of seeing what else may be broken.

Edit 2: (Legacy) EPG is still broke on 9.0.13.539 and it is rejecting my registration keys through the client, isn't there a way to force it(through the registry?)

My Hauppauge 2250 also is being very... slow/problematic in tuning into programming, so I guess I'll be looking into a driver refresh on that front to see if that helps.

[Monedeath]

Originally Posted by Monedeath

Edit 2: (Legacy) EPG is still broke on 9.0.13.539 and it is rejecting my registration keys through the client, isn't there a way to force it(through the registry?)

My Hauppauge 2250 also is being very... slow/problematic in tuning into programming, so I guess I'll be looking into a driver refresh on that front to see if that helps.

The broken (Legacy) EPG is irksome, but was intending to sign up for schedules direct service this week, for testing on a system I'm building. Mildly annoyed to be forced into it on the current server at the same time.

The Hauppauge 2250 issue is just odd and vexing, it shouldn't lock the sage server down for 10 to 15 minutes while trying to tune into a channel(and drag down even the stand alone clients in the process!). Going to mess with tuning delay to see if that helps, as the driver update did nothing.

Edit: Although I think a 15 minute tuning delay is a tad bit on the extreme side. Grabbing the SageTV Log for that.

Edit 2: added log file from just before the start of the hang until the next minute after it ended. (This was with the latest drivers)

Edit 3: Talking to others here, it seems this specific issue may have been presenting in a more subtle form even in 9.0.3.3 but this is much worse, all the same.

[wnjj]

To use your legacy EPG key in V9, create a global environment variable called SAGETVUSERKEY and put the key value in there.

Number 33 in this list: https://forums.sagetv.com/forums/showthread.php?t=62320

[jusjoken]

Originally Posted by wnjj

To use your legacy EPG key in V9, create a global environment variable called SAGETVUSERKEY and put the key value in there.

Number 33 in this list: https://forums.sagetv.com/forums/showthread.php?t=62320

Actually the current workaround is to create a file in the sagetv root called activkey, no extension and spell it like i did and put the key in there.

I do not understand at all why the latest installer is not working for you...have you tried again after resolving the jre issue?

k

[Monedeath]

Originally Posted by jusjoken

Actually the current workaround is to create a file in the sagetv root called activkey, no extension and spell it like i did and put the key in there.

I do not understand at all why the latest installer is not working for you...have you tried again after resolving the jre issue?

Not working in what way? It failed to detect the "jre" folder in the install directory and trigger an alert or take any action on it. As that directory also had Java 6 inside of it, it was then causing SageTV to fail to launch due to not meeting current minimum requirements.

The jre folder even presenting as an issue for many upgrade/install scenarios is probably pretty low. Although I wouldn't be surprised to see it crop up a few more times by July(lucene core is far more likely), as I imagine it was put there as part of a plugin install at one point in time, so when those people try to upgrade such a system....

Once the offending folder was removed, putting the proper JAR file back resolved my initial issue, no further action needed.

I wasn't aware that the installer would address keeping the Legacy guide? I don't recall seeing a prompt when it ran.

As the other problem with the Hauppauge 2250, I think Narflex or someone else is going to have to figure out what is going on there. I suspect a memory issue(or the card is feeling its age), but I'm not certain. I doubt that was an installer problem.

[Monedeath]

Originally Posted by wnjj

To use your legacy EPG key in V9, create a global environment variable called SAGETVUSERKEY and put the key value in there.

Number 33 in this list: https://forums.sagetv.com/forums/showthread.php?t=62320

Hadn't though of looking there, didn't think it was relevant, considering I'd been running V9 since shortly after it was released. It wasn't until this update to a newer version that it dropped out for some reason.

And

On Windows the global environment variable SAGETVUSERKEY should be set to be your license key if you’re using the EXE built from the open source codebase.

Would explain it, since the installer would have zapped the SageTV7 exe.

[wnjj]

Originally Posted by jusjoken

Actually the current workaround is to create a file in the sagetv root called activkey, no extension and spell it like i did and put the key in there.

I do not understand at all why the latest installer is not working for you...have you tried again after resolving the jre issue?

k

It looks like either method will work but activkey is compatible with Linux. If activkey doesn't exist it will check the env var.

Nevertheless, all moot in July.

[Monedeath]

Originally Posted by jusjoken

Actually the current workaround is to create a file in the sagetv root called activkey, no extension and spell it like i did and put the key in there.

Now if only Sage had generated that file before I replaced the launcher. Oh well, kind of hard to fix it now in my case.

[Monedeath]

Originally Posted by Monedeath

The Hauppauge 2250 issue is just odd and vexing, it shouldn't lock the sage server down for 10 to 15 minutes while trying to tune into a channel(and drag down even the stand alone clients in the process!). Going to mess with tuning delay to see if that helps, as the driver update did nothing.

Edit 3: Talking to others here, it seems this specific issue may have been presenting in a more subtle form even in 9.0.3.3 but this is much worse, all the same.

To clarify "Stand alone client" means full client.

Further investigation has turned up that 001d6a4c00d2 is the Extender we were using. So to quote back a selectively edited segment from that log when the Hang resolved itself:

Sat 2/18 14:34:37.413 [MainMsg@162088] setupEncoding0 called for 1252158104 'Hauppauge WinTV-7164 Analog Capture-1' (ver 1.0)
Sat 2/18 14:34:37.413 [MainMsg@162088] QAM:Got capture drv info for QAM mfg:'Hauppauge' Hauppauge WinTV-7164 Analog Capture-1
Sat 2/18 14:34:37.413 [MainMsg@162088] QAM: Hauppauge QAM interface not found (0) hr=0x80070492 at Hauppauge WinTV-7164 Analog Capture-1 
Sat 2/18 14:34:37.413 [MainMsg@162088] QAM:not supported Hauppauge WinTV-7164 Analog Capture-1
Sat 2/18 14:34:37.413 [MainMsg@162088] Encoding to file \\Foo-Media\Recordings\Disk 3\SageDrive3\SkatingGymnasticsSpectacular-15351192-0.mpg
Sat 2/18 14:34:37.415 [MainMsg@162088] setupEncoding0 Trace27 
Sat 2/18 14:34:37.415 [MainMsg@162088] setupEncoding0 Trace28 
Sat 2/18 14:34:37.415 [MainMsg@162088] startEncoding0 called for 'Hauppauge WinTV-7164 Analog Capture-1'
Sat 2/18 14:34:37.978 [AWTThreadWatcher-001d6a4c00d2@16ffdcc] EventThread-001d6a4c00d2 Hang Detected - hang time = 633629 UILocker=Thread[EventRouter-001d6a4c00d2,5,main]
Sat 2/18 14:34:38.134 [MainMsg@162088] GetBroadcastStandard ATSC NET for device:'Hauppauge WinTV-7164 Analog Capture-1'
Sat 2/18 14:34:38.135 [AsyncWatch@13a5720] VF.submitJob(VFJob[WatchMF r=0.0 t=0 file=MediaFile[id=15408810 A[15351192,15350610,"Skating & Gymnastics Spectacular",91098@0218.13:00,120,T] mask=TV host=Foo-Media encodedBy=Hauppauge WinTV-7164 Analog Capture #2 K21JCD format=MPEG2-PS 0:00:00 0 kbps [] \\Foo-Media\Recordings\Disk 3\SageDrive3\SkatingGymnasticsSpectacular-15351192-0.mpg, Seg0[Sat 2/18 14:22:42.997-Wed 12/31 17:00:00.000]] ifn=null])
Sat 2/18 14:34:38.159 [Seeker@16e4577] RootFile=\\Foo-Media\Recordings fstype=null fileLength=0 file=\\Foo-Media\Recordings\Disk 3\SageDrive3\SkatingGymnasticsSpectacular-15351192-0.mpg
Sat 2/18 14:34:38.166 [VideoFrame-001d6a4c00d2@bbac5f] VF processing job VFJob[WatchMF r=0.0 t=0 file=MediaFile[id=15408810 A[15351192,15350610,"Skating & Gymnastics Spectacular",91098@0218.13:00,120,T] mask=TV host=Foo-Media encodedBy=Hauppauge WinTV-7164 Analog Capture #2 K21JCD format=MPEG2-PS 0:00:00 0 kbps [] \\Foo-Media\Recordings\Disk 3\SageDrive3\SkatingGymnasticsSpectacular-15351192-0.mpg, Seg0[Sat 2/18 14:22:42.997-Wed 12/31 17:00:00.000]] ifn=null] nPlayin=false
Sat 2/18 14:34:38.174 [AsyncWatch@13a5720] CEPoolSize=14
Sat 2/18 14:34:38.181 [VideoFrame-001d6a4c00d2@bbac5f] VF processing on UI Thread VFJob[WatchMF r=0.0 t=0 file=MediaFile[id=15408810 A[15351192,15350610,"Skating & Gymnastics Spectacular",91098@0218.13:00,120,T] mask=TV host=Foo-Media encodedBy=Hauppauge WinTV-7164 Analog Capture #2 K21JCD format=MPEG2-PS 0:00:00 0 kbps [] \\Foo-Media\Recordings\Disk 3\SageDrive3\SkatingGymnasticsSpectacular-15351192-0.mpg, Seg0[Sat 2/18 14:22:42.997-Wed 12/31 17:00:00.000]] ifn=null]
Sat 2/18 14:34:38.196 [VideoFrame-001d6a4c00d2@bbac5f] VF processing job VFJob[LoadMF r=0.0 t=0 file=MediaFile[id=15408810 A[15351192,15350610,"Skating & Gymnastics Spectacular",91098@0218.13:00,120,T] mask=TV host=Foo-Media encodedBy=Hauppauge WinTV-7164 Analog Capture #2 K21JCD format=MPEG2-PS 0:00:00 0 kbps [] \\Foo-Media\Recordings\Disk 3\SageDrive3\SkatingGymnasticsSpectacular-15351192-0.mpg, Seg0[Sat 2/18 14:22:42.997-Wed 12/31 17:00:00.000]] ifn=null] nPlayin=false
Sat 2/18 14:34:38.203 [EventRouter-001d6a4c00d2@1108e5c] setUI(sage.PseudoMenu@192e31c[Detailed Info - Airing]) histIdx=9 uiHistory=[sage.PseudoMenu@e4be36[Setup Wizard - Source Details Page], sage.PseudoMenu@a23a1c[Setup Wizard - Summary Page], sage.PseudoMenu@2f3503[Main Menu], sage.PseudoMenu@a4ae96[LiveTVGuide w/ Optional Preview], sage.PseudoMenu@187363d[MediaPlayer OSD], sage.PseudoMenu@a4ae96[LiveTVGuide w/ Optional Preview], sage.PseudoMenu@187363d[MediaPlayer OSD], sage.PseudoMenu@a4ae96[LiveTVGuide w/ Optional Preview], sage.PseudoMenu@187363d[MediaPlayer OSD], sage.PseudoMenu@192e31c[Detailed Info - Airing]] redo=false performingActivation=false
Sat 2/18 14:34:38.210 [AsyncWatch@13a5720] setUI(sage.PseudoMenu@187363d[MediaPlayer OSD]) histIdx=8 uiHistory=[sage.PseudoMenu@e4be36[Setup Wizard - Source Details Page], sage.PseudoMenu@a23a1c[Setup Wizard - Summary Page], sage.PseudoMenu@2f3503[Main Menu], sage.PseudoMenu@a4ae96[LiveTVGuide w/ Optional Preview], sage.PseudoMenu@187363d[MediaPlayer OSD], sage.PseudoMenu@a4ae96[LiveTVGuide w/ Optional Preview], sage.PseudoMenu@187363d[MediaPlayer OSD], sage.PseudoMenu@a4ae96[LiveTVGuide w/ Optional Preview], sage.PseudoMenu@187363d[MediaPlayer OSD]] redo=false performingActivation=false
Sat 2/18 14:34:38.218 [VideoFrame-001d6a4c00d2@bbac5f] VF network encoder playback detected: false
Sat 2/18 14:34:38.225 [ConnRecvQueue@f07732] Increased Thread pool to size=26
Sat 2/18 14:34:38.233 [AsyncPropSaver@f24a87] Saving properties file to C:\Program Files\SageTV\SageTV\Sage.properties
Sat 2/18 14:34:38.266 [VideoFrame-001d6a4c00d2@bbac5f] VF waiting for data to appear in new file...liveWait=-715228
Sat 2/18 14:34:38.273 [ActiveRender-001d6a4c00d2@1a227f9] VideoFrame got registration of a subtitle UI component: sage.ZCCLabel[loc=java.awt.Point[x=39,y=79] size=java.awt.Dimension[width=183,height=21]]
Sat 2/18 14:34:38.280 [FinalRender-001d6a4c00d2@1dfb048] MiniClient did not succeed with menu hint change to:menuName:LiveTVGuide w/ Optional Preview, popupName:null, hasTextInput:false, errcode=1
Sat 2/18 14:34:38.288 [ActiveRender-001d6a4c00d2@1a227f9] VideoFrame got registration of a cc UI component: sage.ZCCLabel[loc=java.awt.Point[x=26,y=10] size=java.awt.Dimension[width=209,height=84]]
Sat 2/18 14:34:38.295 [VideoFrame-001d6a4c00d2@bbac5f] SIGNAL LOSS has been detected by the MediaPlayer
Sat 2/18 14:34:38.303 [EventRouter-001d6a4c00d2@1108e5c] VideoFrame got registration of a subtitle UI component: null
Sat 2/18 14:34:38.310 [VideoFrame-001d6a4c00d2@bbac5f] VF processing job VFJob[LoadMF r=0.0 t=0 file=MediaFile[id=15408810 A[15351192,15350610,"Skating & Gymnastics Spectacular",91098@0218.13:00,120,T] mask=TV host=Foo-Media encodedBy=Hauppauge WinTV-7164 Analog Capture #2 K21JCD format=MPEG2-PS 0:00:00 0 kbps [] \\Foo-Media\Recordings\Disk 3\SageDrive3\SkatingGymnasticsSpectacular-15351192-0.mpg, Seg0[Sat 2/18 14:22:42.997-Wed 12/31 17:00:00.000]] ifn=null] nPlayin=false
Sat 2/18 14:34:38.317 [EventRouter-001d6a4c00d2@1108e5c] VideoFrame got registration of a cc UI component: null
Sat 2/18 14:34:38.325 [VideoFrame-001d6a4c00d2@bbac5f] VF network encoder playback detected: false
Sat 2/18 14:34:38.332 [EventRouter-001d6a4c00d2@1108e5c] Count for type PosterWide = 0
Sat 2/18 14:34:38.340 [VideoFrame-001d6a4c00d2@bbac5f] VF waiting for data to appear in new file...liveWait=-715335
Sat 2/18 14:34:38.347 [EventRouter-001d6a4c00d2@1108e5c] Count for type PosterTall = 0
Sat 2/18 14:34:38.355 [VideoFrame-001d6a4c00d2@bbac5f] VF thread is now waiting for 0:00:00.200
Sat 2/18 14:34:38.363 [AsyncPropSaver@f24a87] Done writing out the data to the properties file
Sat 2/18 14:34:38.371 [EventRouter-001d6a4c00d2@1108e5c] Count for type PhotoWide = 0
Sat 2/18 14:34:38.379 [AsyncPropSaver@f24a87] Saving properties file to clients\001d6a4c00d2.properties
Sat 2/18 14:34:38.475 [FinalRender-001d6a4c00d2@1dfb048] MiniClient did not succeed with menu hint change to:menuName:MediaPlayer OSD, popupName:null, hasTextInput:false, errcode=1
Sat 2/18 14:34:38.564 [VideoFrame-001d6a4c00d2@bbac5f] VF processing job VFJob[LoadMF r=0.0 t=0 file=MediaFile[id=15408810 A[15351192,15350610,"Skating & Gymnastics Spectacular",91098@0218.13:00,120,T] mask=TV host=Foo-Media encodedBy=Hauppauge WinTV-7164 Analog Capture #2 K21JCD format=MPEG2-PS 0:00:00 0 kbps [] \\Foo-Media\Recordings\Disk 3\SageDrive3\SkatingGymnasticsSpectacular-15351192-0.mpg, Seg0[Sat 2/18 14:22:42.997-Wed 12/31 17:00:00.000]] ifn=null] nPlayin=false
Sat 2/18 14:34:38.573 [Thread-144@134e6d8] AVINF:(bytes:322) Hauppauge WinTV-7164 Analog Capture-1 AV-INF|f=MPEG2-PS;br=1961250;[bf=vid;f=MPEG2-Video;fps=59.940060;fpsn=60000;fpsd=1001;ar=1.777778;arn=16;ard=9;w=1280;h=720;lace=0;cs=yuv420p;main=yes;tag=e0;index=0;];[bf=aud;f=AC3;sr=48000;ch=6;br=384000;main=yes;lang=eng;tag=bd-80010000;index=1;];[bf=aud;f=AC3;sr=48000;ch=1;br=96000;lang=spa;tag=bd-81010000;index=2;];
Sat 2/18 14:34:38.573 [MsgManager@130772b] Setting media file format for MediaFile[id=15408810 A[15351192,15350610,"Skating & Gymnastics Spectacular",91098@0218.13:00,120,T] mask=TV host=Foo-Media encodedBy=Hauppauge WinTV-7164 Analog Capture #2 K21JCD format=MPEG2-PS 0:00:00 0 kbps [] \\Foo-Media\Recordings\Disk 3\SageDrive3\SkatingGymnasticsSpectacular-15351192-0.mpg, Seg0[Sat 2/18 14:22:42.997-Wed 12/31 17:00:00.000]] to be MPEG2-PS 0:00:00 1961 kbps [#0 Video[MPEG2-Video 59.94006 fps 1280x720 16:9 progressive id=e0]#1 Audio[AC3 48000 Hz 6 channels 384 kbps MAIN idx=1 id=bd-80010000 eng]#2 Audio[AC3 48000 Hz 1 channels 96 kbps idx=2 id=bd-81010000 spa]]
Sat 2/18 14:34:38.582 [MsgManager@130772b] MAJOR Change to file format detected...reload any active media players using: MediaFile[id=15408810 A[15351192,15350610,"Skating & Gymnastics Spectacular",91098@0218.13:00,120,T] mask=TV host=Foo-Media encodedBy=Hauppauge WinTV-7164 Analog Capture #2 K21JCD format=MPEG2-PS 0:00:00 1961 kbps [#0 Video[MPEG2-Video 59.94006 fps 1280x720 16:9 progressive id=e0]#1 Audio[AC3 48000 Hz 6 channels 384 kbps MAIN idx=1 id=bd-80010000 eng]#2 Audio[AC3 48000 Hz 1 channels 96 kbps idx=2 id=bd-81010000 spa]] \\Foo-Media\Recordings\Disk 3\SageDrive3\SkatingGymnasticsSpectacular-15351192-0.mpg, Seg0[Sat 2/18 14:22:42.997-Wed 12/31 17:00:00.000]]
Sat 2/18 14:34:38.590 [VideoFrame-001d6a4c00d2@bbac5f] VF network encoder playback detected: false
Sat 2/18 14:34:38.598 [VideoFrame-001d6a4c00d2@bbac5f] VF waiting for data to appear in new file...liveWait=-715600
Sat 2/18 14:34:38.605 [VideoFrame-001d6a4c00d2@bbac5f] VF processing job VFJob[LoadMF r=0.0 t=0 file=MediaFile[id=15408810 A[15351192,15350610,"Skating & Gymnastics Spectacular",91098@0218.13:00,120,T] mask=TV host=Foo-Media encodedBy=Hauppauge WinTV-7164 Analog Capture #2 K21JCD format=MPEG2-PS 0:00:00 1961 kbps [#0 Video[MPEG2-Video 59.94006 fps 1280x720 16:9 progressive id=e0]#1 Audio[AC3 48000 Hz 6 channels 384 kbps MAIN idx=1 id=bd-80010000 eng]#2 Audio[AC3 48000 Hz 1 channels 96 kbps idx=2 id=bd-81010000 spa]] \\Foo-Media\Recordings\Disk 3\SageDrive3\SkatingGymnasticsSpectacular-15351192-0.mpg, Seg0[Sat 2/18 14:22:42.997-Wed 12/31 17:00:00.000]] ifn=null] nPlayin=false
Sat 2/18 14:34:38.612 [VideoFrame-001d6a4c00d2@bbac5f] VF network encoder playback detected: false
Sat 2/18 14:34:38.620 [VideoFrame-001d6a4c00d2@bbac5f] VF waiting for data to appear in new file...liveWait=-715622
Sat 2/18 14:34:38.629 [VideoFrame-001d6a4c00d2@bbac5f] VF thread is now waiting for 0:00:00.200
Sat 2/18 14:34:38.728 [AWTThreadWatcher-001d6a4c00d2@16ffdcc] EventThread-001d6a4c00d2 Hang Detected - hang time = 634379 UILocker=null
Sat 2/18 14:34:38.736 [EventRouter-001d6a4c00d2@1108e5c] processUserEvent-UserEvent[select] evtTime=Sat 2/18 14:24:03.995
Sat 2/18 14:34:38.743 [ActiveRender-001d6a4c00d2@1a227f9] VideoFrame got registration of a subtitle UI component: sage.ZCCLabel[loc=java.awt.Point[x=145,y=405] size=java.awt.Dimension[width=681,height=106]]
Sat 2/18 14:34:38.750 [ActiveRender-001d6a4c00d2@1a227f9] VideoFrame got registration of a cc UI component: sage.ZCCLabel[loc=java.awt.Point[x=97,y=53] size=java.awt.Dimension[width=778,height=427]]
Sat 2/18 14:34:38.838 [VideoFrame-001d6a4c00d2@bbac5f] VF processing job VFJob[LoadMF r=0.0 t=0 file=MediaFile[id=15408810 A[15351192,15350610,"Skating & Gymnastics Spectacular",91098@0218.13:00,120,T] mask=TV host=Foo-Media encodedBy=Hauppauge WinTV-7164 Analog Capture #2 K21JCD format=MPEG2-PS 0:00:00 1961 kbps [#0 Video[MPEG2-Video 59.94006 fps 1280x720 16:9 progressive id=e0]#1 Audio[AC3 48000 Hz 6 channels 384 kbps MAIN idx=1 id=bd-80010000 eng]#2 Audio[AC3 48000 Hz 1 channels 96 kbps idx=2 id=bd-81010000 spa]] \\Foo-Media\Recordings\Disk 3\SageDrive3\SkatingGymnasticsSpectacular-15351192-0.mpg, Seg0[Sat 2/18 14:22:42.997-Wed 12/31 17:00:00.000]] ifn=null] nPlayin=false
Sat 2/18 14:34:38.845 [VideoFrame-001d6a4c00d2@bbac5f] VF network encoder playback detected: false
Sat 2/18 14:34:38.860 [VideoFrame-001d6a4c00d2@bbac5f] VF waiting for data to appear in new file...liveWait=-715855
Sat 2/18 14:34:38.867 [VideoFrame-001d6a4c00d2@bbac5f] VF thread is now waiting for 0:00:00.200
Sat 2/18 14:34:39.072 [VideoFrame-001d6a4c00d2@bbac5f] VF processing job VFJob[LoadMF r=0.0 t=0 file=MediaFile[id=15408810 A[15351192,15350610,"Skating & Gymnastics Spectacular",91098@0218.13:00,120,T] mask=TV host=Foo-Media encodedBy=Hauppauge WinTV-7164 Analog Capture #2 K21JCD format=MPEG2-PS 0:00:00 1961 kbps [#0 Video[MPEG2-Video 59.94006 fps 1280x720 16:9 progressive id=e0]#1 Audio[AC3 48000 Hz 6 channels 384 kbps MAIN idx=1 id=bd-80010000 eng]#2 Audio[AC3 48000 Hz 1 channels 96 kbps idx=2 id=bd-81010000 spa]] \\Foo-Media\Recordings\Disk 3\SageDrive3\SkatingGymnasticsSpectacular-15351192-0.mpg, Seg0[Sat 2/18 14:22:42.997-Wed 12/31 17:00:00.000]] ifn=null] nPlayin=false
Sat 2/18 14:34:39.079 [VideoFrame-001d6a4c00d2@bbac5f] VF network encoder playback detected: false
Sat 2/18 14:34:39.100 [VideoFrame-001d6a4c00d2@bbac5f] VF processing on UI Thread VFJob[LoadMF r=0.0 t=0 file=MediaFile[id=15408810 A[15351192,15350610,"Skating & Gymnastics Spectacular",91098@0218.13:00,120,T] mask=TV host=Foo-Media encodedBy=Hauppauge WinTV-7164 Analog Capture #2 K21JCD format=MPEG2-PS 0:00:00 1961 kbps [#0 Video[MPEG2-Video 59.94006 fps 1280x720 16:9 progressive id=e0]#1 Audio[AC3 48000 Hz 6 channels 384 kbps MAIN idx=1 id=bd-80010000 eng]#2 Audio[AC3 48000 Hz 1 channels 96 kbps idx=2 id=bd-81010000 spa]] \\Foo-Media\Recordings\Disk 3\SageDrive3\SkatingGymnasticsSpectacular-15351192-0.mpg, Seg0[Sat 2/18 14:22:42.997-Wed 12/31 17:00:00.000]] ifn=null]
Sat 2/18 14:34:39.121 [EventRouter-001d6a4c00d2@1108e5c] processUserEvent-UserEvent[options] evtTime=Sat 2/18 14:34:38.759

So... The resolution on my end seems to be to add in a tuner delay on the Hauppauge 2250's and all should be well based on some limited testing just done. But the concerning thing I noticed was how viewing a "live stream" that had no data effectively locked up the User Side of the Sage TV system for the clients for 634,379ms according to that log. As SageTV was nearly unusable on my Stand Alone Client during that time.

Other oddities include the specific live recording involved didn't start recording until about that time (14:34:38) but SageTV wanted to claim the recording started back when it was initiated around 14:22. The file was encoded properly from that point, even if SageTV didn't handle the rest of it correctly.

Probably a set of issues here to be added into GitHub. I doubt the 2250's are the only things that could produce this outcome.

Edit: Tuning delay of 1000 is not sufficient to resolve the issue, even though setting a manual record first, then tuning into the in progress recording is enough to avoid the problem entirely. Really weird. Will have to chase it more after I get some sleep.

Edit: Tuning delay of 5000 seems to have mostly resolved it, it still gets a little weird on starting initial playback, but it recovers from there. So it's usable on live TV once more. Still think the preferred option would be SageTV to kick back out rather then locking things up for 12-ish minutes trying to make it work.