SageTV and DVD Playback via MVP - System Timeout

[TBoneJones]

Wasn't sure to place this in the MVP section or this, decided here...

I've got 6.0.19 running as a server in the basement. Atholon XP 2200+, 512MB ram, PVR150 with cable (no STB). Upstairs I've got 2 MVP clients. I've got several DVDs ripped to the server and the play just fine. If we leave the DVD running until it reaches the end we typically get a case where we "hang" the server (high CPU usage). I enabled logging and captured a bit of the following:

In sagetvclient I get messages typical of the following:
Tue 1/30 19:10:06.582 VF thread is now waiting for 0:00:00.000
Tue 1/30 19:15:06.625 VF processing job null nPlayin=false
Tue 1/30 19:15:06.625 VF thread is now waiting for 0:00:00.000
Tue 1/30 19:18:35.983 Saving properties file to C:\Program Files\SageTV\SageTV\SageClient.properties
Tue 1/30 19:19:08.872 AWTThread Hang Detected - hang time = 750
Tue 1/30 19:19:09.622 AWTThread Hang Detected - hang time = 1500

The sagetv log file is something completely different. I had 4 files each exceeding 9800KB with the following repeating error

Tue 1/30 19:53:53.630 Using link (9216) type 36 with 0 0 0

The errors were logged in every 100-200msec

We've had some lock up events prior to this but this is the first time I've had logging enabled. From what I can recall, we typically only saw it if we left a DVD playing thru it's entirety (thru credits).

-Keith

[splicer]

If I go to sleep with a ripped DVD playing on my extender when I wake up in the morning the server is all locked up CPU usage 99-100%. I have to restart sage in order to get it all working again.

[TBoneJones]

I had a thought, though haven't had time to try it out yet...

I've been using DVDShrink to remove menus, extras, and unused audio tracks. I'm wondering if the end of the movie is coded to go back to the menu. Since it isn't there, it is looking for a part of the file that doesn't exist. Are you playing "complete" movies or are they reduced to remove unnecessary content?

[splicer]

I'm useing shrink like you, maybe thats it. I don't think it crashes if I watch movies on the TV hooked directley to the server. It would sure be nice if someone knew why this happens and there was some sort of fix.

[vinny]

I also get the same problem with the CPU usage pegged when a movie ends. I also use DVDShrink and remove menus. Anyone figure out a solution yet?

[splicer]

Has anybody had a chance to figure this out. I have been very busy and have been out of town some so I have not had a chance.

[spacecadet]

I get the same behavior. Never associated it with watching a DVD movie on the MVP, but now that I am thinking about it in context, it seems to fit. Wife goes to bed watching a DVD and we wake up to a hung server.

I also watch DVDs with the main menus removed via Shrink, so that seems to be a common thread.

Like splicer, I also wake up to several large log files containing only the line "Using link (9216) type 36 with 0 0 0", so I lose the logging context from the point at which the hang occurred.

I will try and research this more this week (and produce a log file that shows the point-in-time at which the hang occurs - so I can log a bug with Sage).

Has anyone else logged this with Sage yet?

[TBoneJones]

Is anyone out there good at understanding the ifo file? I downloaed ifoedit to look at the files created by shrink to see if I could find where it may/may not point back to the menu at the end of the file.

[splicer]

Today I had some time so I tried the following:

I did a full disk back up, to a hard drive, of a DVD using Shrink then fast forward on the MVP (in the bedroom) until the last chapter was playing. I went into the living room and watched TV on my server and monitored the CPU usage. After the movie ended and all the credits ran and there was no picture left on the screen in the bedroom CPU usage dropped of about 10% and did not hang the server up. I left it like this for a couple of hours and ran some errands when I returned everything was just as I left it, TV running with the Windows Task Manager running.

So I tried the same thing with another movie, that had everything but the main movie removed with shrink, with the same results no server hang. I tend to think that it has nothing to do with Shrink removing any files from the original movie.

Now I am thinking it must have to do with the fact that when my hang up occurs it is after I have shut off the TV in the living room and put SAGE to sleep in the system tray, gone to bed watched a movie gone to sleep and left the movie running.

This time I shut SAGE down into the system tray and as I fast forwarded another movie to the end the movie locked up and when I went to the living room and looked at the Task Manager CPU usage had shot up to 100%.

I really think this has to do with SAGE being asleep when the movie ends. So it seems until someone who knows more about SAGE than I do can tell us what causes this I guess all we can do is not put SAGE to sleep when shutting down the main TV and going to bed.

[MeInMaui]

splicer,

Are you running sage in service mode on your server. I think that should separate the MVP server from anything you do with the UI. You should be able to exit the UI completely and have no effect. I run my server with no UI at all.

Aloha,
Mike

[splicer]

MeInMaui,

I'm not running in service mode. I have the server function turned on in the SAGE set up and am able to watch TV on the MVP in my bedroom, with SAGE sleeping in the system tray, however this situation with DVD content causing CPU usage to go to 100% when movies end is causing me some grief.

I posted in the thread above that I thought it had to do SAGEs state but I just tried another movie and it hung my server even as I watched live TV so back to square one.

Thanks for your interest!!!!

Splicer

[MeInMaui]

