Plugin: Sage Job Queue (SJQ) v3

[Ericft]

Sat Jun 05 21:12:24 EDT 2010: SJQ Application Dump MediaQueueLoader thread is alive... java.lang.Thread.sleep(Native Method) com.google.code.sagetvaddons.sjq.server.MediaFileQueueLoader.run(MediaFileQueueLoader.java:97) java.lang.Thread.run(Unknown Source) SysMsgQueueLoader thread is alive... java.lang.Thread.sleep(Native Method) com.google.code.sagetvaddons.sjq.server.SystemMessageQueueLoader.run(SystemMessageQueueLoader.java:79) java.lang.Thread.run(Unknown Source) ClientMonitor thread is alive... java.lang.Thread.sleep(Native Method) com.google.code.sagetvaddons.sjq.server.ClientMonitor.run(ClientMonitor.java:38) java.lang.Thread.run(Unknown Source) InteralTaskClient thread is alive... java.lang.Thread.sleep(Native Method) com.google.code.sagetvaddons.sjq.server.InternalTaskClient.run(InternalTaskClient.java:68) java.lang.Thread.run(Unknown Source) Most recent LogCleaner thread is dead (this is normal behaviour)! Most recent FileCleaner thread is dead (this is normal behaviour)! Most recent VacuumCleaner thread is dead (this is normal behaviour)!

[toricred]

Is there a way to set a client to check more often if it has jobs? I'm using this to reset an HDPVR when it flakes and it sometimes takes as long as a few minutes.

[Slugger]

Check the client logs from the clients menu. Also, have a look at the dir where you installed the task client. In there is a subdir called logs and in there a file called wrapper.conf. Any errors in there? Also, does that "missing ] on line 6" error still continue? If so, that needs to be addressed (and might be the cause of the problems). Are you sure the jobs aren't getting into the failed list? If they leave the queue they must go somewhere.

[Slugger]

@Ericft Also, please wrap logs in code tags for easier reading. It's way too hard to even try and read that thread dump you provided let alone try to make sense of it.

[Slugger]

Originally Posted by toricred

Is there a way to set a client to check more often if it has jobs? I'm using this to reset an HDPVR when it flakes and it sometimes takes as long as a few minutes.

http://docs.google.com/View?id=dz87g...72800030706673

The sleep option is what you'll want to change.

[Ericft]

sorry about the code tags issue. didn't know it would look like that. checked wrapper.log:

STATUS | wrapper  | 2010/06/06 05:29:57 | --> Wrapper Started as Service
STATUS | wrapper  | 2010/06/06 05:29:57 | Java Service Wrapper Community Edition 3.3.1
STATUS | wrapper  | 2010/06/06 05:29:57 |   Copyright (C) 1999-2008 Tanuki Software, Inc.  All Rights Reserved.
STATUS | wrapper  | 2010/06/06 05:29:57 |     http://wrapper.tanukisoftware.org
STATUS | wrapper  | 2010/06/06 05:29:57 | 
STATUS | wrapper  | 2010/06/06 05:29:57 | Launching a JVM...
INFO   | jvm 1    | 2010/06/06 05:29:58 | WrapperManager: Initializing...
INFO   | jvm 1    | 2010/06/06 05:29:58 | SJQ Task Client v3.0.2.771
INFO   | jvm 1    | 2010/06/06 05:29:58 | Using 'C:/sjqc' as location for configuration file...

Client logs are empty.
Nothing in completed or failed tasks. What do you reckon is the meaning of the [ missing line 6? where would I address that?

new error in server logs re: sql server...

2010-06-06 05:30:46,108 ERROR [DataStore]: SQL error
java.sql.SQLException: database is locked
	at org.sqlite.DB.throwex(DB.java:288)
	at org.sqlite.DB.executeBatch(DB.java:236)
	at org.sqlite.PrepStmt.executeBatch(PrepStmt.java:83)
	at com.google.code.sagetvaddons.sjq.server.DataStore.flushLogs(DataStore.java:1154)
	at com.google.code.sagetvaddons.sjq.server.SJQServlet.doPost(SJQServlet.java:307)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:727)
	at javax.servlet.http.HttpServlet.service(HttpServlet.java:820)
	at org.mortbay.jetty.servlet.ServletHolder.handle(ServletHolder.java:502)
	at org.mortbay.jetty.servlet.ServletHandler.handle(ServletHandler.java:389)
	at org.mortbay.jetty.security.SecurityHandler.handle(SecurityHandler.java:216)
	at org.mortbay.jetty.servlet.SessionHandler.handle(SessionHandler.java:181)
	at org.mortbay.jetty.handler.ContextHandler.handle(ContextHandler.java:765)
	at org.mortbay.jetty.webapp.WebAppContext.handle(WebAppContext.java:417)
	at org.mortbay.jetty.handler.ContextHandlerCollection.handle(ContextHandlerCollection.java:230)
	at org.mortbay.jetty.handler.HandlerCollection.handle(HandlerCollection.java:114)
	at org.mortbay.jetty.handler.HandlerWrapper.handle(HandlerWrapper.java:152)
	at org.mortbay.jetty.handler.rewrite.RewriteHandler.handle(RewriteHandler.java:230)
	at org.mortbay.jetty.handler.HandlerWrapper.handle(HandlerWrapper.java:152)
	at org.mortbay.jetty.Server.handle(Server.java:326)
	at org.mortbay.jetty.HttpConnection.handleRequest(HttpConnection.java:534)
	at org.mortbay.jetty.HttpConnection$RequestHandler.content(HttpConnection.java:879)
	at org.mortbay.jetty.HttpParser.parseNext(HttpParser.java:747)
	at org.mortbay.jetty.HttpParser.parseAvailable(HttpParser.java:218)
	at org.mortbay.jetty.HttpConnection.handle(HttpConnection.java:404)
	at org.mortbay.io.nio.SelectChannelEndPoint.run(SelectChannelEndPoint.java:409)
	at org.mortbay.thread.QueuedThreadPool$PoolThread.run(QueuedThreadPool.java:520)
