Plugin: Sage Job Queue (SJQ) v3

[Slugger]

off the top of my head, I'd say wrap the call to comskip in a batch file and before calling comskip create a .running file and after comskip is done remove the .running file. As long as the .running file is there, comskip is running, when it's not, it's done.

[ohpleaseno]

Is there any way to limit items to a specific import directory? I have 4 different imported videos directories and I want to call Mediascraper against only one of them to generate a .properties file (and have Mediascraper move it to another import directory). I can limit the search to any imported video without a .properties file, but that gets me a ton of stuff that I don't want to generate .properties files for (home videos and whatnot).

[ptzink]

Originally Posted by ohpleaseno

&& FileExists != "%d%/%p%.edl"

Thanks ohpleaseno! So my ruleset looks like this now

if [IsObjMediaFile == true && $.IsTVFile{} == true && $.IsNotManualOrFavorite{} == false && $.GetAiringChannelName{} !% "WFYI.*|WIPB.*" && FileExists != "%d%/%p%.edl"] {
COMSKIP
}

Does this look right? There is nothing in my queue, but then again there shouldn't be since everything has a comskip file as of now.
Another question - will SJQ kickoff the comskip job as soon as the show (fav or manual) starts recording? I would like that to happen, but didn't know if there is some extra syntax I have to add to make it happen. Thanks for your patience with a newb.

[Slugger]

Originally Posted by ohpleaseno

Is there any way to limit items to a specific import directory? I have 4 different imported videos directories and I want to call Mediascraper against only one of them to generate a .properties file (and have Mediascraper move it to another import directory). I can limit the search to any imported video without a .properties file, but that gets me a ton of stuff that I don't want to generate .properties files for (home videos and whatnot).

Filename ^= "C:/mydir/"

That test will ensure that the file being processed is in the specified directory.

[ohpleaseno]

I don't see the ^= operator in the user manual. Is that the same as =^ ?

[Slugger]

Originally Posted by ohpleaseno

I don't see the ^= operator in the user manual. Is that the same as =^ ?

Yes, that's just a typo... should be =^

[ohpleaseno]

Originally Posted by Slugger

Yes, that's just a typo... should be =^

I'm trying to pull items that are in an imported video folder and run them through Media Scraper. Here is the ruleset I'm using.

if [($.IsVideoFile{} == true && $.IsTVFile{} == false) && Filename =^ "//WHS/Dumpster/done/TVSCRAPE"]
{
   SCRAPE
}

Nothing is coming up though and I have plenty of files in the folder.

[Slugger]

Use the media debugger (Tools menu) and select a file you expect to work then look at the server logs - it should tell you which test is failing.

[graywolf]

Originally Posted by Slugger

Use the media debugger (Tools menu) and select a file you expect to work then look at the server logs - it should tell you which test is failing.

