Plugin: Sage Job Queue (SJQ) v3

[lanmat]

I really do apologize if this answer is elsewhere already. I'm just not finding applicable solutions I haven't already tried in an hour of thread searching and 25 pages is a bit much to go through. I have SJQ installed and working and a ruleset creating jobs, but they don't start. I have a client installed as a "NT service" (at least it appears in the 'client list') and a ruleset defined :

TRANSCODE_NORMAL {
:RESOURCES 80
:CPU "LOW"
"C:\\Program Files\\SageTV\\SageTV\\PostProcessing.bat \"%c%\""
}

No other anomalies in the Server Logs except this line:
2010-03-03 00:02:12,199 WARN [DataStore]: DataStore pool timeout expired! '23045907@qtp-26810747-5' did not return connection within 30 seconds! Adding a replacement connection to the pool.

The client log is blank as well. Is this a normal problem in SJQ setup and am I missing something obvious?

[Slugger]

In the client install dir, under logs there should be a file called wrapper.log. Check that file for any exceptions. If you find any, paste them in here.

[lanmat]

I had to restart the machine to update the file, but here's what it says. I'm guessing the 'connection refused' might be the culprit?

wrapper.log:
STATUS | wrapper | 2010/03/03 21:08:18 | --> Wrapper Started as Service
STATUS | wrapper | 2010/03/03 21:08:18 | Java Service Wrapper Community Edition 3.3.1
STATUS | wrapper | 2010/03/03 21:08:18 | Copyright (C) 1999-2008 Tanuki Software, Inc. All Rights Reserved.
STATUS | wrapper | 2010/03/03 21:08:18 | http://wrapper.tanukisoftware.org
STATUS | wrapper | 2010/03/03 21:08:18 |
STATUS | wrapper | 2010/03/03 21:08:19 | Launching a JVM...
INFO | jvm 1 | 2010/03/03 21:08:24 | WrapperManager: Initializing...
INFO | jvm 1 | 2010/03/03 21:08:27 | SJQ Task Client v3.0.1.705
INFO | jvm 1 | 2010/03/03 21:08:27 | Using 'C:/sjqc' as location for configuration file...
INFO | jvm 1 | 2010/03/03 21:08:31 | Connection refused: connect

[Slugger]