2010-06-06 05:30:46,108 INFO  [SJQServlet]: Servlet POST request completed [3079ms]
2010-06-06 05:30:46,236 INFO  [DataStore]: Flushed 1 log message(s) in 157ms
2010-06-06 05:30:46,236 INFO  [SJQServlet]: Servlet POST request completed [158ms]
2010-06-06 05:30:46,276 INFO  [SJQServlet]: Servlet POST request completed [1ms]
2010-06-06 05:30:46,277 INFO  [SJQServlet]: Servlet POST request completed [39ms]
2010-06-06 05:30:46,426 INFO  [DataStore]: Flushed 1 log message(s) in 346ms
2010-06-06 05:30:46,427 INFO  [SJQServlet]: Servlet POST request completed [348ms]
2010-06-06 05:30:46,428 INFO  [SJQServlet]: Checking client '10.0.1.27': 75 resources free.
2010-06-06 05:30:46,429 INFO  [SJQServlet]: Servlet POST request completed [1ms]
2010-06-06 05:30:46,429 INFO  [SJQServlet]: Servlet POST request completed [1ms]
2010-06-06 05:30:46,559 INFO  [DataStore]: Flushed 1 log message(s) in 125ms
2010-06-06 05:30:46,560 INFO  [SJQServlet]: Servlet POST request completed [127ms]
2010-06-06 05:30:46,562 INFO  [SJQServlet]: Servlet POST request completed [0ms]
2010-06-06 05:30:46,577 INFO  [SJQServlet]: Servlet POST request completed [1ms]
2010-06-06 05:30:46,733 INFO  [DataStore]: Flushed 1 log message(s) in 300ms
2010-06-06 05:30:46,734 INFO  [SJQServlet]: Servlet POST request completed [301ms]
2010-06-06 05:30:46,736 INFO  [SJQServlet]: Checking client '10.0.1.27': 75 resources free.
2010-06-06 05:30:46,736 INFO  [SJQServlet]: Servlet POST request completed [1ms]
2010-06-06 05:30:46,736 INFO  [SJQServlet]: Servlet POST request completed [1ms]
2010-06-06 05:30:46,928 INFO  [DataStore]: Flushed 1 log message(s) in 191ms
2010-06-06 05:30:46,928 INFO  [SJQServlet]: Servlet POST request completed [191ms]
2010-06-06 05:30:46,931 INFO  [SJQServlet]: Servlet POST request completed [1ms]
2010-06-06 05:30:46,947 INFO  [SJQServlet]: Servlet POST request completed [1ms]
2010-06-06 05:30:47,107 INFO  [DataStore]: Flushed 1 log message(s) in 369ms
2010-06-06 05:30:47,107 INFO  [SJQServlet]: Servlet POST request completed [369ms]
2010-06-06 05:30:47,109 INFO  [SJQServlet]: Servlet POST request completed [1ms]
2010-06-06 05:30:47,109 INFO  [SJQServlet]: Checking client '10.0.1.27': 75 resources free.
2010-06-06 05:30:47,110 INFO  [SJQServlet]: Servlet POST request completed [2ms]
2010-06-06 05:30:47,111 INFO  [SJQServlet]: Checking client '10.0.1.27': 75 resources free.
2010-06-06 05:30:47,112 INFO  [SJQServlet]: Servlet POST request completed [1ms]
2010-06-06 05:30:47,274 INFO  [DataStore]: Flushed 1 log message(s) in 164ms
2010-06-06 05:30:47,274 INFO  [SJQServlet]: Servlet POST request completed [164ms]
2010-06-06 05:30:47,277 INFO  [SJQServlet]: Servlet POST request completed [1ms]
2010-06-06 05:30:47,305 INFO  [SJQServlet]: Servlet POST request completed [13ms]
2010-06-06 05:30:47,307 INFO  [SJQServlet]: Checking client '10.0.1.27': 100 resources free.
2010-06-06 05:30:47,307 INFO  [SJQServlet]: Servlet POST request completed [0ms]
2010-06-06 05:30:47,414 INFO  [DataStore]: Flushed 4 log message(s) in 124ms
2010-06-06 05:30:47,414 INFO  [SJQServlet]: Servlet POST request completed [125ms]
2010-06-06 05:30:47,591 INFO  [DataStore]: Flushed 4 log message(s) in 300ms
2010-06-06 05:30:47,592 INFO  [SJQServlet]: Servlet POST request completed [302ms]
2010-06-06 05:30:47,748 INFO  [DataStore]: Flushed 4 log message(s) in 804ms
2010-06-06 05:30:47,748 INFO  [SJQServlet]: Servlet POST request completed [805ms]
2010-06-06 05:30:47,971 INFO  [DataStore]: Flushed 4 log message(s) in 1696ms
2010-06-06 05:30:47,971 INFO  [SJQServlet]: Servlet POST request completed [1697ms]
2010-06-06 05:30:48,244 INFO  [DataStore]: Flushed 4 log message(s) in 1300ms
2010-06-06 05:30:48,244 INFO  [SJQServlet]: Servlet POST request completed [1301ms]
2010-06-06 05:30:48,409 INFO  [DataStore]: Flushed 4 log message(s) in 1833ms
2010-06-06 05:30:48,409 INFO  [SJQServlet]: Servlet POST request completed [1834ms]
2010-06-06 05:30:48,643 INFO  [DataStore]: Flushed 4 log message(s) in 2067ms
2010-06-06 05:30:48,643 INFO  [SJQServlet]: Servlet POST request completed [2068ms]
2010-06-06 05:30:48,847 INFO  [DataStore]: Flushed 4 log message(s) in 2571ms
2010-06-06 05:30:48,847 INFO  [SJQServlet]: Servlet POST request completed [2573ms]
2010-06-06 05:30:54,009 INFO  [SJQServlet]: Servlet POST request completed [0ms]
2010-06-06 05:31:04,044 INFO  [SJQServlet]: Servlet POST request completed [2ms]
2010-06-06 05:31:13,992 INFO  [SJQServlet]: Servlet POST request completed [1ms]
2010-06-06 05:31:19,843 INFO  [SystemMessageQueueLoader]: Run completed [66ms]
2010-06-06 05:31:23,989 INFO  [SJQServlet]: Servlet POST request completed [0ms]
2010-06-06 05:31:33,989 INFO  [SJQServlet]: Servlet POST request completed [0ms]
2010-06-06 05:31:43,988 INFO  [SJQServlet]: Servlet POST request completed [0ms]
2010-06-06 05:31:53,992 INFO  [SJQServlet]: Servlet POST request completed [1ms]
2010-06-06 05:32:03,998 INFO  [SJQServlet]: Servlet POST request completed [0ms]
2010-06-06 05:32:13,988 INFO  [SJQServlet]: Servlet POST request completed [0ms]
2010-06-06 05:32:21,165 INFO  [SystemMessageQueueLoader]: Run completed [360ms]
2010-06-06 05:32:23,990 INFO  [SJQServlet]: Servlet POST request completed [0ms]
2010-06-06 05:32:26,408 INFO  [InternalTaskClient]: Run completed [0ms]
2010-06-06 05:32:33,990 INFO  [SJQServlet]: Servlet POST request completed [1ms]
2010-06-06 05:32:36,677 INFO  [SJQServlet]: Servlet POST request completed [1ms]
2010-06-06 05:32:43,990 INFO  [SJQServlet]: Servlet POST request completed [1ms]
2010-06-06 05:32:53,990 INFO  [SJQServlet]: Servlet POST request completed [0ms]
2010-06-06 05:33:03,989 INFO  [SJQServlet]: Servlet POST request completed [1ms]
2010-06-06 05:33:13,989 INFO  [SJQServlet]: Servlet POST request completed [0ms]
2010-06-06 05:33:21,924 INFO  [SystemMessageQueueLoader]: Run completed [61ms]
2010-06-06 05:33:23,990 INFO  [SJQServlet]: Servlet POST request completed [0ms]
2010-06-06 05:33:33,988 INFO  [SJQServlet]: Servlet POST request completed [0ms]
2010-06-06 05:33:43,989 INFO  [SJQServlet]: Servlet POST request completed [0ms]
2010-06-06 05:33:53,990 INFO  [SJQServlet]: Servlet POST request completed [0ms]
2010-06-06 05:34:04,453 INFO  [SJQServlet]: Servlet POST request completed [0ms]
2010-06-06 05:34:13,988 INFO  [SJQServlet]: Servlet POST request completed [0ms]
2010-06-06 05:34:22,244 INFO  [SystemMessageQueueLoader]: Run completed [149ms]
2010-06-06 05:34:24,011 INFO  [SJQServlet]: Servlet POST request completed [22ms]
2010-06-06 05:34:26,182 INFO  [ClientMonitor]: Run completed [0ms]
2010-06-06 05:34:26,409 INFO  [InternalTaskClient]: Run completed [0ms]
2010-06-06 05:34:34,015 INFO  [SJQServlet]: Servlet POST request completed [0ms]
2010-06-06 05:34:36,672 INFO  [SJQServlet]: Servlet POST request completed [1ms]
2010-06-06 05:34:43,989 INFO  [SJQServlet]: Servlet POST request completed [0ms]
2010-06-06 05:34:54,000 INFO  [SJQServlet]: Servlet POST request completed [1ms]
2010-06-06 05:35:03,990 INFO  [SJQServlet]: Servlet POST request completed [0ms]
2010-06-06 05:35:13,988 INFO  [SJQServlet]: Servlet POST request completed [0ms]
2010-06-06 05:35:22,560 INFO  [SystemMessageQueueLoader]: Run completed [113ms]
2010-06-06 05:35:23,988 INFO  [SJQServlet]: Servlet POST request completed [0ms]
2010-06-06 05:35:33,989 INFO  [SJQServlet]: Servlet POST request completed [0ms]
2010-06-06 05:35:43,989 INFO  [SJQServlet]: Servlet POST request completed [0ms]
2010-06-06 05:35:47,364 INFO  [SJQServlet]: Checking client '10.0.1.27': 100 resources free.
2010-06-06 05:35:47,365 INFO  [SJQServlet]: Servlet POST request completed [10ms]
2010-06-06 05:35:53,989 INFO  [SJQServlet]: Servlet POST request completed [1ms]
2010-06-06 05:36:03,990 INFO  [SJQServlet]: Servlet POST request completed [1ms]
2010-06-06 05:36:13,989 INFO  [SJQServlet]: Servlet POST request completed [0ms]
2010-06-06 05:36:22,822 INFO  [SystemMessageQueueLoader]: Run completed [89ms]
2010-06-06 05:36:23,989 INFO  [SJQServlet]: Servlet POST request completed [0ms]
2010-06-06 05:36:26,409 INFO  [InternalTaskClient]: Run completed [0ms]
2010-06-06 05:36:33,990 INFO  [SJQServlet]: Servlet POST request completed [1ms]
2010-06-06 05:36:36,675 INFO  [SJQServlet]: Servlet POST request completed [0ms]
2010-06-06 05:36:43,989 INFO  [SJQServlet]: Servlet POST request completed [0ms]
2010-06-06 05:36:53,989 INFO  [SJQServlet]: Servlet POST request completed [0ms]
2010-06-06 05:37:03,990 INFO  [SJQServlet]: Servlet POST request completed [1ms]
2010-06-06 05:37:13,991 INFO  [SJQServlet]: Servlet POST request completed [1ms]
2010-06-06 05:37:23,173 INFO  [SystemMessageQueueLoader]: Run completed [158ms]
2010-06-06 05:37:24,007 INFO  [SJQServlet]: Servlet POST request completed [1ms]
2010-06-06 05:37:33,985 INFO  [SJQServlet]: Servlet POST request completed [1ms]
2010-06-06 05:37:43,989 INFO  [SJQServlet]: Servlet POST request completed [0ms]
2010-06-06 05:37:53,989 INFO  [SJQServlet]: Servlet POST request completed [0ms]
2010-06-06 05:38:00,083 INFO  [SJQServlet]: Servlet POST request completed [174ms]
2010-06-06 05:38:23,572 INFO  [SystemMessageQueueLoader]: Run completed [108ms]
2010-06-06 05:38:26,409 INFO  [InternalTaskClient]: Run completed [0ms]
2010-06-06 05:38:38,733 INFO  [SJQServlet]: Servlet POST request completed [1ms]
2010-06-06 05:38:45,079 INFO  [SJQServlet]: Servlet POST request completed [194ms]
2010-06-06 05:39:23,842 INFO  [SystemMessageQueueLoader]: Run completed [69ms]
2010-06-06 05:39:26,182 INFO  [ClientMonitor]: Run completed [0ms]