Yes. The Media Debugger has been a friend to me many many times.
Helps keeping the logic straight or helping to find typos (filename instead of Filename - wouldn't have figured that out without debugger)

[ohpleaseno]

Originally Posted by graywolf

Yes. The Media Debugger has been a friend to me many many times.
Helps keeping the logic straight or helping to find typos (filename instead of Filename - wouldn't have figured that out without debugger)

Yep, just did it for me as well.

Case sensitivity is the death of me in SJQ.

[nyplayer]

Slugger,

Do you know what could be causing the error below.?
Thanks

2010-10-05 06:24:55,015 WARN  [RulesParser]: Unable to invoke method 'GetShowTitle'; return false for test!
2010-10-05 06:24:55,017 WARN  [RulesParser]: Unable to invoke method 'GetShowTitle'; return false for test!
2010-10-05 06:24:55,019 WARN  [RulesParser]: Unable to invoke method 'GetShowEpisode'; return false for test!
2010-10-05 06:24:55,021 WARN  [RulesParser]: Unable to invoke method 'GetPeopleInShow'; return false for test!
2010-10-05 06:24:55,022 WARN  [RulesParser]: Unable to invoke method 'GetPeopleInShow'; return false for test!
2010-10-05 06:24:55,023 WARN  [RulesParser]: Unable to invoke method 'GetPeopleInShow'; return false for test!
2010-10-05 06:24:55,023 WARN  [RulesParser]: Unable to invoke method 'GetPeopleInShow'; return false for test!
2010-10-05 06:24:55,024 WARN  [RulesParser]: Unable to invoke method 'GetPeopleInShow'; return false for test!
2010-10-05 06:24:55,111 WARN  [RulesParser]: Unable to invoke method 'GetShowTitle'; return false for test!
2010-10-05 06:24:55,112 WARN  [RulesParser]: Unable to invoke method 'GetShowTitle'; return false for test!
2010-10-05 06:24:55,113 WARN  [RulesParser]: Unable to invoke method 'GetShowEpisode'; return false for test!
2010-10-05 06:24:55,115 WARN  [RulesParser]: Unable to invoke method 'GetPeopleInShow'; return false for test!
2010-10-05 06:24:55,115 WARN  [RulesParser]: Unable to invoke method 'GetPeopleInShow'; return false for test!
2010-10-05 06:24:55,116 WARN  [RulesParser]: Unable to invoke method 'GetPeopleInShow'; return false for test!
2010-10-05 06:24:55,116 WARN  [RulesParser]: Unable to invoke method 'GetPeopleInShow'; return false for test!
2010-10-05 06:24:55,117 WARN  [RulesParser]: Unable to invoke method 'GetPeopleInShow'; return false for test!
2010-10-05 06:24:55,351 WARN  [RulesParser]: Unable to invoke method 'GetShowTitle'; return false for test!
2010-10-05 06:24:55,353 WARN  [RulesParser]: Unable to invoke method 'GetShowEpisode'; return false for test!

[Slugger]

You're processing a non-media object (system message, perhaps?) and not first using the IsObjMediaFile test.

[phelme]

Originally Posted by doncote0

Everything has been working for a while now and very well. Suddenly my hd-pvr recordings stopped transcoding.

1. SJQ sees the *.ts files
2. SJQ queues them up
3. SJQ adds them to Sage for trancoding
4. The recordings stay there with a status of Waiting...
5. All other Sage and SJQ processes continue normally.

Could you give me a couple of ideas on where to look for the problem? I do not have any blackout times, SJQ adds and resolves the transcode normally,
I have not changed the syntax for the Jobs in a long time.

Server throws no errors, and sjq sees the job as being completed correctly without error, but the jobs stay in Waiting status and do not queue up.

Thanks!

I'm actually getting a lot of this transcoder stuck "Waiting" business lately as well. Not sure what's causing it, there is nothing in the logs, but I believe SJQ sees it as something registered in the TranscodeQueue so it messes up all transcoding for me. It could be something to do with the beta of version 7 I'm running.

[Slugger]

Originally Posted by phelme

I'm actually getting a lot of this transcoder stuck "Waiting" business lately as well. Not sure what's causing it, there is nothing in the logs, but I believe SJQ sees it as something registered in the TranscodeQueue so it messes up all transcoding for me. It could be something to do with the beta of version 7 I'm running.

Check the thread dump of SJQ, is the internal task client dead? If so, then it's crashing for some reason. If not, then the transcode queue size test might be returning unexpected results in the v7 core.

Either way, it won't be fixed, if it's an SJQ issue. I'm well into coding the SJQv4 engine (only) at this point and investigating weird, hard to reproduce bugs in SJQv3 isn't worth it. Easy/quick to fix bugs can still be fixed for v3, but otherwise I'm hoping to have an early beta for SJQv4 in the next few weeks.

[ohpleaseno]

How do I troubleshoot a client not starting a task? I've had six recordings in the queue since 6:30 this morning that have not been picked up by SJQ to process on a client that, up until now, has been churning through recordings in Mediashrink without any difficulty.

[Slugger]

There is a known issue where if you restart the Sage/SJQ server then the task client may lose its connection to the server and require a restart. Look at the clients tab in the UI. Does it list the client? If not then this is probably your issue, try restarting the task client service.

If that's not it, look at the SJQ server logs, it should tell you why it didn't hand a task off to a willing client (not enough resources, etc.).

If that's not, look at the Jetty request logs. Do you see the task client calling in every 5 minutes?

[ohpleaseno]

My SJQ log says nothing about 192.168.3.135 polling the server.

2010-10-12 20:21:10,666 INFO  [SJQServlet]: Checking client '192.168.3.133': 100 resources free.
2010-10-12 20:21:10,667 INFO  [SJQServlet]: Servlet POST request completed [2ms]
2010-10-12 20:21:10,667 INFO  [DataStore]: Thread 'SJQ-LogCleaner' is waiting for an exclusive DataStore connection! [AVAIL=4; MAX=8; WAIT=1385687ms]
2010-10-12 20:21:10,770 INFO  [DataStore]: Flushed 7 log message(s) in 110ms
2010-10-12 20:21:10,770 INFO  [SJQServlet]: Servlet POST request completed [110ms]
2010-10-12 20:21:10,771 INFO  [DataStore]: Thread 'SJQ-LogCleaner' is waiting for an exclusive DataStore connection! [AVAIL=4; MAX=8; WAIT=1385791ms]
2010-10-12 20:21:10,889 INFO  [DataStore]: Flushed 11 log message(s) in 226ms
2010-10-12 20:21:10,889 INFO  [DataStore]: Thread 'SJQ-LogCleaner' is waiting for an exclusive DataStore connection! [AVAIL=5; MAX=8; WAIT=1385909ms]
2010-10-12 20:21:10,889 INFO  [SJQServlet]: Servlet POST request completed [229ms]
2010-10-12 20:21:11,013 INFO  [DataStore]: Flushed 1 log message(s) in 345ms
2010-10-12 20:21:11,013 INFO  [DataStore]: Thread 'SJQ-LogCleaner' is waiting for an exclusive DataStore connection! [AVAIL=6; MAX=8; WAIT=1386033ms]
2010-10-12 20:21:11,013 INFO  [SJQServlet]: Servlet POST request completed [345ms]
2010-10-12 20:21:11,015 INFO  [SJQServlet]: Checking client '192.168.3.133': 50 resources free.
2010-10-12 20:21:11,015 INFO  [SJQServlet]: Client '192.168.3.133' cannot pop a task of type 'SAC': Already running :MAX instances [MAX=1]
2010-10-12 20:21:11,015 INFO  [SJQServlet]: Client '192.168.3.133' cannot pop a task of type 'SCRAPE': Requires 51 resources, but only 50 available.
2010-10-12 20:21:11,016 INFO  [SJQServlet]: Servlet POST request completed [1ms]
2010-10-12 20:21:11,016 INFO  [DataStore]: Thread 'SJQ-LogCleaner' is waiting for an exclusive DataStore connection! [AVAIL=4; MAX=8; WAIT=1386036ms]
2010-10-12 20:21:11,016 INFO  [SJQServlet]: Servlet POST request completed [1ms]
2010-10-12 20:21:11,016 INFO  [DataStore]: Thread 'SJQ-LogCleaner' is waiting for an exclusive DataStore connection! [AVAIL=6; MAX=8; WAIT=1386036ms]
2010-10-12 20:21:11,182 INFO  [DataStore]: Flushed 1 log message(s) in 164ms
2010-10-12 20:21:11,182 INFO  [SJQServlet]: Servlet POST request completed [165ms]
2010-10-12 20:21:11,183 INFO  [DataStore]: Thread 'SJQ-LogCleaner' is waiting for an exclusive DataStore connection! [AVAIL=6; MAX=8; WAIT=1386203ms]
2010-10-12 20:21:11,189 INFO  [SJQServlet]: Servlet POST request completed [0ms]
2010-10-12 20:21:11,189 INFO  [DataStore]: Thread 'SJQ-LogCleaner' is waiting for an exclusive DataStore connection! [AVAIL=6; MAX=8; WAIT=1386209ms]
2010-10-12 20:21:14,591 INFO  [DataStore]: Thread 'SJQ-LogCleaner' is waiting for an exclusive DataStore connection! [AVAIL=5; MAX=8; WAIT=1389611ms]
2010-10-12 20:21:14,665 INFO  [SystemMessageQueueLoader]: Run completed [74ms]
2010-10-12 20:21:14,711 INFO  [DataStore]: Thread 'SJQ-LogCleaner' is waiting for an exclusive DataStore connection! [AVAIL=2; MAX=8; WAIT=1389731ms]
2010-10-12 20:21:14,711 INFO  [SJQServlet]: Servlet POST request completed [1ms]
2010-10-12 20:21:14,713 INFO  [SJQServlet]: Checking client '192.168.3.133': 100 resources free.
2010-10-12 20:21:14,713 INFO  [DataStore]: Thread 'SJQ-LogCleaner' is waiting for an exclusive DataStore connection! [AVAIL=2; MAX=8; WAIT=1389733ms]
2010-10-12 20:21:14,714 INFO  [SJQServlet]: Servlet POST request completed [2ms]
2010-10-12 20:21:14,714 INFO  [DataStore]: Thread 'SJQ-LogCleaner' is waiting for an exclusive DataStore connection! [AVAIL=3; MAX=8; WAIT=1389734ms]
2010-10-12 20:21:14,748 INFO  [DataStore]: Thread 'SJQ-LogCleaner' is waiting for an exclusive DataStore connection! [AVAIL=3; MAX=8; WAIT=1389768ms]
2010-10-12 20:21:14,951 INFO  [DataStore]: Flushed 11 log message(s) in 244ms
2010-10-12 20:21:14,951 INFO  [SJQServlet]: Servlet POST request completed [244ms]
2010-10-12 20:21:14,952 INFO  [DataStore]: Thread 'SJQ-LogCleaner' is waiting for an exclusive DataStore connection! [AVAIL=4; MAX=8; WAIT=1389972ms]
2010-10-12 20:21:15,101 INFO  [DataStore]: Flushed 1 log message(s) in 386ms
2010-10-12 20:21:15,101 INFO  [DataStore]: Thread 'SJQ-LogCleaner' is waiting for an exclusive DataStore connection! [AVAIL=5; MAX=8; WAIT=1390121ms]
2010-10-12 20:21:15,101 INFO  [SJQServlet]: Servlet POST request completed [386ms]
2010-10-12 20:21:15,104 INFO  [SJQServlet]: Checking client '192.168.3.133': 50 resources free.
2010-10-12 20:21:15,105 INFO  [SJQServlet]: Client '192.168.3.133' cannot pop a task of type 'SAC': Already running :MAX instances [MAX=1]
2010-10-12 20:21:15,105 INFO  [SJQServlet]: Client '192.168.3.133' cannot pop a task of type 'SCRAPE': Requires 51 resources, but only 50 available.
2010-10-12 20:21:15,105 INFO  [SJQServlet]: Servlet POST request completed [2ms]
2010-10-12 20:21:15,105 INFO  [SJQServlet]: Servlet POST request completed [1ms]
2010-10-12 20:21:15,106 INFO  [DataStore]: Thread 'SJQ-LogCleaner' is waiting for an exclusive DataStore connection! [AVAIL=5; MAX=8; WAIT=1390126ms]
2010-10-12 20:21:15,212 INFO  [DataStore]: Flushed 7 log message(s) in 506ms
2010-10-12 20:21:15,213 INFO  [SJQServlet]: Servlet POST request completed [507ms]
2010-10-12 20:21:15,213 INFO  [DataStore]: Thread 'SJQ-LogCleaner' is waiting for an exclusive DataStore connection! [AVAIL=5; MAX=8; WAIT=1390233ms]
2010-10-12 20:21:15,363 INFO  [DataStore]: Flushed 1 log message(s) in 255ms
2010-10-12 20:21:15,364 INFO  [SJQServlet]: Servlet POST request completed [257ms]
2010-10-12 20:21:15,364 INFO  [DataStore]: Thread 'SJQ-LogCleaner' is waiting for an exclusive DataStore connection! [AVAIL=6; MAX=8; WAIT=1390384ms]
2010-10-12 20:21:15,367 INFO  [SJQServlet]: Servlet POST request completed [0ms]
2010-10-12 20:21:15,367 INFO  [DataStore]: Thread 'SJQ-LogCleaner' is waiting for an exclusive DataStore connection! [AVAIL=6; MAX=8; WAIT=1390387ms]
2010-10-12 20:21:18,929 INFO  [SJQServlet]: Servlet POST request completed [1ms]
2010-10-12 20:21:18,929 INFO  [DataStore]: Thread 'SJQ-LogCleaner' is waiting for an exclusive DataStore connection! [AVAIL=6; MAX=8; WAIT=1393949ms]
2010-10-12 20:21:19,428 INFO  [SJQServlet]: Servlet POST request completed [17ms]
2010-10-12 20:21:19,428 INFO  [DataStore]: Thread 'SJQ-LogCleaner' is waiting for an exclusive DataStore connection! [AVAIL=5; MAX=8; WAIT=1394448ms]
2010-10-12 20:21:19,431 INFO  [SJQServlet]: Servlet POST request completed [10ms]
2010-10-12 20:21:19,431 INFO  [DataStore]: Thread 'SJQ-LogCleaner' is waiting for an exclusive DataStore connection! [AVAIL=6; MAX=8; WAIT=1394451ms]
2010-10-12 20:21:19,617 INFO  [SJQServlet]: Servlet POST request completed [0ms]
2010-10-12 20:21:19,617 INFO  [DataStore]: Thread 'SJQ-LogCleaner' is waiting for an exclusive DataStore connection! [AVAIL=4; MAX=8; WAIT=1394637ms]
2010-10-12 20:21:19,618 INFO  [SJQServlet]: Checking client '192.168.3.133': 100 resources free.
2010-10-12 20:21:19,618 INFO  [SJQServlet]: Servlet POST request completed [1ms]
2010-10-12 20:21:19,618 INFO  [DataStore]: Thread 'SJQ-LogCleaner' is waiting for an exclusive DataStore connection! [AVAIL=4; MAX=8; WAIT=1394638ms]
2010-10-12 20:21:19,740 INFO  [DataStore]: Flushed 11 log message(s) in 127ms
2010-10-12 20:21:19,740 INFO  [SJQServlet]: Servlet POST request completed [128ms]
2010-10-12 20:21:19,740 INFO  [DataStore]: Thread 'SJQ-LogCleaner' is waiting for an exclusive DataStore connection! [AVAIL=4; MAX=8; WAIT=1394760ms]
2010-10-12 20:21:19,857 INFO  [DataStore]: Flushed 1 log message(s) in 238ms
2010-10-12 20:21:19,857 INFO  [DataStore]: Thread 'SJQ-LogCleaner' is waiting for an exclusive DataStore connection! [AVAIL=5; MAX=8; WAIT=1394877ms]
2010-10-12 20:21:19,857 INFO  [SJQServlet]: Servlet POST request completed [238ms]
2010-10-12 20:21:19,859 INFO  [SJQServlet]: Checking client '192.168.3.133': 50 resources free.
2010-10-12 20:21:19,859 INFO  [SJQServlet]: Client '192.168.3.133' cannot pop a task of type 'SAC': Already running :MAX instances [MAX=1]
2010-10-12 20:21:19,859 INFO  [SJQServlet]: Servlet POST request completed [1ms]
2010-10-12 20:21:19,859 INFO  [SJQServlet]: Client '192.168.3.133' cannot pop a task of type 'SCRAPE': Requires 51 resources, but only 50 available.
2010-10-12 20:21:19,859 INFO  [DataStore]: Thread 'SJQ-LogCleaner' is waiting for an exclusive DataStore connection! [AVAIL=4; MAX=8; WAIT=1394879ms]
2010-10-12 20:21:19,859 INFO  [SJQServlet]: Servlet POST request completed [1ms]
2010-10-12 20:21:19,859 INFO  [DataStore]: Thread 'SJQ-LogCleaner' is waiting for an exclusive DataStore connection! [AVAIL=5; MAX=8; WAIT=1394879ms]
2010-10-12 20:21:19,972 INFO  [DataStore]: Flushed 1 log message(s) in 112ms
2010-10-12 20:21:19,973 INFO  [DataStore]: Thread 'SJQ-LogCleaner' is waiting for an exclusive DataStore connection! [AVAIL=5; MAX=8; WAIT=1394993ms]
2010-10-12 20:21:19,973 INFO  [SJQServlet]: Servlet POST request completed [113ms]
2010-10-12 20:21:19,976 INFO  [SJQServlet]: Servlet POST request completed [0ms]
2010-10-12 20:21:19,977 INFO  [DataStore]: Thread 'SJQ-LogCleaner' is waiting for an exclusive DataStore connection! [AVAIL=5; MAX=8; WAIT=1394996ms]
2010-10-12 20:21:20,262 INFO  [DataStore]: Flushed 7 log message(s) in 649ms
2010-10-12 20:21:20,262 INFO  [DataStore]: Thread 'SJQ-LogCleaner' is waiting for an exclusive DataStore connection! [AVAIL=6; MAX=8; WAIT=1395282ms]
2010-10-12 20:21:20,262 INFO  [SJQServlet]: Servlet POST request completed [649ms]
2010-10-12 20:21:24,100 INFO  [SJQServlet]: Servlet POST request completed [1ms]
2010-10-12 20:21:24,100 INFO  [DataStore]: Thread 'SJQ-LogCleaner' is waiting for an exclusive DataStore connection! [AVAIL=6; MAX=8; WAIT=1399120ms]
2010-10-12 20:21:24,101 INFO  [SJQServlet]: Checking client '192.168.3.133': 100 resources free.
2010-10-12 20:21:24,101 INFO  [SJQServlet]: Servlet POST request completed [0ms]
2010-10-12 20:21:24,102 INFO  [DataStore]: Thread 'SJQ-LogCleaner' is waiting for an exclusive DataStore connection! [AVAIL=6; MAX=8; WAIT=1399122ms]
2010-10-12 20:21:24,247 INFO  [DataStore]: Flushed 1 log message(s) in 144ms
2010-10-12 20:21:24,247 INFO  [DataStore]: Thread 'SJQ-LogCleaner' is waiting for an exclusive DataStore connection! [AVAIL=4; MAX=8; WAIT=1399267ms]
2010-10-12 20:21:24,248 INFO  [SJQServlet]: Servlet POST request completed [145ms]
2010-10-12 20:21:24,249 INFO  [SJQServlet]: Checking client '192.168.3.133': 50 resources free.
2010-10-12 20:21:24,249 INFO  [SJQServlet]: Client '192.168.3.133' cannot pop a task of type 'SAC': Already running :MAX instances [MAX=1]
2010-10-12 20:21:24,249 INFO  [SJQServlet]: Client '192.168.3.133' cannot pop a task of type 'SCRAPE': Requires 51 resources, but only 50 available.
2010-10-12 20:21:24,250 INFO  [SJQServlet]: Servlet POST request completed [1ms]
2010-10-12 20:21:24,250 INFO  [DataStore]: Thread 'SJQ-LogCleaner' is waiting for an exclusive DataStore connection! [AVAIL=3; MAX=8; WAIT=1399270ms]
2010-10-12 20:21:24,251 INFO  [SJQServlet]: Servlet POST request completed [1ms]
2010-10-12 20:21:24,251 INFO  [DataStore]: Thread 'SJQ-LogCleaner' is waiting for an exclusive DataStore connection! [AVAIL=4; MAX=8; WAIT=1399271ms]
2010-10-12 20:21:24,379 INFO  [DataStore]: Flushed 11 log message(s) in 267ms
2010-10-12 20:21:24,379 INFO  [DataStore]: Thread 'SJQ-LogCleaner' is waiting for an exclusive DataStore connection! [AVAIL=4; MAX=8; WAIT=1399399ms]
2010-10-12 20:21:24,379 INFO  [SJQServlet]: Servlet POST request completed [267ms]
2010-10-12 20:21:24,518 INFO  [DataStore]: Flushed 1 log message(s) in 265ms
2010-10-12 20:21:24,518 INFO  [DataStore]: Thread 'SJQ-LogCleaner' is waiting for an exclusive DataStore connection! [AVAIL=5; MAX=8; WAIT=1399538ms]
2010-10-12 20:21:24,518 INFO  [SJQServlet]: Servlet POST request completed [266ms]
2010-10-12 20:21:24,525 INFO  [SJQServlet]: Servlet POST request completed [1ms]
2010-10-12 20:21:24,525 INFO  [DataStore]: Thread 'SJQ-LogCleaner' is waiting for an exclusive DataStore connection! [AVAIL=5; MAX=8; WAIT=1399545ms]
2010-10-12 20:21:24,679 INFO  [DataStore]: Flushed 7 log message(s) in 566ms
2010-10-12 20:21:24,680 INFO  [SJQServlet]: Servlet POST request completed [567ms]
2010-10-12 20:21:24,680 INFO  [DataStore]: Thread 'SJQ-LogCleaner' is waiting for an exclusive DataStore connection! [AVAIL=6; MAX=8; WAIT=1399700ms]
2010-10-12 20:21:25,553 INFO  [SJQServlet]: Servlet POST request completed [1ms]
2010-10-12 20:21:25,553 INFO  [DataStore]: Thread 'SJQ-LogCleaner' is waiting for an exclusive DataStore connection! [AVAIL=6; MAX=8; WAIT=1400573ms]
2010-10-12 20:21:25,563 INFO  [SJQServlet]: Servlet POST request completed [1ms]
2010-10-12 20:21:25,563 INFO  [DataStore]: Thread 'SJQ-LogCleaner' is waiting for an exclusive DataStore connection! [AVAIL=6; MAX=8; WAIT=1400583ms]
2010-10-12 20:21:28,176 INFO  [DataStore]: Thread 'SJQ-LogCleaner' is waiting for an exclusive DataStore connection! [AVAIL=4; MAX=8; WAIT=1403196ms]
2010-10-12 20:21:28,177 INFO  [SJQServlet]: Servlet POST request completed [1ms]
2010-10-12 20:21:28,177 INFO  [DataStore]: Thread 'SJQ-LogCleaner' is waiting for an exclusive DataStore connection! [AVAIL=5; MAX=8; WAIT=1403197ms]
2010-10-12 20:21:28,177 INFO  [SJQServlet]: Checking client '192.168.3.133': 100 resources free.
2010-10-12 20:21:28,178 INFO  [SJQServlet]: Servlet POST request completed [1ms]
2010-10-12 20:21:28,178 INFO  [DataStore]: Thread 'SJQ-LogCleaner' is waiting for an exclusive DataStore connection! [AVAIL=4; MAX=8; WAIT=1403198ms]
2010-10-12 20:21:28,350 INFO  [DataStore]: Flushed 7 log message(s) in 176ms
2010-10-12 20:21:28,351 INFO  [SJQServlet]: Servlet POST request completed [178ms]
2010-10-12 20:21:28,351 INFO  [DataStore]: Thread 'SJQ-LogCleaner' is waiting for an exclusive DataStore connection! [AVAIL=4; MAX=8; WAIT=1403371ms]
2010-10-12 20:21:28,486 INFO  [DataStore]: Flushed 11 log message(s) in 308ms
2010-10-12 20:21:28,486 INFO  [SJQServlet]: Servlet POST request completed [308ms]
2010-10-12 20:21:28,487 INFO  [DataStore]: Thread 'SJQ-LogCleaner' is waiting for an exclusive DataStore connection! [AVAIL=5; MAX=8; WAIT=1403507ms]
2010-10-12 20:21:28,645 INFO  [DataStore]: Flushed 1 log message(s) in 465ms
2010-10-12 20:21:28,645 INFO  [DataStore]: Thread 'SJQ-LogCleaner' is waiting for an exclusive DataStore connection! [AVAIL=6; MAX=8; WAIT=1403665ms]
2010-10-12 20:21:28,645 INFO  [SJQServlet]: Servlet POST request completed [466ms]
2010-10-12 20:21:28,646 INFO  [SJQServlet]: Checking client '192.168.3.133': 50 resources free.
2010-10-12 20:21:28,647 INFO  [SJQServlet]: Client '192.168.3.133' cannot pop a task of type 'SAC': Already running :MAX instances [MAX=1]
2010-10-12 20:21:28,647 INFO  [SJQServlet]: Client '192.168.3.133' cannot pop a task of type 'SCRAPE': Requires 51 resources, but only 50 available.
2010-10-12 20:21:28,647 INFO  [DataStore]: Thread 'SJQ-LogCleaner' is waiting for an exclusive DataStore connection! [AVAIL=4; MAX=8; WAIT=1403667ms]
2010-10-12 20:21:28,647 INFO  [SJQServlet]: Servlet POST request completed [1ms]
2010-10-12 20:21:28,647 INFO  [SJQServlet]: Servlet POST request completed [1ms]
2010-10-12 20:21:28,647 INFO  [DataStore]: Thread 'SJQ-LogCleaner' is waiting for an exclusive DataStore connection! [AVAIL=6; MAX=8; WAIT=1403667ms]
2010-10-12 20:21:28,744 INFO  [DataStore]: Flushed 1 log message(s) in 96ms
2010-10-12 20:21:28,745 INFO  [SJQServlet]: Servlet POST request completed [98ms]
2010-10-12 20:21:28,745 INFO  [DataStore]: Thread 'SJQ-LogCleaner' is waiting for an exclusive DataStore connection! [AVAIL=6; MAX=8; WAIT=1403765ms]
2010-10-12 20:21:28,747 INFO  [SJQServlet]: Servlet POST request completed [0ms]
2010-10-12 20:21:28,747 INFO  [DataStore]: Thread 'SJQ-LogCleaner' is waiting for an exclusive DataStore connection! [AVAIL=6; MAX=8; WAIT=1403767ms]
2010-10-12 20:21:30,216 INFO  [SJQServlet]: Servlet POST request completed [106ms]
2010-10-12 20:21:30,216 INFO  [DataStore]: Thread 'SJQ-LogCleaner' is waiting for an exclusive DataStore connection! [AVAIL=6; MAX=8; WAIT=1405236ms]
2010-10-12 20:21:32,820 INFO  [SJQServlet]: Servlet POST request completed [1ms]
2010-10-12 20:21:32,821 INFO  [DataStore]: Thread 'SJQ-LogCleaner' is waiting for an exclusive DataStore connection! [AVAIL=4; MAX=8; WAIT=1407841ms]
2010-10-12 20:21:32,823 INFO  [SJQServlet]: Checking client '192.168.3.133': 100 resources free.
2010-10-12 20:21:32,824 INFO  [SJQServlet]: Servlet POST request completed [2ms]
2010-10-12 20:21:32,824 INFO  [DataStore]: Thread 'SJQ-LogCleaner' is waiting for an exclusive DataStore connection! [AVAIL=4; MAX=8; WAIT=1407844ms]
2010-10-12 20:21:32,949 INFO  [DataStore]: Flushed 7 log message(s) in 133ms
2010-10-12 20:21:32,950 INFO  [SJQServlet]: Servlet POST request completed [135ms]
2010-10-12 20:21:32,950 INFO  [DataStore]: Thread 'SJQ-LogCleaner' is waiting for an exclusive DataStore connection! [AVAIL=4; MAX=8; WAIT=1407970ms]
2010-10-12 20:21:33,183 INFO  [DataStore]: Flushed 11 log message(s) in 365ms
2010-10-12 20:21:33,183 INFO  [DataStore]: Thread 'SJQ-LogCleaner' is waiting for an exclusive DataStore connection! [AVAIL=5; MAX=8; WAIT=1408203ms]
2010-10-12 20:21:33,183 INFO  [SJQServlet]: Servlet POST request completed [365ms]
2010-10-12 20:21:33,409 INFO  [DataStore]: Flushed 1 log message(s) in 584ms
2010-10-12 20:21:33,409 INFO  [DataStore]: Thread 'SJQ-LogCleaner' is waiting for an exclusive DataStore connection! [AVAIL=6; MAX=8; WAIT=1408429ms]
2010-10-12 20:21:33,409 INFO  [SJQServlet]: Servlet POST request completed [584ms]
2010-10-12 20:21:33,411 INFO  [SJQServlet]: Checking client '192.168.3.133': 50 resources free.
2010-10-12 20:21:33,411 INFO  [SJQServlet]: Client '192.168.3.133' cannot pop a task of type 'SAC': Already running :MAX instances [MAX=1]
2010-10-12 20:21:33,411 INFO  [SJQServlet]: Client '192.168.3.133' cannot pop a task of type 'SCRAPE': Requires 51 resources, but only 50 available.
2010-10-12 20:21:33,411 INFO  [SJQServlet]: Servlet POST request completed [1ms]
2010-10-12 20:21:33,411 INFO  [DataStore]: Thread 'SJQ-LogCleaner' is waiting for an exclusive DataStore connection! [AVAIL=4; MAX=8; WAIT=1408431ms]
2010-10-12 20:21:33,412 INFO  [SJQServlet]: Servlet POST request completed [1ms]
2010-10-12 20:21:33,412 INFO  [DataStore]: Thread 'SJQ-LogCleaner' is waiting for an exclusive DataStore connection! [AVAIL=6; MAX=8; WAIT=1408432ms]
2010-10-12 20:21:33,526 INFO  [DataStore]: Flushed 1 log message(s) in 113ms
2010-10-12 20:21:33,527 INFO  [SJQServlet]: Servlet POST request completed [114ms]
2010-10-12 20:21:33,527 INFO  [DataStore]: Thread 'SJQ-LogCleaner' is waiting for an exclusive DataStore connection! [AVAIL=6; MAX=8; WAIT=1408547ms]
2010-10-12 20:21:33,531 INFO  [SJQServlet]: Servlet POST request completed [0ms]
2010-10-12 20:21:33,531 INFO  [DataStore]: Thread 'SJQ-LogCleaner' is waiting for an exclusive DataStore connection! [AVAIL=6; MAX=8; WAIT=1408551ms]
2010-10-12 20:21:37,038 INFO  [SJQServlet]: Servlet POST request completed [0ms]
2010-10-12 20:21:37,038 INFO  [DataStore]: Thread 'SJQ-LogCleaner' is waiting for an exclusive DataStore connection! [AVAIL=4; MAX=8; WAIT=1412058ms]
2010-10-12 20:21:37,040 INFO  [SJQServlet]: Checking client '192.168.3.133': 100 resources free.
2010-10-12 20:21:37,040 INFO  [SJQServlet]: Servlet POST request completed [1ms]
2010-10-12 20:21:37,040 INFO  [DataStore]: Thread 'SJQ-LogCleaner' is waiting for an exclusive DataStore connection! [AVAIL=4; MAX=8; WAIT=1412060ms]
2010-10-12 20:21:37,182 INFO  [DataStore]: Flushed 7 log message(s) in 148ms
2010-10-12 20:21:37,182 INFO  [DataStore]: Thread 'SJQ-LogCleaner' is waiting for an exclusive DataStore connection! [AVAIL=4; MAX=8; WAIT=1412202ms]
2010-10-12 20:21:37,182 INFO  [SJQServlet]: Servlet POST request completed [148ms]
2010-10-12 20:21:37,284 INFO  [DataStore]: Flushed 1 log message(s) in 243ms
2010-10-12 20:21:37,284 INFO  [SJQServlet]: Servlet POST request completed [243ms]
2010-10-12 20:21:37,284 INFO  [DataStore]: Thread 'SJQ-LogCleaner' is waiting for an exclusive DataStore connection! [AVAIL=5; MAX=8; WAIT=1412304ms]
2010-10-12 20:21:37,285 INFO  [SJQServlet]: Checking client '192.168.3.133': 50 resources free.
2010-10-12 20:21:37,285 INFO  [SJQServlet]: Client '192.168.3.133' cannot pop a task of type 'SAC': Already running :MAX instances [MAX=1]
2010-10-12 20:21:37,285 INFO  [SJQServlet]: Client '192.168.3.133' cannot pop a task of type 'SCRAPE': Requires 51 resources, but only 50 available.
2010-10-12 20:21:37,285 INFO  [SJQServlet]: Servlet POST request completed [1ms]
2010-10-12 20:21:37,285 INFO  [DataStore]: Thread 'SJQ-LogCleaner' is waiting for an exclusive DataStore connection! [AVAIL=5; MAX=8; WAIT=1412305ms]
2010-10-12 20:21:37,286 INFO  [DataStore]: Thread 'SJQ-LogCleaner' is waiting for an exclusive DataStore connection! [AVAIL=4; MAX=8; WAIT=1412306ms]
2010-10-12 20:21:37,286 INFO  [SJQServlet]: Servlet POST request completed [1ms]
2010-10-12 20:21:37,286 INFO  [DataStore]: Thread 'SJQ-LogCleaner' is waiting for an exclusive DataStore connection! [AVAIL=5; MAX=8; WAIT=1412306ms]
2010-10-12 20:21:37,390 INFO  [DataStore]: Flushed 11 log message(s) in 356ms
2010-10-12 20:21:37,391 INFO  [SJQServlet]: Servlet POST request completed [357ms]
2010-10-12 20:21:37,391 INFO  [DataStore]: Thread 'SJQ-LogCleaner' is waiting for an exclusive DataStore connection! [AVAIL=5; MAX=8; WAIT=1412411ms]
2010-10-12 20:21:37,499 INFO  [DataStore]: Flushed 1 log message(s) in 212ms
2010-10-12 20:21:37,500 INFO  [SJQServlet]: Servlet POST request completed [213ms]
2010-10-12 20:21:37,500 INFO  [DataStore]: Thread 'SJQ-LogCleaner' is waiting for an exclusive DataStore connection! [AVAIL=6; MAX=8; WAIT=1412520ms]
2010-10-12 20:21:37,506 INFO  [SJQServlet]: Servlet POST request completed [0ms]
2010-10-12 20:21:37,507 INFO  [DataStore]: Thread 'SJQ-LogCleaner' is waiting for an exclusive DataStore connection! [AVAIL=6; MAX=8; WAIT=1412527ms]
2010-10-12 20:21:41,512 INFO  [DataStore]: Thread 'SJQ-LogCleaner' is waiting for an exclusive DataStore connection! [AVAIL=3; MAX=8; WAIT=1416532ms]
2010-10-12 20:21:41,512 INFO  [SJQServlet]: Servlet POST request completed [1ms]
2010-10-12 20:21:41,512 INFO  [DataStore]: Thread 'SJQ-LogCleaner' is waiting for an exclusive DataStore connection! [AVAIL=4; MAX=8; WAIT=1416532ms]
2010-10-12 20:21:41,513 INFO  [SJQServlet]: Checking client '192.168.3.133': 100 resources free.
2010-10-12 20:21:41,513 INFO  [SJQServlet]: Servlet POST request completed [0ms]
2010-10-12 20:21:41,513 INFO  [DataStore]: Thread 'SJQ-LogCleaner' is waiting for an exclusive DataStore connection! [AVAIL=4; MAX=8; WAIT=1416533ms]
2010-10-12 20:21:41,705 INFO  [DataStore]: Flushed 11 log message(s) in 201ms
2010-10-12 20:21:41,705 INFO  [SJQServlet]: Servlet POST request completed [202ms]
2010-10-12 20:21:41,706 INFO  [DataStore]: Thread 'SJQ-LogCleaner' is waiting for an exclusive DataStore connection! [AVAIL=5; MAX=8; WAIT=1416726ms]
2010-10-12 20:21:41,805 INFO  [DataStore]: Flushed 7 log message(s) in 300ms
2010-10-12 20:21:41,806 INFO  [DataStore]: Thread 'SJQ-LogCleaner' is waiting for an exclusive DataStore connection! [AVAIL=6; MAX=8; WAIT=1416826ms]
2010-10-12 20:21:41,806 INFO  [SJQServlet]: Servlet POST request completed [302ms]
2010-10-12 20:22:14,907 INFO  [DataStore]: Thread 'SJQ-LogCleaner' is waiting for an exclusive DataStore connection! [AVAIL=6; MAX=8; WAIT=1449927ms]
2010-10-12 20:22:14,908 WARN  [RulesParser]: Unable to invoke method 'IsVideoFile'; return false for test!
2010-10-12 20:22:14,908 WARN  [RulesParser]: Unable to invoke method 'IsVideoFile'; return false for test!
2010-10-12 20:22:14,908 WARN  [RulesParser]: Unable to invoke method 'IsVideoFile'; return false for test!
2010-10-12 20:22:14,908 WARN  [RulesParser]: Unable to invoke method 'IsVideoFile'; return false for test!
2010-10-12 20:22:15,077 WARN  [RulesParser]: Unable to invoke method 'IsVideoFile'; return false for test!
2010-10-12 20:22:15,078 WARN  [RulesParser]: Unable to invoke method 'IsVideoFile'; return false for test!
2010-10-12 20:22:15,080 WARN  [RulesParser]: Unable to invoke method 'IsVideoFile'; return false for test!
2010-10-12 20:22:15,081 WARN  [RulesParser]: Unable to invoke method 'IsVideoFile'; return false for test!
2010-10-12 20:22:15,084 WARN  [RulesParser]: Unable to invoke method 'IsVideoFile'; return false for test!
2010-10-12 20:22:15,084 WARN  [RulesParser]: Unable to invoke method 'IsVideoFile'; return false for test!
2010-10-12 20:22:15,087 WARN  [RulesParser]: Unable to invoke method 'IsVideoFile'; return false for test!
2010-10-12 20:22:15,088 WARN  [RulesParser]: Unable to invoke method 'IsVideoFile'; return false for test!
2010-10-12 20:22:15,090 WARN  [RulesParser]: Unable to invoke method 'IsVideoFile'; return false for test!
2010-10-12 20:22:15,091 WARN  [RulesParser]: Unable to invoke method 'IsVideoFile'; return false for test!
2010-10-12 20:22:15,094 WARN  [RulesParser]: Unable to invoke method 'IsVideoFile'; return false for test!
2010-10-12 20:22:15,094 WARN  [RulesParser]: Unable to invoke method 'IsVideoFile'; return false for test!
2010-10-12 20:22:15,097 WARN  [RulesParser]: Unable to invoke method 'IsVideoFile'; return false for test!
2010-10-12 20:22:15,098 WARN  [RulesParser]: Unable to invoke method 'IsVideoFile'; return false for test!
2010-10-12 20:22:15,101 WARN  [RulesParser]: Unable to invoke method 'IsVideoFile'; return false for test!
2010-10-12 20:22:15,101 WARN  [RulesParser]: Unable to invoke method 'IsVideoFile'; return false for test!
2010-10-12 20:22:15,104 WARN  [RulesParser]: Unable to invoke method 'IsVideoFile'; return false for test!
2010-10-12 20:22:15,105 WARN  [RulesParser]: Unable to invoke method 'IsVideoFile'; return false for test!
2010-10-12 20:22:15,108 WARN  [RulesParser]: Unable to invoke method 'IsVideoFile'; return false for test!
2010-10-12 20:22:15,109 WARN  [RulesParser]: Unable to invoke method 'IsVideoFile'; return false for test!
2010-10-12 20:22:15,111 WARN  [RulesParser]: Unable to invoke method 'IsVideoFile'; return false for test!
2010-10-12 20:22:15,112 WARN  [RulesParser]: Unable to invoke method 'IsVideoFile'; return false for test!
2010-10-12 20:22:15,115 WARN  [RulesParser]: Unable to invoke method 'IsVideoFile'; return false for test!
2010-10-12 20:22:15,116 WARN  [RulesParser]: Unable to invoke method 'IsVideoFile'; return false for test!
2010-10-12 20:22:15,117 WARN  [RulesParser]: Unable to invoke method 'IsVideoFile'; return false for test!
2010-10-12 20:22:15,118 WARN  [RulesParser]: Unable to invoke method 'IsVideoFile'; return false for test!
2010-10-12 20:22:15,121 WARN  [RulesParser]: Unable to invoke method 'IsVideoFile'; return false for test!
2010-10-12 20:22:15,122 WARN  [RulesParser]: Unable to invoke method 'IsVideoFile'; return false for test!
2010-10-12 20:22:15,124 WARN  [RulesParser]: Unable to invoke method 'IsVideoFile'; return false for test!
2010-10-12 20:22:15,125 WARN  [RulesParser]: Unable to invoke method 'IsVideoFile'; return false for test!
2010-10-12 20:22:15,128 WARN  [RulesParser]: Unable to invoke method 'IsVideoFile'; return false for test!
2010-10-12 20:22:15,129 WARN  [RulesParser]: Unable to invoke method 'IsVideoFile'; return false for test!
2010-10-12 20:22:15,132 WARN  [RulesParser]: Unable to invoke method 'IsVideoFile'; return false for test!
2010-10-12 20:22:15,133 WARN  [RulesParser]: Unable to invoke method 'IsVideoFile'; return false for test!
2010-10-12 20:22:15,135 WARN  [RulesParser]: Unable to invoke method 'IsVideoFile'; return false for test!
2010-10-12 20:22:15,136 WARN  [RulesParser]: Unable to invoke method 'IsVideoFile'; return false for test!
2010-10-12 20:22:15,139 WARN  [RulesParser]: Unable to invoke method 'IsVideoFile'; return false for test!
2010-10-12 20:22:15,140 WARN  [RulesParser]: Unable to invoke method 'IsVideoFile'; return false for test!
2010-10-12 20:22:15,143 WARN  [RulesParser]: Unable to invoke method 'IsVideoFile'; return false for test!
2010-10-12 20:22:15,177 WARN  [RulesParser]: Unable to invoke method 'IsVideoFile'; return false for test!
2010-10-12 20:24:16,215 INFO  [SystemMessageQueueLoader]: Run completed [349ms]
2010-10-12 20:24:16,328 INFO  [DataStore]: Thread 'SJQ-LogCleaner' is waiting for an exclusive DataStore connection! [AVAIL=5; MAX=8; WAIT=1571348ms]
2010-10-12 20:24:16,746 WARN  [DataStore]: DataStore pool timeout expired! '29892897@qtp-4009580-4' did not return connection within 30 seconds!  Adding a replacement connection to the pool.
2010-10-12 20:24:16,747 INFO  [DataStore]: Thread 'SJQ-LogCleaner' is waiting for an exclusive DataStore connection! [AVAIL=6; MAX=8; WAIT=1571767ms]

2010-10-12 20:22:15,143 WARN [RulesParser]: Unable to invoke method 'IsVideoFile'; return false for test! shows up about 1000 times

[Slugger]

Restart the task client service on .135; it probably lost its connection to the server at some point and when it does, it dies. The 'unable to invoke errors' are usually a result of not using an IsObjMediaFile == true at the beginning of an if [] block and so when SJQ is processing system messages it ends up trying to test if the system message is a video file and that's not a valid check for a sys msg, hence the errors.

[ohpleaseno]

So when I stop 135 (and I've done it a few times), it still shows up in my active client list.

edit: I let it sit for a few more minutes and it eventually purged itself from the list. I purged my other two clients after it came back on line and they still show up 5 minutes later.

[Slugger]

Once they restart the tasks should start being assigned, no? If not, then you may need to restart the SJQ server. If restarting the server fixes the issue then you've discovered a bug that hasn't been discovered (or at least reported) to me before now. Unfortunately, I'm pretty much committed to SJQv4 development so tracking down such a bug in the server code probably isn't going to happen at this point, unless I can easily reproduce it locally. The good news is that the v4 code base is a complete rewrite from scratch and so any such bug in the server should not carry over to v4.