Is the client on the same machine as the server? If not, then that error is the problem (check firewall settings on server to ensure that it's allowing incoming connections). If they're on the same machine then that error probably just means the client started before the server. In this case, check the log again after a few mins for other errors.

[lanmat]

Client/Server are same machine. And I don't see anything else in that log after leaving it overnight. All jobs still just say 'waiting'.

update:
Ok. For some reason it did not update overnight, but now as I get ready to leave I see the file is larger and contains the following which I think is related to the fact that right now the SJQ page is telling me I have an invalid password:


INFO | jvm 1 | 2010/03/04 06:13:50 | WrapperSimpleApp:
INFO | jvm 1 | 2010/03/04 06:13:50 | WrapperSimpleApp: Encountered an error running main:
INFO | jvm 1 | 2010/03/04 06:13:50 | WrapperSimpleApp: java.lang.RuntimeException: java.io.IOException: Server returned HTTP response code: 500 for URL: http://localhost:8500/sjq/SJQ?proto=4&cmd=writeLog
INFO | jvm 1 | 2010/03/04 06:13:50 | WrapperSimpleApp: at com.google.code.sagetvaddons.sjqc.TaskClient.log(Unknown Source)
INFO | jvm 1 | 2010/03/04 06:13:50 | WrapperSimpleApp: at com.google.code.sagetvaddons.sjqc.TaskClient.log(Unknown Source)
INFO | jvm 1 | 2010/03/04 06:13:50 | WrapperSimpleApp: at com.google.code.sagetvaddons.sjqc.TaskClient.pop(Unknown Source)
INFO | jvm 1 | 2010/03/04 06:13:50 | WrapperSimpleApp: at com.google.code.sagetvaddons.sjqc.TaskClient.run(Unknown Source)
INFO | jvm 1 | 2010/03/04 06:13:50 | WrapperSimpleApp: at com.google.code.sagetvaddons.sjqc.TaskClient.main(Unknown Source)
INFO | jvm 1 | 2010/03/04 06:13:50 | WrapperSimpleApp: at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
INFO | jvm 1 | 2010/03/04 06:13:50 | WrapperSimpleApp: at sun.reflect.NativeMethodAccessorImpl.invoke(Unknown Source)
INFO | jvm 1 | 2010/03/04 06:13:50 | WrapperSimpleApp: at sun.reflect.DelegatingMethodAccessorImpl.invoke(Unknown Source)
INFO | jvm 1 | 2010/03/04 06:13:50 | WrapperSimpleApp: at java.lang.reflect.Method.invoke(Unknown Source)
INFO | jvm 1 | 2010/03/04 06:13:50 | WrapperSimpleApp: at org.tanukisoftware.wrapper.WrapperSimpleApp.run(WrapperSimpleApp.java:236)
INFO | jvm 1 | 2010/03/04 06:13:50 | WrapperSimpleApp: at java.lang.Thread.run(Unknown Source)
INFO | jvm 1 | 2010/03/04 06:13:50 | WrapperSimpleApp: Caused by: java.io.IOException: Server returned HTTP response code: 500 for URL: http://localhost:8500/sjq/SJQ?proto=4&cmd=writeLog
INFO | jvm 1 | 2010/03/04 06:13:50 | WrapperSimpleApp: at sun.net.http://www.protocol.http.HttpURLConn...Stream(Unknown Source)
INFO | jvm 1 | 2010/03/04 06:13:50 | WrapperSimpleApp: ... 11 more
STATUS | wrapper | 2010/03/04 06:13:52 | <-- Wrapper Stopped



...stopping and restarting the SageTV service fixed the login problem.

[Slugger]

Stop the task client, open the sjqc.properties file and reduce the buffer to 65000 (it should be at 199000 currently). Restart task client. All should be good.

[lanmat]

-Changed the buffer size, rebooted (had other updates to another program that required it).
-Logged back into SJQ and saw no clients in the list.
-Did net start SJQTaskClient, but it was already started (as it should have).
-Stopped then restarted the SageTV Service, then relogged in to SJQ and the local client popped up. Jobs still at 'waiting'.

Here's the wrapper.log since the reboot. There's still that 'connection refused: connect' line at the bottom.

STATUS | wrapper | 2010/03/05 06:09:26 | Machine is shutting down.
STATUS | wrapper | 2010/03/05 06:09:28 | <-- Wrapper Stopped
STATUS | wrapper | 2010/03/05 06:12:00 | --> Wrapper Started as Service
STATUS | wrapper | 2010/03/05 06:12:00 | Java Service Wrapper Community Edition 3.3.1
STATUS | wrapper | 2010/03/05 06:12:00 | Copyright (C) 1999-2008 Tanuki Software, Inc. All Rights Reserved.
STATUS | wrapper | 2010/03/05 06:12:00 | http://wrapper.tanukisoftware.org
STATUS | wrapper | 2010/03/05 06:12:00 |
STATUS | wrapper | 2010/03/05 06:12:00 | Launching a JVM...
INFO | jvm 1 | 2010/03/05 06:12:09 | WrapperManager: Initializing...
INFO | jvm 1 | 2010/03/05 06:12:14 | SJQ Task Client v3.0.1.705
INFO | jvm 1 | 2010/03/05 06:12:14 | Using 'C:/sjqc' as location for configuration file...
INFO | jvm 1 | 2010/03/05 06:12:21 | Connection refused: connect

[Slugger]

That connection refused error is normal, it just means the task client started before the server. The task client recovers on its next check.

Go to sagetv dir, edit sjq.log4j.properties and on the first line change INFO to DEBUG (to increase logging level). Restart SJQ. In the sjq.log, I need to see your client connection output. It will look something like this:

2010-03-05 09:43:17,878 DEBUG [ClientParser]: === GLOBAL OPTIONS ===
=== GLOBAL OPTIONS ===
This client has 4 ClientTask object(s) attached to it.=== ClientTask 'TVMETADATA
' ===
MAX => -1
RETURNCODE => 0.0
NORECORDING =>
MAXRUNRATIO => false
MAXRUN => -1.0
RESOURCES => 5
NOCLIENT =>
CPU => NORMAL
OFFDAY =>
OFFHOUR =>
Run: "C:/Program Files/SageTV/SageTV/bmt.bat" "%c%"
=== ClientTask 'TVMETADATA' ===
=== ClientTask 'MOVMETADATA' ===
MAX => -1
RETURNCODE => 0.0
NORECORDING =>
MAXRUNRATIO => false
MAXRUN => -1.0
RESOURCES => 5
NOCLIENT =>
CPU => NORMAL
OFFDAY =>
OFFHOUR =>
Run: "C:/Program Files/SageTV/SageTV/bmt.bat" "%c%"
=== ClientTask 'MOVMETADATA' ===
=== ClientTask 'SDCOMSKIP' ===
MAX => -1
RETURNCODE => 0.0
NORECORDING =>
MAXRUNRATIO => true
MAXRUN => 0.2
RESOURCES => 15
NOCLIENT =>
CPU => NORMAL
OFFDAY =>
OFFHOUR =>
Run: "C:\Program Files\Dragon Global\ShowAnalyzerSuite\ShowAnalyzerEngine.exe" "
%c%"
=== ClientTask 'SDCOMSKIP' ===
=== ClientTask 'HDCOMSKIP' ===
MAX => -1
RETURNCODE => 0.0
NORECORDING =>
MAXRUNRATIO => true
MAXRUN => 0.75
RESOURCES => 75
NOCLIENT =>
CPU => NORMAL
OFFDAY =>
OFFHOUR =>
Run: "C:\Program Files\Dragon Global\ShowAnalyzerSuite\ShowAnalyzerEngine.exe" "
%c%"
Run: java -cp "C:/Program Files/SageTV/tools/edl_editor.jar" com.google.code.sag
etvaddons.utils.EdlEditor +1.5 "%d%/%p%.edl"
=== ClientTask 'HDCOMSKIP' ===
2010-03-05 09:43:17,878 INFO  [SJQServlet]: Checking client '127.0.0.1': 100 resources free.

I need that output from you, plus please paste in your server ruleset. After you get all that output, you will want to change the log level back to INFO and restart SJQ. (Remember, to restart SJQ, simply go to sagetv/jetty/contexts and open/resave the sjq.context.xml file; there is no need to completely restart SageTV to do this; though no harm in doing it that way).

[banshee]

Is there any way to automatically delete completed tasks? I am trying to use SJQ to periodically stop and re-start a process (because it crashes like clockwork every few days).

It is working...but after the first time, the process won't run again because it is completed; then I have to clear it from completed tasks to make it run again...which rather defeats the purpose.

Suggestions?

[Slugger]

With the current version, your best bet is to have the task return an error code such that SJQ believes that the task failed. Then in the SJQ settings tell it to ignore failed tasks, which will allow the task to be automatically re-queued. Doing this has other ramifications such as all failed tasks being automatically re-queued.

Alternatively, go and star this issue in order to be notified on its progress. That issue ticket is for introducing a standard cron type scheduler into SJQ. No guarantee that it'll get done (there are a lot of considerations/edge cases/etc.), but if more people star the issue then I get a feeling for how popular the feature is. Again, there's no guarantee that I'll end up implementing it.

[banshee]

Thanks, your workaround works great. I also left a comment at your link...couldn't quite figure out how to "star" it, though.

[lobosrul]

I'd like SJQ to only run comskip on NEW recordings. Is this possible? I set "The MediaFileQueueLoader thread should run:" to "after start of each new scheduled recording" but no job ever runs.

If I manually "mediafilequeueloader" it queues up every single recording I have which is not what I want.

[Slugger]

You have to be more selective with your rules when deciding which recordings to queue up. Define "new" recording? Would it be a recording that SageTV decides is "new"? If so, then use the $.IsShowFirstRun{} test to identify those recordings. Is it recordings that haven't already been comm skipped before (by some other process)? If so, then check for the existence of an edl file using the FileExists test. Or is it something else? I'd be surprised if you can't define your wishes one way or another in an SJQ rule, but you're going to have to define exactly how you want to restrict things.

The settings on when the QueueLoader runs (before/after recordings start/finish) only determine when the rules are processed in relation to the start or end of a recording event. Regardless of when you invoke the QueueLoader, you still have to write a proper rule to identify exactly which recordings you want processed and which ones you don't.

[jhh]

hi,

I have some dependent rules - something like conditions for my rule number 2 can only be met after rule 1 has executed. (I had some trouble with jobs not starting in the order I wanted).

Apart from setting the "Maximum time MediaFileQueueLoader will sleep between runs (in minutes):" very low - is there a way to trigger a new queue load at the end of a job?

thanks!

[Slugger]

Originally Posted by jhh

hi,

I have some dependent rules - something like conditions for my rule number 2 can only be met after rule 1 has executed. (I had some trouble with jobs not starting in the order I wanted).

Apart from setting the "Maximum time MediaFileQueueLoader will sleep between runs (in minutes):" very low - is there a way to trigger a new queue load at the end of a job?

thanks!

Use the :RUNQLOADER task option to trigger an immediate rerun of the QueueLoader after a task executes successfully.

[lobosrul]

Originally Posted by Slugger

Is it recordings that haven't already been comm skipped before (by some other process)?

That. I just did a workaround of creating a bogus job for SJQ to run on every existing recording .

[Slugger]

Originally Posted by lobosrul

That. I just did a workaround of creating a bogus job for SJQ to run on every existing recording .

That works, too, but the standard approach is to use the FileExists test, such as this:

# Comskip HD tv recordings if an edl doesn't already exist for it, it's not
# actively recording, it hasn't already been watched and it's a manual or 
# favourite recording (in other words, it's not an IR or live tv recording).
if [IsObjMediaFile == true && FileExists != "%d%/%p%.edl" && $.IsTVFile{} == true && Filename =$ ".ts" && $.IsFileCurrentlyRecording{} == false && $.IsWatchedCompletely{} == false && ($.IsManualRecord{} == true || $.IsFavorite{} == true)] {
   :PRIORITY 5
   HDCOMSKIP
}

[lanmat]

I changed INFO to DEBUG and restarted SJQ. But after letting it sit for a while, I'm not seeing any instances of '[ClientParser]' in the log, or any other mentions that it's connecting to a client, though 127.0.0.1 shows up in the Client list.

Here's my test server ruleset for now:
if [(IsObjMediaFile == true && $.IsTVFile{} == true && $.IsFileCurrentlyRecording{} == false && Filename =$ ".mpg" && FileExists != "%d/%p%.avi" && ($.GetShowTitle{} == "24" || $.IsLibraryFile{} == true ))]{
:PRIORITY 1
TRANSCODE_NORMAL
}

[Slugger]

Looks like you may have stumbled upon a client parser bug (or more specifically, a poorly documented task id constraint). Can you remove the underscore in the task id in both the ruleset and the client config and then retry everything? I think that'll fix you up. Let me know either way, please. Task ids can only have upper and lower case letters.

[woribhabor]

I am slowing implimenting job queue with media shrink. I test a quick half hour of a TV show by having Job Queue only queue up based on the show title "Post Oscars", that worked fine. Now I want to test a single DVD, "Milk" which is in my library so i'm using the following code,

if [IsObjMediaFile == true && $.GetShowTitle{} == "Milk" && $.IsDVD{} == true] {
   :PRIORITY 10
   MEDIASHRINK
}

This queues up nothing. Am i writing something wrong? Its the title that the debugger keeps telling me it fails on. Is there a different title variable for DVD's? Also where would i find a list of variables/functions such as $.GetShowTitle