[Slugger]

The "[ line 6..." error means that there is a syntax error on line 6 of your ruleset. However, it seems you've fixed that at some point.

I need your jetty request logs matching the timestamps of the logs you provided above. If the jobs are just disappearing then I don't know what's going on. Your sjq.sqlite db file might also prove helpful. Though I will warn you, it might be a few days (or longer) before I find the time to do the kind of debugging required in this case.

[davephan]

Originally Posted by sportera

This may be a dumb question, but is there any advantage to running SJQ if you're using Dirmon2 to process commercial skipping vs comskip monitor?

I just loaded it for the first time in v7 after reading a couple of posts stating it is a super, duper useful plugin. But so far haven't gotten deep enough in the reading to find out what it does, other than add more flexibility to comskip processing.

I used Dirmon2 for years, and it does work great. It is much easier to setup than SJQ. However, I think you will find it worth the effort to get SJQ setup. I used to Comskip everything with Dirmon2. Several computers running Dirmon2 had a tough time keeping up with all the Comskip jobs. The Comskip processing is not perfect, so commercials can be detected where they don't exist on non-commercial channels. Plus, it is a big waste of processing power to blindly Comskip everything. I offloaded my Dirmon2 to several computers in the past, and it had a tough time keeping up. I now have SJQ offloaded to a second computer, Comskip processing only the commercial channels, and keeping up with the recordings. I offload the Comskip processing to remove CPU load from my SageTV computer.

