SageTV 9.1.1.651 broke HVR-1600

[graywolf]

Upgraded SageTV from 9.0.13.536_R1.011 to 9.1.1.651 and now when I go to Guide, choose a channel, 1 of 2 things happen. (using HD200)
Either it shows the channel briefly then kicks me back to the Guide or it stays there with black screen. Switching TV Source to check the signal from the DirecTV box, it does change the channel

Sagetv log files attached

If I uninstall 9.1.1.651 (via the SageTVSetup_9.1.1.651.exe file), then run SageTVSetup_9.0.13.536_R1.011.exe to install it then it is working again as normal.

Had problems when migrating to Schedules Direct for EPG and was suggested I upgrade.

[EnterNoEscape]

You're not the first person to report this issue, but I'm struggling to see a connection between the most recent changes and this new problem. Is this happening only in the full clients?

[graywolf]

I reverted so will have to try next weekend.

Only checked using HD200 box

[EnterNoEscape]

Sorry, I somehow missed that detail in your post. The other user had problems whether they used a network encoder or the built in support for the HDHomeRun. The issue appears to be format detection never happens. In their case 9.14.0 worked fine, just not 9.1.1. I've been running 9.1.1 myself and use the same network encoder for many tuners and do not have any of the described issues.

My mind is drifting towards some specific configuration that causes this or we would all see this fairly consistently. One thing that's consistent is that the people that have this issue always have it. It doesn't work all of the time; not just sometimes.

So far I've mostly been try to see if this issue somehow has anything to do with a lack of EPG data, but I can't find any problems there on my test setups. It's important to note that Carny has nothing to do with your ability to tune into a live channel. That's all done within Seeker (it effectively bypasses Scheduler).

[graywolf]

Not using network encoder. Using 1 hvr-1600 s-video on the PC with Sage installed. As you recall from other thread, I tried latest build because had issue with Scedules Direct switchover.
Probably won't have time during week to mess with it but will see about trying again during weekend.
Anything I can do to help collect more data/info to troubleshoot?
Any Windows version between 9.0.13 and current that might not have the tuner issue but works for SD?

Btw. Existing recordings did play. Only happened when going live tv from guide

[EnterNoEscape]

9.14.0 was reported to be ok. I'll try to get you a jar file with more logging where I think the problem is happening sometime this week. It's just so strange because where I'm going to insert logging was not actually changed, in any meaningful way (a comment was added), but it almost has to be where things are breaking down because the issue so far has been common to 3 different capture device interfaces that are all very different in how they communicate. My only thoughts on how this is possible is maybe the new Carny might have removed/moved synchronization that was allowing something to work that actually shouldn't have worked (happens-before relationship) and might be the source of something that was more sporadic before.

I looked at your logs from 9.1.1 again today and I couldn't find any lines that actually showed a tuning attempt had been made. That kind of data is what I need most in tracking this down.

[graywolf]

Ok. So I would upgrade to 651. Stop sage. Copy jar file from you. Start sage. Try live tv and wait 10+ secs before hitting stop. Then post sagetv_0 log file.

[EnterNoEscape]

Correct.

[Narflex]

This looks like an issue with the changes to Carny. I'm fairly sure Carny is not setting 'prepped' to be true, which then causes the Scheduler to never be true for isPrepped() which means Seeker never sets canRecord to true...so it thinks it can't record anything. LiveTV subverts this by running in it's own thread and executing Seeker logic for grabbing a tuner...but then the Scheduler gets kicked, Seeker gets kicked and Seeker ends all encoding because it's not supposed to be recording yet.

If you look at the Carny output in the first log file he posted you can see it's not logging things you'd expect Carny to be logging.

[EnterNoEscape]

I can see where it is likely that is happening (no agents returns without setting this value), but what I don't understand is that I tested what happens when wiz.bin is completely empty with no agents and it didn't have this result. I was still able to tune in a channel. Maybe it also has some to do with the speed of the computer?

Edit: Actually, no I can't see where this is happening because when stdProcessing() returns, it always sets doneInit true. The only other possibility I can think of is that it's throwing an exception that nothing is catching.

[EnterNoEscape]

Here are my thoughts:

I see:

Mon 5/29 15:19:43.669 [SageTV@a08072] Splash: Profiler is initializing... 0% done
Mon 5/29 15:19:43.724 [SageTV@a08072] CARNY building airing maps...
Mon 5/29 15:19:43.911 [SageTV@a08072] CARNY Processing 1000 Agents & 57908 Airs
Mon 5/29 15:19:43.958 [SageTV@a08072] Splash: Waiting for SageTV to finish initialization...

The last line there shows that it didn't throw an exception and we wouldn't have a Seeker thread if it had. The 1000 agents could be cleaned up a little since it's actually showing the current table size and not how many of those elements actually refer to an object (which in this case must be 0 since we never actually process any data.).

Then the EPG thread kicks Carny again:

Mon 5/29 15:19:43.960 [Carny@125df72] CARNY building airing maps...
Mon 5/29 15:19:44.084 [Carny@125df72] CARNY Processing 1000 Agents & 57908 Airs
Mon 5/29 15:19:44.085 [Carny@125df72] Carny waiting for awhile...

We still don't actually have any agents, so the Carny thread stops processing after it see that the elements in the table are still empty.

Other than we could maybe use a little better logging to clear up what is happening, I don't actually see any serious issues here.

[EnterNoEscape]

I was finally able to re-produce the issue. I'll have a fix submitted today. (It's more subtle than just doneInit being set to true.)

Edit: It's basically what Narflex suggested. Because it returns immediately when there are no agents, prepped doesn't get set true and that causes this cascade of issues that generally only effects new installs.

Edit 2: As a fun fact, just setting a show to watched or creating a favorite would actually "fix" this too.

[graywolf]

Thanks for finding this so quickly.

Edit 2: As a fun fact, just setting a show to watched or creating a favorite would actually "fix" this too.

Is that a 1 and done or would need to be done upon each SageTV recycle or PC reboot?

[EnterNoEscape]

Originally Posted by graywolf

Thanks for finding this so quickly.

I put in the fix, but Narflex found the real cause. I was way off base in what I was thinking might be happening.

Originally Posted by graywolf

Is that a 1 and done or would need to be done upon each SageTV recycle or PC reboot?

That's a one and done. You can still wait of course for the next release. The reason this works is because it generally creates at least one new agent for intelligent recordings.

[VCRUser]

I have a 1600 and am planning to update to Sage9 today or tomorrow. Is the fixed version available for download, and if so, could a link be posted?

[Fuzzy]

No, I don't believe the fix is compiled/distributed yet. The workaround EnE is discussing should work fine though.. essentially, once you get sage up and running, and get the EPG downloaded, simply go to the guide, and either mark a recording as watched, or create your first favorite. Once that is done, this bug will be avoided. That, or download the last version before this one, and get up and going on that, and then update when the new build is out in the wild.

[jusjoken]

Originally Posted by Fuzzy

No, I don't believe the fix is compiled/distributed yet. The workaround EnE is discussing should work fine though.. essentially, once you get sage up and running, and get the EPG downloaded, simply go to the guide, and either mark a recording as watched, or create your first favorite. Once that is done, this bug will be avoided. That, or download the last version before this one, and get up and going on that, and then update when the new build is out in the wild.

Its building and uploading as we speak

Should be there in a few hours or at least by morning

k

[VCRUser]

So, to make sure I understand, setting any old show to watched or setting up any show as a favorite, whether or not it would use the affected tuner, wouldfix the problem for good? Can I then un-set the favorite or watched status or do they have to stay set? May be worth waiting til tomorrow to do the update.

[EnterNoEscape]

The server executable installer is available right now. If you need anything else, I would just wait until tomorrow unless you're just dying to try it out tonight.

I believe that unwatching the show could end up removing the agent(s) because it will then be seen as a "traitor," so if you marked it watched, then unwatch it, you might have the same problem again if you restart SageTV. The best way to approach this if you cannot live with a recording marked watched that you didn't actually watch , would be to create a favorite that you want.

[VCRUser]

That's all I need at the moment, since I understand PlaceShifter and extenders don't need to match versions. I saw the server & client files 9.1.2.662, which I just downloaded. If those are the right ones, I may yet do the update tonight, since I have only one more day off this week, and I want to get at least the open source installed this week, and maybe the SD EPG the upcoming weekend.