Plugin: Sage Job Queue (SJQ)

[Skirge01]

Originally Posted by Slugger

It's not the 2009_08_xx.request.log file I need from Jetty, it's the 2009_08_xx.stderrout.log file that I need. This will be the file that logs the exceptions that are being thrown. If you are not seeing this file (it's in the same location as the 2009_08_xx.request.log file) then you must enable debug logging in Jetty - see JettyStarter.properties.

While you stop Sage to enable debug logging, also upgrade the SJQ server and task client to the latest versions. Server is snapshot 511 and task client is snapshot 504. Then when you start seeing the HTTP 500 errors again, get the stderrout log and send that to me, please.

Slugger, I went ahead and updated the server and client to the lastest builds. I'm still seeing lots of locking up of the comskip processes which I need to kill off. I'm also needing to restart SJQ via resaving the sjq.context.xml file you mentioned (thanks for that tip, btw), or else nothing else gets queued up. I checked with erik and the hangs are almost definitely caused by comskip, not SJQ. This may be the reason I'm not finding the stderrout files you're requesting.

At this point, I'm having to babysit both SJQ and comskip every time a comskip is due to finish (with 7 instances running in parallel, this is about every 30 minutes), so that I can update the sjq.context.xml file, restart the SJQC services on each client and kill all the hung comskip instances. Obviously, this means that while I'm at work, comskip very likely is not running for that 8-10 hours of the day or while I sleep and can't keep an eye on it. (Darn that whole work/sleep thing! )

Is there any way to get SJQ to know when a comskip instance is hung up, so that it knows to kill it, possibly requeue it, and start another comskip instance? In my, admittedly, extremely limited programming skills, I would think that a periodic check of the recording's log file timestamps would provide the necessary information to know whether it was hung.

EDIT: Through my constant monitoring of the 3 computers, I've found that, when a process is hung, if I stop the SJQC service, the hung process starts up. Then, if I start the service, I believe everything continues normally. I'm not certain of this last part, so I will check to ensure future shows are getting queued on those clients.

[Slugger]

Originally Posted by Skirge01

Is there any way to get SJQ to know when a comskip instance is hung up, so that it knows to kill it, possibly requeue it, and start another comskip instance? In my, admittedly, extremely limited programming skills, I would think that a periodic check of the recording's log file timestamps would provide the necessary information to know whether it was hung.

Check out the MAXRUNRATIO setting in the user guide. That should do exactly what you're looking for.

[Skirge01]

Thanks for that tip! That does seem to have resolved the issue of hung processes. They do appear to be ending at this point.

However, the clients seem to simply stop running anything and I need to "update" the sjq.context.xml file, followed by stopping and restarting the service on both the server (also a client) and a 2nd client PC, before any more comskip sessions will be started. (For unrelated reasons, I stopped using the 3rd computer for comskip at the moment.) To date, I still have yet to find one of those stderr log files you mentioned. I expected to find it on the server, but also checked the client log folder, just to be sure. Do I need to stop the Sage service in order for the true setting on the debug flag to take effect?

[Slugger]

Yes, Jetty would have to be restarted for the debug flag to take effect and to restart Jetty requires a stop/restart of Sage.

[Skirge01]

Thanks, Slugger. Sorry for these seemingly dumb questions. I don't know how you put up with us! But, we sure do appreciate that you do!!!

[Skirge01]

I did some more checking and here's what my jettystarter.properties file says (in part, obviously):

# jetty.logs only contains logs of requests to the Jetty server.
jetty.logs=$(jetty.home)/logs

# Uncomment to get more detailed logging from Jetty. Output is written to the standard
# output stream (by default, sagetv_0.txt).
DEBUG=true

I thought the second part was what would be giving me the stderr logs, but according to the comment, these debug logs will go to the default Sage log file. Is this what you're talking about or am I even more confused than I thought?

[Slugger]

Right above that section add the $(jetty.home)/etc/jetty-logging.xml file to jetty.configfiles

[Skirge01]

Based on that, I made the following change to jettystarter.properties:

###########################
### Configuration Files ###
###########################

# The set of files used to configure Jetty. If a file has spaces in its path,
# it must be enclosed in double quotes.
# - jetty.xml sets up a non-SSL server with hot-deployment of web applications
# - jetty-ssl.xml adds an SSL server
#jetty.configfiles="$(jetty.home)/etc/jetty.xml"
jetty.configfiles="$(jetty.home)/etc/jetty.xml" "$(jetty.home)/etc/jetty-ssl.xml"
jetty.configfiles="$(jetty.home)/etc/jetty-logging.xml"

That's all I need to do? I assume I also need to restart Sage, but I was talking about editing any other files.

[Slugger]

No, you need to append... here's what mine looks like:

jetty.configfiles="$(jetty.home)/etc/jetty.xml" "$(jetty.home)/etc/jetty-ssl.xml
" "$(jetty.home)/etc/jetty-logging.xml"

Remove the ssl one if you don't need/use the SSL port with Jetty.

[Skirge01]

Thanks. I think I got it now. Sad to say, it shouldn't be long before some errors pop up.

[jreichen]

Keep in mind that since SageTV's core and Jetty both log to Java's standard error (stderr) and standard output (stdout) streams - as opposed to using a logging framework - using jetty-logging.xml will redirect SageTV's logging as well. Plus some of the initial log messages will be written to sagetv_0.txt until Sage starts the Jetty plugin and activates that change in logging configuration.

It's not what I'd consider ideal - I don't know if they can be separated or not. Slugger if you have any suggestions on improving logging I'd be happy to hear them.

[Skirge01]

For a few hours there, I thought simply making that change for the logging had actually fixed the issue with comskip hanging and no new jobs getting queued up. Alas, it didn't last long. I'm attaching that elusive file you've been requesting. Let me know if there's any other information you need. Thanks!

[Slugger]

Do you have more than one client configured and might they both be running a comskip job simultaneously?

The SJQ database is constantly locked and throwing exceptions, that's the SJQ problem. All the exceptions are a result of trying to log task output back to the db. The first thing I'd try is to disable SJQ from logging task output.

Go to Tools > Edit Settings > SJQ should log task output to the server > No

Save the change. That should alleviate the db locking. The side effect is that command output will not be available on the server. Hopefully that fixes you up (I plan on moving logging out of the database down the road as SQLite just doesn't seem to be able to handle the concurrency all too well).

However, while scanning over the log files, I noticed a lot of NPEs being thrown by SageTV itself:

java.lang.NullPointerException
	at sage.d.e$66.try(Unknown Source)
	at sage.ax.a(Unknown Source)
	at sage.e.a(Unknown Source)
	at sage.w.e(Unknown Source)
	at sage.w.d(Unknown Source)
	at sage.w.access$100(Unknown Source)
	at sage.w$3.run(Unknown Source)
	at sage.cs$a.run(Unknown Source)
sage.a.e: Error in method reflection of IsFilePath of java.lang.NullPointerException
	at sage.ax.a(Unknown Source)
	at sage.e.a(Unknown Source)
	at sage.w.e(Unknown Source)
	at sage.w.d(Unknown Source)
	at sage.w.access$100(Unknown Source)
	at sage.w$3.run(Unknown Source)
	at sage.cs$a.run(Unknown Source)
Caused by: java.lang.NullPointerException
	at sage.d.e$66.try(Unknown Source)
	... 7 more

I can only speculate (b/c of the obfuscated stack traces), but it would seem Sage is having troubles accessing a path on your system. Now if that's the case then API calls might be taking an unusual amount of time (I don't know how long it is before Sage actually throws this NPE), and depending on exactly what's going on, say a file check in SJQ or the file cleaner in SJQ, etc. then this could be the reason the sjq db file is being locked for such a long period of time and then the reason why SJQ is failing. As I say, it's pure speculation only, but I've got a gut feeling these Sage exceptions are at least partly to blame for why SJQ is struggling. However, start with disabling sjq from logging task output and see what that gets you. Next step might be to contact Sage support about the NPEs Sage is throwing.

[Skirge01]

Thanks for the tips, Slugger. I have 2 clients (one on the server itself and a separate PC). I've disabled the logging piece you mentioned. Regarding the NPE's, I took a look at the sage log and noticed this line showing up for just about every NPE I could find:

Tue 9/15 17:10:24.951 [AWT-EventQueue-0@4f459c] EXCEPTION in getValueAsObject:sage.a.e: sage.a.e: Error in method reflection of IsFilePath of java.lang.NullPointerException for:IsFilePath(phoenix_api_GetFanartBackground(Airing))

I'm wondering if upgrading BMT would alleviate this particular issue. I'm still running a very old version (pre-webGUI version). Phoenix is version 1.36, so maybe that's an old version, too. I'll take a look around and see what else I may need to update.

[moothekow]

Ok - I apologized if this has been asked/answered, but I've spent hours searching through the forums and am not sure how to accomplish (or if I can accomplish) what I'm trying to do. Not sure of the things i've read what is old and doesn't apply, etc etc.

What I want to do is fairly simple/straight forward. After a record is finished - I want to move the file into another directory. So - lets say my tv shows record to a directory: 'd:\RecordedTV'. After the recording is finished I want to sort the episode by show/season/episode-name.mpg. So - example:

Go from:
d:\RecordedTV\FilenameSageTVGivesRecording.mpg

To:
d:\SortedTV\TVshowName\Season XX\SXXEXX - EpisodeName.mpg

is this possible? In a perfect world I'd like to still consider it a recorded tv show and all that fun jazz... but if it meant I could only get to it via the 'media center' videos area I could probably live with that.

Thanks.

[Slugger]

Originally Posted by moothekow

Ok - I apologized if this has been asked/answered, but I've spent hours searching through the forums and am not sure how to accomplish (or if I can accomplish) what I'm trying to do. Not sure of the things i've read what is old and doesn't apply, etc etc.

What I want to do is fairly simple/straight forward. After a record is finished - I want to move the file into another directory. So - lets say my tv shows record to a directory: 'd:\RecordedTV'. After the recording is finished I want to sort the episode by show/season/episode-name.mpg. So - example:

Go from:
d:\RecordedTV\FilenameSageTVGivesRecording.mpg

To:
d:\SortedTV\TVshowName\Season XX\SXXEXX - EpisodeName.mpg

is this possible? In a perfect world I'd like to still consider it a recorded tv show and all that fun jazz... but if it meant I could only get to it via the 'media center' videos area I could probably live with that.

Thanks.

Others are doing this and the details should be further up this thread - you'll need to go searching. My only warning is that moving recording files while SageTV is running (and it must be in order for SJQ to do the moving) is not a recommended practice, though the issues that arise from doing it might have been solved by the others who are doing similar things. Again, you'll have to search back up this thread for details.

[moothekow]

Originally Posted by Slugger

Others are doing this and the details should be further up this thread - you'll need to go searching. My only warning is that moving recording files while SageTV is running (and it must be in order for SJQ to do the moving) is not a recommended practice, though the issues that arise from doing it might have been solved by the others who are doing similar things. Again, you'll have to search back up this thread for details.

Ok - so I figured out it looks like I'll need to run a batch file ... but I'm not sure where to go from here...

I figure I need a custom ruleset like this:

if [IsTV == true && IsActivelyRecording == false && IsScheduledRecording == true] {
SORTRECORDING
}

Contents of the client job (i think that's what is is called?): ... not entirely sure what to use in here for my arguments to get what I need to my batch file...
SORTRECORDING {
:CPU low
:MAX 1
"C:\RenameEpisode.bat" "%c%" ..... what else can I use here?
}

Also not sure what else I need to do in my custom ruleset to make it mark the file post-move. Do I need to somehow do something with the '_MANUALREC' internal task? I've been digging through these forums a long time now and am having trouble working out the exact details of what I need to do.

Contents of the batch file I've come up with:

SET _inputFile=%1
SET _showName=%~n2
SET _season=%~n3
SET _episodeNumber=%~n4
SET _episodeName=%~n5

SET _baseFolder=c:\TVShows\
SET _showFolder=%_baseFolder%%_showName%\
SET _seasonFolder=%_showFolder%Season %_season%\
SET _newFileName=%_seasonFolder%S%_season%E%_episodeNumber% - %_episodeName%.mpg

if not exist "%_showFolder%" (
md "%_showFolder%"
)

if not exist "%_seasonFolder%\" (
md "%_seasonFolder%"
)

copy "%_inputFile%" "%_newFileName%"

[Slugger]

Originally Posted by moothekow

Contents of the client job (i think that's what is is called?): ... not entirely sure what to use in here for my arguments to get what I need to my batch file...
SORTRECORDING {
:CPU low
:MAX 1
"C:\RenameEpisode.bat" "%c%" ..... what else can I use here?
}

I'll answer what I can; the others who are doing similar things will have to chime in with the rest.

The available media variables available for command lines are documented here.

[Slugger]

Snapshot 542 is now available on Google Code. I am looking for as many people as possible to test this build and report any problems. The build contains just one change:

* Support short circuiting of test evaluations

Basically, prior to 542 if your test block looked like this:

if [IsTV == true && Title == "Family Guy" && IsActivelyRecording == false ] {

}

And the QueueLoader was processing a recording of "The Simpsons" then even after the second test failed (meaning the entire block is destined to fail), SJQ would still run the IsActivelyRecording test before rendering a verdict of false for the media object. Now with 542, SJQ recognizes that IsActivelyRecording doesn't need to be ran and that calculation can be skipped. I did account for this kind of test block:

if [IsTV == true && Title == "Family Guy" && IsActivelyRecording == false || DayOfWeek == 7 ] {

}

Is this case (again, assuming we're processing "The Simpsons"), SJQ will still skip the IsActivelyRecording test and then go on to test the DayOfWeek.

It is worth mentioning, formally, that SJQ's operators have the following precedence:

1. parenthesis have precedence
2. The || and && operators have equal precedence and are always evaluated in order from left to right

So consider the following statement:

A || B && C

In C/C++ that statement implies this order of evaluation:

A || (B && C)

But in SJQ, it is evaluated as such:

(A || B) && C

This has always been the case and does not change with this snapshot, but it is worth mentioning explicitly (you'll learn why later this winter ). I'll add this to the user guide shortly.

The obvious gain with this change is a performance boost when the QueueLoader is scanning media - many test evaluations will now be skipped, but that isn't the reason I am making this change today. This ability to short circuit out of a test block is the basis for SJQ v3. The ability to prevent tests from running is the key feature needed to allow the processing of other types of objects (say SageTV system message objects or event objects) with the least amount of code change. That's all I'll say for now, but I really do need as many people to test this build as possible to ensure I haven't broken the rules parser component.

[moothekow]

Slugger - is it at all possible to expose more media variables than are currently in the file? (Such as the episode title, episode number, season number, etc?). Looking at what you have so far - great works... Being a programmer myself I know how many hours you must have put into this thing... thanks.