Dave

[Ericft]

how to i get the jetty request files? also my squlite.db is invalid to list on this website. i changed it to .txt and compressed. attached.also, i looked in my queue and found this error next to some of the files that were waiting in the queue...the files are definately there but get this error

Sat Jun 05 18:40:22 EDT 2010: Starting task with priority 5/1/10
Executing command line: C:/comskip/comskip.exe "D:\ErinBrockovich-8025985-0.ts"
Comskip 0.80.031, made using:
mpeg2dec-0.4.0 - by Michel Lespinasse <walken@zoy.org> and Aaron Holtzman
No such file or directory - could not open file D:\ErinBrockovich-8025985-0.ts

The commandline used was:
C:\comskip\comskip.exe D:\ErinBrockovich-8025985-0.ts
Opening D:\ErinBrockovich-8025985-0.ts

Sat Jun 05 18:45:46 EDT 2010: Starting task with priority 5/1/10
Executing command line: C:/comskip/comskip.exe "D:\ErinBrockovich-8025985-0.ts"
The commandline used was:
C:\comskip\comskip.exe D:\ErinBrockovich-8025985-0.ts
Opening D:\ErinBrockovich-8025985-0.ts

Comskip 0.80.031, made using:
mpeg2dec-0.4.0 - by Michel Lespinasse <walken@zoy.org> and Aaron Holtzman
No such file or directory - could not open file D:\ErinBrockovich-8025985-0.ts