I bet if you try running sage in service mode that your problem will go away. If it doesn't work for you, just turn off the service and you will be back to your present configuration. Note that when you run in service mode that the UI on the server is started as a client. It will therefore use the sageclient.properties file instead of the sage.properties file. This may require you to go through initial setup the first time you try it. To avoid this, you can make a copy of sage.properties and rename it to sageclient.properties. This should give you the same configuration you are currently running. HTH

Aloha,
Mike

Edit: The nice thing about service mode is that your recordings won't be affected if your UI crashes or if you have to exit the UI for any reason.

[splicer]

MeInMaui,

Well it was worth a try, I enabled Service Mode went through the initial setup then tried to play a movie. After the movie ends on the MVP it still sends the CPU usage to 100% on the server.

Any other ideas, I usually can't spend time on this but today I have a little so I thought I would try and figure this out.

Thanks for the help!!!
Splicer

[MeInMaui]

Sorry, that's about all I can think of right now. Can you try your MVP test with no UI running of the server at all? What version of Java are you running? I'll let you know if I can think of anything else.

Aloha,
Mike

[splicer]

Java version 1.4.2_06

Thanks,
Splicer

[spacecadet]

Originally Posted by splicer

MeInMaui,

Well it was worth a try, I enabled Service Mode went through the initial setup then tried to play a movie. After the movie ends on the MVP it still sends the CPU usage to 100% on the server.

Any other ideas, I usually can't spend time on this but today I have a little so I thought I would try and figure this out.

Thanks for the help!!!
Splicer

Yes. I am in service mode and have the same issue.

Splicer, Have you captured a clean log file (one that shows the point in time where the problem occurs?). Have you logged a bug with Sage TV yet? This sounds like a bug (especially if it works from the Sage Server UI, but not on the MVP).

I am going to try and reproduce this weekend as well. If I can get a clean log file, I am going to open a bug.

[MeInMaui]

Originally Posted by splicer

Java version 1.4.2_06

Thanks,
Splicer

I don't know if it would help, but you could try upgrading java to v1.6. Many of us have been running this version for a while now with very good results. I have found it to be very stable. It also has the side benefit of making the MVP menus much more responsive. It's worth a shot and you can always uninstall it to revert back to your current version.

Aloha,
Mike

[splicer]

Originally Posted by spacecadet

Yes. I am in service mode and have the same issue.

Splicer, Have you captured a clean log file (one that shows the point in time where the problem occurs?). Have you logged a bug with Sage TV yet? This sounds like a bug (especially if it works from the Sage Server UI, but not on the MVP).

I am going to try and reproduce this weekend as well. If I can get a clean log file, I am going to open a bug.

spacecadet,

No I have not captured any logs, if you have any luck with this please post back and let us know what you find out.

Splicer

[Wakecrash]

Just adding a me too,,,
I have a sage server in service mode running Jave 1.6. When MVP hits the end of a show ripped with DVD Shrink the server goes to 100% CPU usage. When I go to restart the server I get a "windowsformsparking" window pops up and I have to end. Google search says that is due to a program trying to use the same memory space as the OS. Not 100% sure, but I don't believe it ever locked up on DVD saved with nero recode.

[spacecadet]

Originally Posted by splicer

spacecadet,

No I have not captured any logs, if you have any luck with this please post back and let us know what you find out.

Splicer

Did a test this morning and was able to capture a log at the point in time of the failure. You have to be fast to catch this as it looks like this problem generates about 10 MB of log every 5 seconds.

Overall, the log doesn't look like much to me, but I am going to submit a support request and see where it goes.

Sun 2/18 11:06:37.067 Trying to read nav block at 3322211
Sun 2/18 11:06:37.068 vobu sector 3322211 length 22 next at 22
Sun 2/18 11:06:37.070 NAV Packet at 2048
Sun 2/18 11:06:37.192 Trying to read nav block at 3322233
Sun 2/18 11:06:37.193 vobu sector 3322233 length 21 next at 21
Sun 2/18 11:06:37.196 NAV Packet at 12288
Sun 2/18 11:06:37.204 Trying to read nav block at 3322254
Sun 2/18 11:06:37.205 vobu sector 3322254 length 36 next at 1073741823
Sun 2/18 11:06:37.208 NAV Packet at 10240
Sun 2/18 11:06:37.233 End of cell detected
Sun 2/18 11:06:37.233 going to next cell

Sun 2/18 11:06:37.234 DVDVM: Doing cell 36 post
Sun 2/18 11:06:37.234 DVDVM: reached last cell of pgc
Sun 2/18 11:06:37.235 DVDVM: Doing PGC post commands
Sun 2/18 11:06:37.235 Executing cmd : 30 01 00 00 00 00 00 00  : Exit
Sun 2/18 11:06:37.236 Using link (9216) type 36 with 0 0 0
Sun 2/18 11:06:37.236 Using link (9216) type 36 with 0 0 0
Sun 2/18 11:06:37.236 Using link (9216) type 36 with 0 0 0
Sun 2/18 11:06:37.237 Using link (9216) type 36 with 0 0 0
Sun 2/18 11:06:37.237 Using link (9216) type 36 with 0 0 0
Sun 2/18 11:06:37.237 Using link (9216) type 36 with 0 0 0