Sat Jun 05 18:56:11 EDT 2010: Starting task with priority 10/1/10
Executing command line: C:/comskip/comskip.exe "D:\ErinBrockovich-8025985-0.ts"
Comskip 0.80.031, made using:
mpeg2dec-0.4.0 - by Michel Lespinasse <walken@zoy.org> and Aaron Holtzman
No such file or directory - could not open file D:\ErinBrockovich-8025985-0.ts

[peternm22]

I'm just setting up SJQ for the first time, and I'm having a bit of trouble configuring it. I've used Dirmon2 for a few years, so this is all new to me.

Every time a recording starts, I want it to start running Showanalyzer right away. From what I understand the MediaFileQueueLoader is what adds items to the queue to be processed. In the settings I set for the MediaFileQueueLoader thread to run "After start of each scheduled program". I begin recording something, but it doesn't show up in the active queue. I wait a few minutes, still nothing. I manually run the MediaFileQueueLoader and it finally appears in the active queue. Where am I going wrong? Shouldn't the recordings be popping up immediately in the active queue? Unless I manually invoke the MediaFileQueueLoader, the "Next Run" time is about 20 minutes away.

Next issue, is that after a task is finally added to active queue, it just sits there with a "Waiting" state for 3-5 minutes (I haven't timed it exactly, but that's close). Then it starts Showanalyzer, and everything is working fine again.

Any ideas why I am getting the delays? My configuration details are below.

Thanks.

My Ruleset:

if [IsObjMediaFile == true && $.IsTVFile{} == true && FileExists != "%d%/%p%.edl" && $.GetAiringChannelNumber{} !% "50[0-3]" && $.GetAiringChannelNumber{} !% "62[1-5]" && $.GetAiringChannelNumber{} != "364" && $.GetAiringChannelNumber{} != "374" && $.GetAiringChannelNumber{} != "375" && $.GetAiringChannelNumber{} != "296" && $.GetAiringChannelNumber{} != "297" && $.GetAiringChannelNumber{} != "283" && $.GetAiringChannelNumber{} != "288" && $.IsNotManualOrFavorite{} == false]{
   :PRIORITY 10
   COMSKIP
}

My task client:

COMSKIP {
   :RESOURCES 50 # Up to 2 comskips can be run simultaneously (every client has exactly 100 resources available)

   # CPU priority to be used for this task process; one of LOW, NORMAL, HIGH (case sensitive)
   :CPU LOW   # Default is NORMAL if not specified

   "C:/Program Files (x86)/Dragon Global/ShowAnalyzer/ShowAnalyzer.exe \"%c%\""
}

[Slugger]

Originally Posted by Ericft

how to i get the jetty request files? also my squlite.db is invalid to list on this website. i changed it to .txt and compressed. attached.also, i looked in my queue and found this error next to some of the files that were waiting in the queue...the files are definately there but get this error

Sat Jun 05 18:40:22 EDT 2010: Starting task with priority 5/1/10
Executing command line: C:/comskip/comskip.exe "D:\ErinBrockovich-8025985-0.ts"
Comskip 0.80.031, made using:
mpeg2dec-0.4.0 - by Michel Lespinasse <walken@zoy.org> and Aaron Holtzman
No such file or directory - could not open file D:\ErinBrockovich-8025985-0.ts

The commandline used was:
C:\comskip\comskip.exe D:\ErinBrockovich-8025985-0.ts
Opening D:\ErinBrockovich-8025985-0.ts

Sat Jun 05 18:45:46 EDT 2010: Starting task with priority 5/1/10
Executing command line: C:/comskip/comskip.exe "D:\ErinBrockovich-8025985-0.ts"
The commandline used was:
C:\comskip\comskip.exe D:\ErinBrockovich-8025985-0.ts
Opening D:\ErinBrockovich-8025985-0.ts

Comskip 0.80.031, made using:
mpeg2dec-0.4.0 - by Michel Lespinasse <walken@zoy.org> and Aaron Holtzman
No such file or directory - could not open file D:\ErinBrockovich-8025985-0.ts

Sat Jun 05 18:56:11 EDT 2010: Starting task with priority 10/1/10
Executing command line: C:/comskip/comskip.exe "D:\ErinBrockovich-8025985-0.ts"
Comskip 0.80.031, made using:
mpeg2dec-0.4.0 - by Michel Lespinasse <walken@zoy.org> and Aaron Holtzman
No such file or directory - could not open file D:\ErinBrockovich-8025985-0.ts

And where did you find these logs? In the failed tasks, no? Anyway, this is all I need to see. I assume you're running the task client on a different host than the Sage server that's recording these files? You either need to ensure D:\ on your client machine is mapped to D:\ on your Sage server or you need to use the :MAPDIR directive in your task client config to remap. See the User Guide for more details. The error should be rather obvious -- comskip can't find the recordings you're telling it to comskip. You need to configure the task client host to be able to find the recordings. You do this either by mapping network drives or using the :MAPDIR directive in SJQ.

[Slugger]

Originally Posted by peternm22

I'm just setting up SJQ for the first time, and I'm having a bit of trouble configuring it. I've used Dirmon2 for a few years, so this is all new to me.

Every time a recording starts, I want it to start running Showanalyzer right away. From what I understand the MediaFileQueueLoader is what adds items to the queue to be processed. In the settings I set for the MediaFileQueueLoader thread to run "After start of each scheduled program". I begin recording something, but it doesn't show up in the active queue. I wait a few minutes, still nothing. I manually run the MediaFileQueueLoader and it finally appears in the active queue. Where am I going wrong? Shouldn't the recordings be popping up immediately in the active queue? Unless I manually invoke the MediaFileQueueLoader, the "Next Run" time is about 20 minutes away.

SJQ periodically checks the recording schedule to try and figure out when the next recording will start. When you go and start a manual recording then SJQ knows nothing about it. That's why the queue loader doesn't run immediately. Eventually I'll be porting SJQ to use the new SageTV v7 event model and when I do then it will handle any recording starting at any time. Until then, it's working as designed at the moment.

Next issue, is that after a task is finally added to active queue, it just sits there with a "Waiting" state for 3-5 minutes (I haven't timed it exactly, but that's close). Then it starts Showanalyzer, and everything is working fine again.

Any ideas why I am getting the delays? My configuration details are below.

Thanks.

My Ruleset:

if [IsObjMediaFile == true && $.IsTVFile{} == true && FileExists != "%d%/%p%.edl" && $.GetAiringChannelNumber{} !% "50[0-3]" && $.GetAiringChannelNumber{} !% "62[1-5]" && $.GetAiringChannelNumber{} != "364" && $.GetAiringChannelNumber{} != "374" && $.GetAiringChannelNumber{} != "375" && $.GetAiringChannelNumber{} != "296" && $.GetAiringChannelNumber{} != "297" && $.GetAiringChannelNumber{} != "283" && $.GetAiringChannelNumber{} != "288" && $.IsNotManualOrFavorite{} == false]{
   :PRIORITY 10
   COMSKIP
}

My task client:

COMSKIP {
   :RESOURCES 50 # Up to 2 comskips can be run simultaneously (every client has exactly 100 resources available)

   # CPU priority to be used for this task process; one of LOW, NORMAL, HIGH (case sensitive)
   :CPU LOW   # Default is NORMAL if not specified

   "C:/Program Files (x86)/Dragon Global/ShowAnalyzer/ShowAnalyzer.exe \"%c%\""
}

Again, working as designed. The task client polls the server every five minutes by default. If you want it to poll more often then edit the sjqc.properties file of your task client. It will accept values no lower than 30 (i.e. 30 seconds between checks). You will need to restart the task client after changing the polling time.

[peternm22]

Originally Posted by Slugger

SJQ periodically checks the recording schedule to try and figure out when the next recording will start. When you go and start a manual recording then SJQ knows nothing about it. That's why the queue loader doesn't run immediately. Eventually I'll be porting SJQ to use the new SageTV v7 event model and when I do then it will handle any recording starting at any time. Until then, it's working as designed at the moment.

How often does it check the recording schedule? Any way to change it?

Originally Posted by Slugger

Again, working as designed. The task client polls the server every five minutes by default. If you want it to poll more often then edit the sjqc.properties file of your task client. It will accept values no lower than 30 (i.e. 30 seconds between checks). You will need to restart the task client after changing the polling time.

Excellent, I changed the time to 2 minutes (120 seconds).

Thanks for the help.

[Slugger]

Originally Posted by peternm22

How often does it check the recording schedule? Any way to change it?

It checks the recording schedule each time the queue loader runs. A run is triggered at SJQ start up then as determined by the results of that first run.

Can that frequency be changed? No. As I say, when I have some time I will change the queue loader to listen for the new SageTV v7 events and act on them. When I do that then it'll run anytime any recording is started. There is no ETA as to when I may make that change (SJQ is way down the priority list right now). To write the patch should only take someone familar with Java but a few hours (at most) to do and I'm always willing to accept patches.

[drmargarit]

What would I download to use SJQ with the latest 6.x sagetv?. The only file that matches the directions in the pdf manual is sjq-3.1.0.806.zip which has a note that says it requires SageTV v7.

JLM

[Slugger]

Originally Posted by drmargarit

What would I download to use SJQ with the latest 6.x sagetv?. The only file that matches the directions in the pdf manual is sjq-3.1.0.806.zip which has a note that says it requires SageTV v7.

JLM

http://code.google.com/p/sagetv-addo...p&can=1&q=sjq-

Be warned, however, that bug fixes, etc. will no longer be fixed in 3.0.x (or older).

[graywolf]

ok...had SJQC service running. Made some changes to the server and client rules. rebooted machine. now i get stuff in the active queue but client isn't running anything.

this is what I have in the wrapper.log file

STATUS | wrapper | 2010/06/10 17:46:25 | Launching a JVM...
INFO | jvm 1 | 2010/06/10 17:46:27 | WrapperManager: Initializing...
INFO | jvm 1 | 2010/06/10 17:46:28 | SJQ Task Client v3.0.1.705
INFO | jvm 1 | 2010/06/10 17:46:28 | Using 'C:\sjqc\sjqc_winntsvc\bin' as location for configuration file...
INFO | jvm 1 | 2010/06/10 17:46:29 | Connection refused: connect

any suggestions?

ps. it does show in Clients. Just not processing anything in the Active Queue.

Client Tasks are:

DURATION {
:RESOURCES 25
:MAX 1
:CPU "NORMAL"
"C\:\\MediaInfo\\MediaInfo.exe --Inform=General;%Duration% --LogFile=\"%d%\\%p%.duration\" \"%c%\""
}
COMSKIP1 {
:RESOURCES 100 # 1 comskips can be run simultaneously (every client has exactly 100 resources available)
# CPU priority to be used for this task process; one of LOW, NORMAL, HIGH (case sensitive)
:CPU "NORMAL" # Default is NORMAL if not specified
# Comskip returns 1 on success instead of the universally accepted zero; tell SJQ that
# a return code of 1 means success instead of the default value of zero
:RETURNCODE 1
"C:/comskip/comskip.exe --ini=c:/comskip/comskip1.ini \"%c%\""
}
COMSKIP_CBS {
:RESOURCES 100 # 1 comskips can be run simultaneously (every client has exactly 100 resources available)
# CPU priority to be used for this task process; one of LOW, NORMAL, HIGH (case sensitive)
:CPU "NORMAL" # Default is NORMAL if not specified
# Comskip returns 1 on success instead of the universally accepted zero; tell SJQ that
# a return code of 1 means success instead of the default value of zero
:RETURNCODE 1
"C:/comskip/comskip.exe --ini=c:/comskip/cbs.ini \"%c%\""
}
COMSKIP_ABC {
:RESOURCES 100 # 1 comskips can be run simultaneously (every client has exactly 100 resources available)
# CPU priority to be used for this task process; one of LOW, NORMAL, HIGH (case sensitive)
:CPU "NORMAL" # Default is NORMAL if not specified
# Comskip returns 1 on success instead of the universally accepted zero; tell SJQ that
# a return code of 1 means success instead of the default value of zero
:RETURNCODE 1
"C:/comskip/comskip.exe --ini=c:/comskip/abc.ini \"%c%\""
}
COMSKIP_NBC {
:RESOURCES 100 # 1 comskips can be run simultaneously (every client has exactly 100 resources available)
# CPU priority to be used for this task process; one of LOW, NORMAL, HIGH (case sensitive)
:CPU "NORMAL" # Default is NORMAL if not specified
# Comskip returns 1 on success instead of the universally accepted zero; tell SJQ that
# a return code of 1 means success instead of the default value of zero
:RETURNCODE 1
"C:/comskip/comskip.exe --ini=c:/comskip/nbc.ini \"%c%\""
}

[Slugger]

Is the client listed in the clients menu on the GUI? If so, that means it's connecting, but not being assigned any work. If that's the case, check the sjq server logs for details on what it's doing.

If the client isn't listed, give it 5 mins and if it's still not listed then the task client isn't configured properly or the server is not allowing it to connect. Check sjqc.properties and ensure the host is set to the server host and the port set to the port that jetty runs on. If that looks good, check the firewall settings on the server to ensure that it's allowing the task client to connect.

[graywolf]

not running firewall. server/client on Sage Server

2010-06-10 18:06:38,500 INFO  [ClientMonitor]: Run completed [0ms]
2010-06-10 18:06:38,515 INFO  [InternalTaskClient]: Run completed [0ms]
2010-06-10 18:06:38,843 WARN  [SJQServlet]: All client connections are being accepted and processed, please consider setting up client restrictions in SJQ settings
2010-06-10 18:06:38,843 INFO  [SJQServlet]: Servlet POST request completed [0ms]
2010-06-10 18:06:47,984 INFO  [SystemMessageQueueLoader]: Run completed [94ms]
2010-06-10 18:07:00,312 WARN  [DataStore]: DataStore pool timeout expired! '10551079@qtp-32373432-7' did not return connection within 30 seconds!  Adding a replacement connection to the pool.
2010-06-10 18:07:09,046 WARN  [SJQServlet]: All client connections are being accepted and processed, please consider setting up client restrictions in SJQ settings
2010-06-10 18:07:09,046 INFO  [SJQServlet]: Servlet POST request completed [0ms]
2010-06-10 18:07:13,609 WARN  [SJQServlet]: All client connections are being accepted and processed, please consider setting up client restrictions in SJQ settings
2010-06-10 18:07:13,625 INFO  [SJQServlet]: Servlet POST request completed [16ms]
2010-06-10 18:07:13,656 WARN  [SJQServlet]: All client connections are being accepted and processed, please consider setting up client restrictions in SJQ settings
2010-06-10 18:07:13,656 INFO  [SJQServlet]: Servlet POST request completed [0ms]
2010-06-10 18:07:21,531 WARN  [SJQServlet]: All client connections are being accepted and processed, please consider setting up client restrictions in SJQ settings
2010-06-10 18:07:21,531 INFO  [SJQServlet]: Servlet POST request completed [0ms]
2010-06-10 18:07:23,656 WARN  [SJQServlet]: All client connections are being accepted and processed, please consider setting up client restrictions in SJQ settings
2010-06-10 18:07:23,656 INFO  [SJQServlet]: Servlet POST request completed [0ms]
2010-06-10 18:07:33,312 WARN  [SJQServlet]: All client connections are being accepted and processed, please consider setting up client restrictions in SJQ settings
2010-06-10 18:07:33,312 INFO  [SJQServlet]: Servlet POST request completed [0ms]
2010-06-10 18:07:36,703 WARN  [SJQServlet]: All client connections are being accepted and processed, please consider setting up client restrictions in SJQ settings
2010-06-10 18:07:36,703 INFO  [SJQServlet]: Servlet POST request completed [0ms]
2010-06-10 18:07:39,484 WARN  [SJQServlet]: All client connections are being accepted and processed, please consider setting up client restrictions in SJQ settings
2010-06-10 18:07:39,500 INFO  [SJQServlet]: Servlet POST request completed [16ms]
2010-06-10 18:07:39,531 WARN  [SJQServlet]: All client connections are being accepted and processed, please consider setting up client restrictions in SJQ settings
2010-06-10 18:07:39,531 INFO  [SJQServlet]: Servlet POST request completed [0ms]
2010-06-10 18:07:44,078 WARN  [SJQServlet]: All client connections are being accepted and processed, please consider setting up client restrictions in SJQ settings
2010-06-10 18:07:44,078 INFO  [SJQServlet]: Servlet POST request completed [0ms]
2010-06-10 18:07:48,265 INFO  [SystemMessageQueueLoader]: Run completed [94ms]
2010-06-10 18:07:55,593 WARN  [SJQServlet]: All client connections are being accepted and processed, please consider setting up client restrictions in SJQ settings
2010-06-10 18:07:55,593 INFO  [SJQServlet]: Servlet POST request completed [0ms]
2010-06-10 18:07:55,593 INFO  [MediaFileQueueLoader]: sleep interrupted
2010-06-10 18:07:56,078 INFO  [MediaFileQueueLoader]: Run completed [485ms]
2010-06-10 18:07:56,078 INFO  [DataStore]: Thread 'SJQ-LogCleaner' is seeking an exclusive DataStore connection!
2010-06-10 18:07:56,078 INFO  [DataStore]: Thread 'SJQ-LogCleaner' is waiting for an exclusive DataStore connection! [AVAIL=4; MAX=5; WAIT=0ms]
2010-06-10 18:07:56,078 INFO  [VacuumCleaner]: Thread finished [0ms]
2010-06-10 18:07:56,078 INFO  [DataStore]: Thread 'SJQ-LogCleaner' is waiting for an exclusive DataStore connection! [AVAIL=4; MAX=5; WAIT=0ms]
2010-06-10 18:07:56,078 INFO  [DataStore]: Thread 'SJQ-LogCleaner' has received an exclusive DataStore connection! [WAIT=0ms]
2010-06-10 18:07:56,093 INFO  [FileCleaner]: Thread finished [15ms]
2010-06-10 18:07:56,171 INFO  [DataStore]: 'SJQ-LogCleaner' has returned its exclusive DataStore connection!
2010-06-10 18:07:56,171 INFO  [LogCleaner]: Thread finished [93ms]
2010-06-10 18:08:09,359 WARN  [SJQServlet]: All client connections are being accepted and processed, please consider setting up client restrictions in SJQ settings
2010-06-10 18:08:09,375 INFO  [SJQServlet]: Servlet POST request completed [16ms]
2010-06-10 18:08:38,515 INFO  [InternalTaskClient]: Run completed [0ms]
2010-06-10 18:08:48,515 INFO  [SystemMessageQueueLoader]: Run completed [78ms]
2010-06-10 18:08:54,359 WARN  [SJQServlet]: All client connections are being accepted and processed, please consider setting up client restrictions in SJQ settings
2010-06-10 18:08:54,359 INFO  [SJQServlet]: Servlet POST request completed [0ms]
2010-06-10 18:09:21,531 WARN  [SJQServlet]: All client connections are being accepted and processed, please consider setting up client restrictions in SJQ settings
2010-06-10 18:09:21,531 INFO  [SJQServlet]: Servlet POST request completed [0ms]
2010-06-10 18:09:39,359 WARN  [SJQServlet]: All client connections are being accepted and processed, please consider setting up client restrictions in SJQ settings

[graywolf]

ok...got it working.

looks like the task names do not like underscores in them.

COMSKIP_ABC changed to COMSKIPABC seemed to have resolved the issue