Plugin: Sage Job Queue (SJQ) v3

[Fuzzy]

Originally Posted by rmac321

First - thanks for the great tool. I've finally decided to invest the time to learn to use SJQ and am having great success automating a bunch of stuff.

The question - Is there a test for whether a specific recording is being watched? If I understand correctly, the test "IsViewingMedia" is actually a test for whether anything at all is currently being watched. It would be nice to have a quick test for whether a specific file is being watched before attempting a relink or a move. I took a quick look at the Sage API listing, but I don't see anything obvious like "IsBeingWatched"

I don't think sage itself even has this capability. The sage server has no idea whether a client is viewing a file or not. All it gets is updated watched points when a UI instance has changed the watched status of a file (when stopped, it'll update the watched point to the current point... and flag completely watched if at the end).

[skiingwiz]

Originally Posted by rmac321

The question - Is there a test for whether a specific recording is being watched? If I understand correctly, the test "IsViewingMedia" is actually a test for whether anything at all is currently being watched. It would be nice to have a quick test for whether a specific file is being watched before attempting a relink or a move. I took a quick look at the Sage API listing, but I don't see anything obvious like "IsBeingWatched"

You can use MediaPlayerAPI.GetCurrentMediaFile() to determine what each extender is watching (by calling it with the extender's UI Context). It gets trickier if you have full clients. In fact, you can't do it at all for full clients without something like stuckless's remote APIs installed.

[Slugger]

Originally Posted by rmac321

FWIW - the SJQ User's Guide on the googlecode site won't load today.

Yes, had to take it offline for awhile. I created the PDF version and posted it in the downloads section. That PDF is the final version of the SJQ 3.0.x User's Guide.

[Slugger]

Originally Posted by rmac321

First - thanks for the great tool. I've finally decided to invest the time to learn to use SJQ and am having great success automating a bunch of stuff.

The question - Is there a test for whether a specific recording is being watched? If I understand correctly, the test "IsViewingMedia" is actually a test for whether anything at all is currently being watched. It would be nice to have a quick test for whether a specific file is being watched before attempting a relink or a move. I took a quick look at the Sage API listing, but I don't see anything obvious like "IsBeingWatched"

Originally Posted by Fuzzy

I don't think sage itself even has this capability. The sage server has no idea whether a client is viewing a file or not. All it gets is updated watched points when a UI instance has changed the watched status of a file (when stopped, it'll update the watched point to the current point... and flag completely watched if at the end).

Originally Posted by skiingwiz

You can use MediaPlayerAPI.GetCurrentMediaFile() to determine what each extender is watching (by calling it with the extender's UI Context). It gets trickier if you have full clients. In fact, you can't do it at all for full clients without something like stuckless's remote APIs installed.

This about covers it. I've contemplated adding this kind of test in the past, but, at best, such a test is misleading because the server cannot query a client about what it's watching. So the test could only tell you if the server or an extender/placeshifter is watching the file. If a client were watching it the test would return false even though it should return true. To save the confusion, I never bothered adding a test for it.

[rmac321]

Originally Posted by Slugger

This about covers it. I've contemplated adding this kind of test in the past, but, at best, such a test is misleading because the server cannot query a client about what it's watching. So the test could only tell you if the server or an extender/placeshifter is watching the file. If a client were watching it the test would return false even though it should return true. To save the confusion, I never bothered adding a test for it.

Thanks for the quick response. For basic file moving, I use the "IsViewingMedia" and "IsSomethingRecording" which makes sure files only move around during down-time - which is fine. I was basically looking ahead to the possibility that someone might be viewing a file that happens to also be in the queue to be shrunk. I had hoped I could add an "IsWatchingThisExactFile" test befoe doing a MediaShrink/_RELINK/_MOVEREC series of operations. Maybe that is why Slugger and others don't do /inPlace shrinking. If I keep the mpg and the .autoencode.mkv, it wouldn't matter if someone is watching the mpg during shrinking since it doesn't get deleted at the end of the shrink. I could then use the "IsViewingMedia" test prior to _ReLINK and _MOVEREC to make sure the file gets linked and moved only when nobo9dy is watching anything.

[rmac321]

Originally Posted by Slugger

Yes, had to take it offline for awhile. I created the PDF version and posted it in the downloads section. That PDF is the final version of the SJQ 3.0.x User's Guide.

Will the online version no longer be available? There are a few places to modify if that link is no longer going to be valid. The link on the Sage Add-ons page on Google.code (http://code.google.com/p/sagetv-addons/) links to the online version. SJQ's own drop down help menu goes to the dead link. Also, your first post in this thread still has the link to the online version. The first post could use a pointer to the SJQ downloads as well.

Another issue to figure out. The pdf looks good, but the right half of the "Available Tests" chart (starts on page 20) goes off the page. That chart was the main reason I kept referring back to the online version since my attempt to make a pdf of the guide produced the same cropped table. Since I was using the online version, I never made a second attempt to copy that table.

Thanks!

[Slugger]

The online version will be available again in the not too distant future.

[jbuszkie]

I've been using SJQ happily now for a while and updraged to 3.x back in march maybe? and everything was happy doing my comskip stuff. but I started noticing that it seems to have stopped working. My shows are no longer being comskipped. So I tried to get into the server and I can't get past my password.

I've tried all the passwords that I know and ever the default sjqadmin and I still can't get in to see why I'm not working anymore. It's been so long I have no idea where to begin. Could the password database have gotten corrupted?

Where can I start looking? (as in where are the log files I should look at)

Oh.. and I have version SJQ v3.0.1.704

Help?

[jbuszkie]

Ok.. I think I found the log file.

Here is the part that looks interesting..

2010-04-26 06:35:59,218 WARN  [SJQServlet]: All client connections are being accepted and processed, please consider setting up client restrictions in SJQ settings
2010-04-26 06:35:59,218 INFO  [SJQServlet]: Checking client '127.0.0.1': 0 resources free.
2010-04-26 06:35:59,218 INFO  [SJQServlet]: Client '127.0.0.1' cannot pop a task of type 'COMSKIP': Requires 100 resources, but only 0 available.
2010-04-26 06:35:59,218 INFO  [SJQServlet]: Servlet POST request completed [0ms]
2010-04-26 06:36:00,625 WARN  [SJQServlet]: All client connections are being accepted and processed, please consider setting up client restrictions in SJQ settings
2010-04-26 06:36:00,625 INFO  [SJQServlet]: Servlet POST request completed [0ms]

Then I get this:

2010-04-27 19:57:44,375 INFO  [SystemMessageQueueLoader]: Run completed [32ms]
2010-04-27 19:58:40,484 WARN  [SJQServlet]: All client connections are being accepted and processed, please consider setting up client restrictions in SJQ settings
2010-04-27 19:58:40,484 INFO  [SJQServlet]: Checking client '127.0.0.1': 100 resources free.
2010-04-27 19:58:40,484 INFO  [SJQServlet]: Servlet POST request completed [0ms]
2010-04-27 19:58:44,390 INFO  [SystemMessageQueueLoader]: Run completed [15ms]
2010-04-27 19:59:27,937 INFO  [InternalTaskClient]: Run completed [0ms]
2010-04-27 19:59:44,421 INFO  [SystemMessageQueueLoader]: Run completed [15ms]
2010-04-27 20:00:44,468 INFO  [SystemMessageQueueLoader]: Run completed [31ms]
2010-04-27 20:01:10,250 INFO  [MediaFileQueueLoader]: Run completed [250ms]
2010-04-27 20:01:10,250 INFO  [DataStore]: Thread 'SJQ-VacuumCleaner' is seeking an exclusive DataStore connection!
2010-04-27 20:01:10,250 INFO  [DataStore]: Thread 'SJQ-VacuumCleaner' is waiting for an exclusive DataStore connection! [AVAIL=4; MAX=5; WAIT=0ms]
2010-04-27 20:01:10,250 INFO  [DataStore]: Thread 'SJQ-LogCleaner' is seeking an exclusive DataStore connection!
2010-04-27 20:01:10,250 INFO  [DataStore]: Thread 'SJQ-LogCleaner' has received an exclusive DataStore connection! [WAIT=0ms]
2010-04-27 20:01:10,250 INFO  [DataStore]: Thread 'SJQ-VacuumCleaner' is waiting for an exclusive DataStore connection! [AVAIL=4; MAX=5; WAIT=0ms]
2010-04-27 20:01:10,312 INFO  [DataStore]: 'SJQ-LogCleaner' has returned its exclusive DataStore connection!
2010-04-27 20:01:10,312 INFO  [DataStore]: Thread 'SJQ-VacuumCleaner' has received an exclusive DataStore connection! [WAIT=62ms]
2010-04-27 20:01:10,312 INFO  [LogCleaner]: Thread finished [62ms]
2010-04-27 20:01:11,468 INFO  [FileCleaner]: Thread finished [1218ms]
2010-04-27 20:01:27,937 INFO  [InternalTaskClient]: Run completed [0ms]
2010-04-27 20:01:40,312 WARN  [DataStore]: DataStore pool timeout expired! 'SJQ-VacuumCleaner' did not return connection within 30 seconds!  Adding a replacement connection to the pool.
2010-04-27 20:01:43,750 FATAL [DataStore]: SQL error
java.sql.SQLException: database is locked
	at org.sqlite.DB.throwex(DB.java:288)
	at org.sqlite.NativeDB.prepare(Native Method)
	at org.sqlite.DB.prepare(DB.java:114)
	at org.sqlite.Stmt.executeQuery(Stmt.java:89)
	at com.google.code.sagetvaddons.sjq.server.DataStore.loadDDL(DataStore.java:301)
	at com.google.code.sagetvaddons.sjq.server.DataStore.<init>(DataStore.java:154)
	at com.google.code.sagetvaddons.sjq.server.DataStore.<init>(DataStore.java:53)
	at com.google.code.sagetvaddons.sjq.server.DataStore$1.run(DataStore.java:186)
	at java.util.TimerThread.mainLoop(Unknown Source)
	at java.util.TimerThread.run(Unknown Source)
2010-04-27 20:01:44,390 WARN  [DataStore]: Thread 'SJQ-VacuumCleaner' attempted to return a timed out connection!  Dropping connection.
2010-04-27 20:01:44,390 INFO  [VacuumCleaner]: Thread finished [34140ms]
2010-04-27 20:02:26,046 INFO  [ClientMonitor]: Run completed [0ms]
2010-04-27 20:03:27,937 INFO  [InternalTaskClient]: Run completed [0ms]
2010-04-27 20:05:27,937 INFO  [InternalTaskClient]: Run completed [0ms]
2010-04-27 20:07:26,046 INFO  [ClientMonitor]: Run completed [0ms]
2010-04-27 20:07:27,937 INFO  [InternalTaskClient]: Run completed [0ms]
2010-04-27 20:09:27,937 INFO  [InternalTaskClient]: Run completed [0ms]
2010-04-27 20:11:27,937 INFO  [InternalTaskClient]: Run completed [0ms]
2010-04-27 20:12:26,046 INFO  [ClientMonitor]: Run completed [0ms]

Then the rest of the log file(s) looks like this:

2010-04-27 22:07:27,937 INFO  [InternalTaskClient]: Run completed [0ms]
2010-04-27 22:09:27,937 INFO  [InternalTaskClient]: Run completed [0ms]
2010-04-27 22:11:27,937 INFO  [InternalTaskClient]: Run completed [0ms]
2010-04-27 22:12:26,046 INFO  [ClientMonitor]: Run completed [0ms]
2010-04-27 22:13:27,937 INFO  [InternalTaskClient]: Run completed [0ms]
2010-04-27 22:15:27,937 INFO  [InternalTaskClient]: Run completed [0ms]
2010-04-27 22:17:26,046 INFO  [ClientMonitor]: Run completed [0ms]
2010-04-27 22:17:27,937 INFO  [InternalTaskClient]: Run completed [0ms]
2010-04-27 22:19:27,953 INFO  [InternalTaskClient]: Run completed [0ms]
2010-04-27 22:21:27,953 INFO  [InternalTaskClient]: Run completed [0ms]
2010-04-27 22:22:26,046 INFO  [ClientMonitor]: Run completed [0ms]
2010-04-27 22:23:27,953 INFO  [InternalTaskClient]: Run completed [0ms]
2010-04-27 22:25:27,953 INFO  [InternalTaskClient]: Run completed [0ms]
2010-04-27 22:27:26,046 INFO  [ClientMonitor]: Run completed [0ms]
2010-04-27 22:27:27,953 INFO  [InternalTaskClient]: Run completed [0ms]
2010-04-27 22:29:27,953 INFO  [InternalTaskClient]: Run completed [0ms]
2010-04-27 22:31:27,953 INFO  [InternalTaskClient]: Run completed [0ms]
2010-04-27 22:32:26,046 INFO  [ClientMonitor]: Run completed [0ms]
2010-04-27 22:33:27,953 INFO  [InternalTaskClient]: Run completed [0ms]
2010-04-27 22:35:27,953 INFO  [InternalTaskClient]: Run completed [0ms]
2010-04-27 22:37:26,046 INFO  [ClientMonitor]: Run completed [0ms]
2010-04-27 22:37:27,953 INFO  [InternalTaskClient]: Run completed [0ms]
2010-04-27 22:39:27,953 INFO  [InternalTaskClient]: Run completed [0ms]
2010-04-27 22:41:27,953 INFO  [InternalTaskClient]: Run completed [0ms]
2010-04-27 22:42:26,046 INFO  [ClientMonitor]: Run completed [0ms]
2010-04-27 22:43:27,953 INFO  [InternalTaskClient]: Run completed [0ms]
2010-04-27 22:45:27,953 INFO  [InternalTaskClient]: Run completed [0ms]
2010-04-27 22:47:26,046 INFO  [ClientMonitor]: Run completed [0ms]
2010-04-27 22:47:27,953 INFO  [InternalTaskClient]: Run completed [0ms]
2010-04-27 22:49:27,953 INFO  [InternalTaskClient]: Run completed [0ms]
2010-04-27 22:51:27,953 INFO  [InternalTaskClient]: Run completed [0ms]
2010-04-27 22:52:26,046 INFO  [ClientMonitor]: Run completed [0ms]
2010-04-27 22:53:27,953 INFO  [InternalTaskClient]: Run completed [0ms]
2010-04-27 22:55:27,953 INFO  [InternalTaskClient]: Run completed [0ms]
2010-04-27 22:57:26,046 INFO  [ClientMonitor]: Run completed [0ms]
2010-04-27 22:57:27,953 INFO  [InternalTaskClient]: Run completed [0ms]
2010-04-27 22:59:27,953 INFO  [InternalTaskClient]: Run completed [0ms]
2010-04-27 23:01:27,953 INFO  [InternalTaskClient]: Run completed [0ms]
2010-04-27 23:02:26,046 INFO  [ClientMonitor]: Run completed [0ms]
2010-04-27 23:03:27,953 INFO  [InternalTaskClient]: Run completed [0ms]
2010-04-27 23:05:27,953 INFO  [InternalTaskClient]: Run completed [0ms]
2010-04-27 23:07:26,046 INFO  [ClientMonitor]: Run completed [0ms]
2010-04-27 23:07:27,953 INFO  [InternalTaskClient]: Run completed [0ms]
2010-04-27 23:09:27,953 INFO  [InternalTaskClient]: Run completed [0ms]
2010-04-27 23:11:27,953 INFO  [InternalTaskClient]: Run completed [0ms]
2010-04-27 23:12:26,046 INFO  [ClientMonitor]: Run completed [0ms]
2010-04-27 23:13:27,953 INFO  [InternalTaskClient]: Run completed [0ms]
2010-04-27 23:15:27,953 INFO  [InternalTaskClient]: Run completed [0ms]
2010-04-27 23:17:26,046 INFO  [ClientMonitor]: Run completed [0ms]
2010-04-27 23:17:27,953 INFO  [InternalTaskClient]: Run completed [0ms]
2010-04-27 23:19:27,953 INFO  [InternalTaskClient]: Run completed [0ms]
2010-04-27 23:21:27,953 INFO  [InternalTaskClient]: Run completed [0ms]
2010-04-27 23:22:26,046 INFO  [ClientMonitor]: Run completed [0ms]
2010-04-27 23:23:27,953 INFO  [InternalTaskClient]: Run completed [0ms]
2010-04-27 23:25:27,953 INFO  [InternalTaskClient]: Run completed [0ms]
2010-04-27 23:27:26,046 INFO  [ClientMonitor]: Run completed [0ms]
2010-04-27 23:27:27,953 INFO  [InternalTaskClient]: Run completed [0ms]
2010-04-27 23:29:27,953 INFO  [InternalTaskClient]: Run completed [0ms]
2010-04-27 23:31:27,953 INFO  [InternalTaskClient]: Run completed [0ms]
2010-04-27 23:32:26,046 INFO  [ClientMonitor]: Run completed [0ms]
2010-04-27 23:33:27,953 INFO  [InternalTaskClient]: Run completed [0ms]
2010-04-27 23:35:27,953 INFO  [InternalTaskClient]: Run completed [0ms]
2010-04-27 23:37:26,046 INFO  [ClientMonitor]: Run completed [0ms]
2010-04-27 23:37:27,953 INFO  [InternalTaskClient]: Run completed [0ms]
2010-04-27 23:39:27,953 INFO  [InternalTaskClient]: Run completed [0ms]
2010-04-27 23:41:27,953 INFO  [InternalTaskClient]: Run completed [0ms]
2010-04-27 23:42:26,046 INFO  [ClientMonitor]: Run completed [0ms]
2010-04-27 23:43:27,953 INFO  [InternalTaskClient]: Run completed [0ms]
2010-04-27 23:45:27,953 INFO  [InternalTaskClient]: Run completed [0ms]
2010-04-27 23:47:26,046 INFO  [ClientMonitor]: Run completed [0ms]
2010-04-27 23:47:27,953 INFO  [InternalTaskClient]: Run completed [0ms]
2010-04-27 23:49:27,953 INFO  [InternalTaskClient]: Run completed [0ms]
2010-04-27 23:51:27,953 INFO  [InternalTaskClient]: Run completed [0ms]
2010-04-27 23:52:26,046 INFO  [ClientMonitor]: Run completed [0ms]
2010-04-27 23:53:27,953 INFO  [InternalTaskClient]: Run completed [0ms]
2010-04-27 23:55:27,953 INFO  [InternalTaskClient]: Run completed [0ms]
2010-04-27 23:57:26,046 INFO  [ClientMonitor]: Run completed [0ms]
2010-04-27 23:57:27,953 INFO  [InternalTaskClient]: Run completed [0ms]
2010-04-27 23:59:27,953 INFO  [InternalTaskClient]: Run completed [0ms]
2010-04-28 00:01:27,953 INFO  [InternalTaskClient]: Run completed [0ms]
2010-04-28 00:02:26,046 INFO  [ClientMonitor]: Run completed [0ms]
2010-04-28 00:03:27,953 INFO  [InternalTaskClient]: Run completed [0ms]
2010-04-28 00:05:27,953 INFO  [InternalTaskClient]: Run completed [0ms]
2010-04-28 00:07:26,046 INFO  [ClientMonitor]: Run completed [0ms]
2010-04-28 00:07:27,953 INFO  [InternalTaskClient]: Run completed [0ms]
2010-04-28 00:09:27,953 INFO  [InternalTaskClient]: Run completed [0ms]
2010-04-28 00:11:27,953 INFO  [InternalTaskClient]: Run completed [0ms]
2010-04-28 00:12:26,046 INFO  [ClientMonitor]: Run completed [0ms]
2010-04-28 00:13:27,953 INFO  [InternalTaskClient]: Run completed [0ms]
2010-04-28 00:15:27,953 INFO  [InternalTaskClient]: Run completed [0ms]
2010-04-28 00:17:26,046 INFO  [ClientMonitor]: Run completed [0ms]
2010-04-28 00:17:27,953 INFO  [InternalTaskClient]: Run completed [0ms]
2010-04-28 00:19:27,953 INFO  [InternalTaskClient]: Run completed [0ms]
2010-04-28 00:21:27,953 INFO  [InternalTaskClient]: Run completed [0ms]
2010-04-28 00:22:26,046 INFO  [ClientMonitor]: Run completed [0ms]
2010-04-28 00:23:27,953 INFO  [InternalTaskClient]: Run completed [0ms]
2010-04-28 00:25:27,953 INFO  [InternalTaskClient]: Run completed [0ms]
2010-04-28 00:27:26,046 INFO  [ClientMonitor]: Run completed [0ms]
2010-04-28 00:27:27,953 INFO  [InternalTaskClient]: Run completed [0ms]
2010-04-28 00:29:27,953 INFO  [InternalTaskClient]: Run completed [0ms]
2010-04-28 00:31:27,953 INFO  [InternalTaskClient]: Run completed [0ms]
2010-04-28 00:32:26,046 INFO  [ClientMonitor]: Run completed [0ms]
2010-04-28 00:33:27,953 INFO  [InternalTaskClient]: Run completed [0ms]
2010-04-28 00:35:27,953 INFO  [InternalTaskClient]: Run completed [0ms]
2010-04-28 00:37:26,046 INFO  [ClientMonitor]: Run completed [0ms]
2010-04-28 00:37:27,953 INFO  [InternalTaskClient]: Run completed [0ms]
2010-04-28 00:39:27,953 INFO  [InternalTaskClient]: Run completed [0ms]
2010-04-28 00:41:27,953 INFO  [InternalTaskClient]: Run completed [0ms]
2010-04-28 00:42:26,046 INFO  [ClientMonitor]: Run completed [0ms]
2010-04-28 00:43:27,953 INFO  [InternalTaskClient]: Run completed [0ms]
2010-04-28 00:45:27,953 INFO  [InternalTaskClient]: Run completed [0ms]
2010-04-28 00:47:26,046 INFO  [ClientMonitor]: Run completed [0ms]
2010-04-28 00:47:27,953 INFO  [InternalTaskClient]: Run completed [0ms]
2010-04-28 00:49:27,953 INFO  [InternalTaskClient]: Run completed [0ms]
2010-04-28 00:51:27,953 INFO  [InternalTaskClient]: Run completed [0ms]
2010-04-28 00:52:26,046 INFO  [ClientMonitor]: Run completed [0ms]
2010-04-28 00:53:27,953 INFO  [InternalTaskClient]: Run completed [0ms]
2010-04-28 00:55:27,953 INFO  [InternalTaskClient]: Run completed [0ms]
2010-04-28 00:57:26,046 INFO  [ClientMonitor]: Run completed [0ms]
2010-04-28 00:57:27,953 INFO  [InternalTaskClient]: Run completed [0ms]
2010-04-28 00:59:27,953 INFO  [InternalTaskClient]: Run completed [0ms]
2010-04-28 01:01:27,953 INFO  [InternalTaskClient]: Run completed [0ms]
2010-04-28 01:02:26,046 INFO  [ClientMonitor]: Run completed [0ms]
2010-04-28 01:03:27,953 INFO  [InternalTaskClient]: Run completed [0ms]
2010-04-28 01:05:27,953 INFO  [InternalTaskClient]: Run completed [0ms]
2010-04-28 01:07:26,046 INFO  [ClientMonitor]: Run completed [0ms]
2010-04-28 01:07:27,953 INFO  [InternalTaskClient]: Run completed [0ms]
2010-04-28 01:09:27,953 INFO  [InternalTaskClient]: Run completed [0ms]
2010-04-28 01:11:27,953 INFO  [InternalTaskClient]: Run completed [0ms]
2010-04-28 01:12:26,046 INFO  [ClientMonitor]: Run completed [0ms]
2010-04-28 01:13:27,953 INFO  [InternalTaskClient]: Run completed [0ms]
2010-04-28 01:15:27,953 INFO  [InternalTaskClient]: Run completed [0ms]
2010-04-28 01:17:26,046 INFO  [ClientMonitor]: Run completed [0ms]
2010-04-28 01:17:27,953 INFO  [InternalTaskClient]: Run completed [0ms]
2010-04-28 01:19:27,953 INFO  [InternalTaskClient]: Run completed [0ms]
2010-04-28 01:21:27,953 INFO  [InternalTaskClient]: Run completed [0ms]
2010-04-28 01:22:26,046 INFO  [ClientMonitor]: Run completed [0ms]
2010-04-28 01:23:27,953 INFO  [InternalTaskClient]: Run completed [0ms]
2010-04-28 01:25:27,953 INFO  [InternalTaskClient]: Run completed [0ms]
2010-04-28 01:27:26,046 INFO  [ClientMonitor]: Run completed [0ms]
2010-04-28 01:27:27,953 INFO  [InternalTaskClient]: Run completed [0ms]
2010-04-28 01:29:27,953 INFO  [InternalTaskClient]: Run completed [0ms]
2010-04-28 01:31:27,953 INFO  [InternalTaskClient]: Run completed [0ms]
2010-04-28 01:32:26,046 INFO  [ClientMonitor]: Run completed [0ms]
2010-04-28 01:33:27,953 INFO  [InternalTaskClient]: Run completed [0ms]

I've sworn I've rebooted the computer since this happened.. but I'll try again.

Jim

[jbuszkie]

I guess I hadn't rebooted my computer in a while.. after the full reboot, I was able to log in and comskip seems to be running happily again. It's got a lot a files to catch up to!

I wonder what happened?

Jim

[Slugger]

Which server version of SJQ are you running? Please try upgrading to the latest snapshot if you're not running it (3.0.2.794).

The file cleaner thread is taking over a second to run - seems everything is slow, which can lead to db lock exceptions like you're seeing. A system reboot can't hurt. If you still see the issue after an upgrade and system reboot then let me know.

[Slugger]

Originally Posted by jbuszkie

I guess I hadn't rebooted my computer in a while.. after the full reboot, I was able to log in and comskip seems to be running happily again. It's got a lot a files to catch up to!

I wonder what happened?

Jim

Once you start running into DB Locked exceptions then all bets are off - things aren't going to work like they should. What causes them? Possibly (probably) bugs in the SJQ server code, but with your logs the problem seems to be the file cleaner took a rather long time, which locked the db longer than expected, which caused the db cleanup thread to timeout, which caused the db exception, which killed the db connections, which eventually kills the task loader thread.

Unfortunately, without the ability to reproduce, it's rather hard to track down the problem (if it's indeed an SJQ problem). Hopefully I'm able to reproduce it someday and then fix it, otherwise SJQ restart is about the best course of action.

[rmac321]

Originally Posted by Slugger

Otherwise SJQ restart is about the best course of action.

What's the preferred method for a SJQ restart? Is there a specific service to stop and start or is there a better method? I presume the "sjq task client" service is the local client service, not the server. I stopped and started the Sage Service, but it had no effect. Does this require a server reboot?

I have a situation at the moment where SJQ is running my tasks - both internal and client tasks, but my Active Queue appears empty even though it isn't. The completed tasks keeps getting updated, and nothing is failing, but I can't see what is actually in the queue. I'm hesitatnt to reboot the Sage-Server since I can't tell when an internal task like a _MOVEREC begins - I can only see when one has been completed, so I don't want to do a complete reboot in the middle of a file move.

I presume it is best to make sure all tasks are completed before doing a reboot. To make sure I don't interrupt anything currently running, I could reset all my resources to 101 to prevent any more client tasks from starting, but I guess I'd have to comment out my internal tasks and wait a while to be sure they are done running and being added to the queue.

What are the consequences to an external task if I stop in the middle of a task. FI, if a different client is running a mediashrink task and I restart the sjq server, I presume, the server will not just start back up where it left off, but will build a new queue.

[Slugger]

Originally Posted by rmac321

What's the preferred method for a SJQ restart? Is there a specific service to stop and start or is there a better method? I presume the "sjq task client" service is the local client service, not the server. I stopped and started the Sage Service, but it had no effect. Does this require a server reboot?

Depending on the problem(s) you're trying to fix. The best way to restart SJQ is to move the sjq.context.xml file out of the jetty/contexts dir. This will undeploy the app in Jetty; no Sage restart required. If that doesn't fix your problem, stop Sage and restart it. Once Sage is stopped SJQ is definitely stopped.

I have a situation at the moment where SJQ is running my tasks - both internal and client tasks, but my Active Queue appears empty even though it isn't. The completed tasks keeps getting updated, and nothing is failing, but I can't see what is actually in the queue. I'm hesitatnt to reboot the Sage-Server since I can't tell when an internal task like a _MOVEREC begins - I can only see when one has been completed, so I don't want to do a complete reboot in the middle of a file move.

I presume it is best to make sure all tasks are completed before doing a reboot. To make sure I don't interrupt anything currently running, I could reset all my resources to 101 to prevent any more client tasks from starting, but I guess I'd have to comment out my internal tasks and wait a while to be sure they are done running and being added to the queue.

You are correct. Set your tasks to 101 resources required and give the internal task queue some time. You can use the server snapshot view on the Tools menu to get a snapshot of the system. If the internal task client is sleeping then you're good to go. A sleeping internal task client will look like this in the thread output:

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)

I'd like to be able to reproduce this empty queue view bug you're seeing. If you have Firebug or something equivalent installed in your browser and can view the XHR requests from your browser then PM me and we can get some debug info (if you have no idea what I'm talking about then just ignore me).

What are the consequences to an external task if I stop in the middle of a task. FI, if a different client is running a mediashrink task and I restart the sjq server, I presume, the server will not just start back up where it left off, but will build a new queue.

If my memory is correct, an external task (on a remote host or the same as the server) will complete, but when it tries to update the server with the status at the end it will fail. When the server restarts it will not know the task ever completed and will requeue it. There is a chance that the task client will fail out almost immediately on newer builds, I don't remember how I implemented the callback logic for clients to check to see if the server has requested the task to be terminated.

[Skirge01]

Slugger, I'm having an issue with NBC. I set up the following rule:

if [IsObjMediaFile == true && $.IsTVFile{} == true && $.IsNotManualOrFavorite{} == false && $.GetAiringChannelName{} =% "WABCDT|WCBSDT|WNBCDT" && MediaAge < "10D" && FileExists != "%d%/%p%.edl"] {
   :PRIORITY 10
   :FAILALERT "TRUE"
    ABCCBSNBCSKIP
}

I have Law & Order being recorded and it's not getting added. Running the file through the debugger, I see the issue is with the channel, but I can't figure out what's wrong. Here's the debugger line:

[RulesParser]: 	Line 2: Evaluating '$.GetAiringChannelName{} =% "WABCDT|WCBSDT|WNBCDT"' == false

In the SageTV guide, I see the channel listed as "WNBCDT". In my channel setup for the tuner which did this recording, I see "4 - WNBCDT [28-4-1] WNBCDT (WNBC-DT) New York". The program info screen in SageTV also shows the same thing. I don't know where to look in order to find out what channel SageTV believes this recording is from. I tried "WNBC-DT" with no luck either. I also tried without any other channels and an "==" operator.

I've seen other shows being queued up via that rule, but not shows on NBC.

Any suggestions on where to look to track this down?

Thanks!

[Slugger]

It's going to be awhile before I can add the extra debug info to SJQ. If you're able to get around in Studio, what you can do is use the expression evaluator to print the value of GetAiringChannelName for the object. Whatever value that returns in Studio (should) be the value SJQ is using.

EDIT: Put this into the expression evaluator in Studio:

GetAiringChannelName(GetAiringForID("2504594"))

Replace the id number with an airing id from a NBC recording that isn't being loaded by SJQ. Get the airing id from the web server details page. That will print out the channel name as received by SJQ.

[Skirge01]

Awesome! Thanks for the tip!

[Slugger]

Originally Posted by Skirge01

Awesome! Thanks for the tip!

If you don't mind letting me know what you discovered (i.e. SJQ bug or something else), that'd be appreciated.

[rmac321]

Originally Posted by Slugger

stop Sage and restart it. Once Sage is stopped SJQ is definitely stopped.

That's interesting. After I did a stop and restart of the Sage Service, the queue still appeared empty, even though the tasks were still chugging along. I viewed SJQ on another computer as well to make sure it wasn't something to do with the laptop I'm normally on, but I had the same results on the other computer.

It's a very curious glitch in that the clients still appear, the tasks keep being added to the Completed Tasks as they finish, The Ruleset Editor appears to be available, I can edit my settings, etc. Pretty much everything is alive and active except that it won't display anything in my Active Queue even though it is clearly chewing through tasks.

Thanks for the tip on using snapshot. I forgot that was available. I don't see anything in the snapshot that looks funky, but I also don't have a clue what a bunch of it means.

Tue May 18 23:19:50 CDT 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... 
sage.media.format.MPEGParser.getMediaAVInf0(Native Method) 
sage.media.format.g.if(Unknown Source) 
sage.media.format.g.a(Unknown Source) 
sage.at.a(Unknown Source) 
sage.d.l$2.try(Unknown Source) 
sage.ax.a(Unknown Source) 
sage.e.a(Unknown Source) 
sage.SageTV.apiUI(Unknown Source) 
gkusnick.sagetv.api.API.Call(API.java:146) 
gkusnick.sagetv.api.MediaFileAPI.AddMediaFile(MediaFileAPI.java:29) 
com.google.code.sagetvaddons.sjq.server.tasks.TvArchiver.createMediaFile(TvArchiver.java:628) 
com.google.code.sagetvaddons.sjq.server.tasks.TvArchiver.run(TvArchiver.java:394) 
com.google.code.sagetvaddons.sjq.server.InternalTaskClient.moveRec(InternalTaskClient.java:169) 
com.google.code.sagetvaddons.sjq.server.InternalTaskClient.performTask(InternalTaskClient.java:114) 
com.google.code.sagetvaddons.sjq.server.InternalTaskClient.run(InternalTaskClient.java:61) 
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)!

I have a lot of instances like this in my server log. Does that give a clue?

2010-05-18 15:55:23,243 INFO  [SJQServlet]: Servlet POST request completed [0ms]
2010-05-18 15:55:29,086 WARN  [DataStore]: DataStore pool timeout expired! '18667724@qtp-4289465-6' did not return connection within 30 seconds!  Adding a replacement connection to the pool.

Originally Posted by Slugger

I'd like to be able to reproduce this empty queue view bug you're seeing. If you have Firebug or something equivalent installed in your browser and can view the XHR requests from your browser then PM me and we can get some debug info (if you have no idea what I'm talking about then just ignore me).

While I don't know what that means, I'm always willing to learn. I have a lot on my plate for the next few days, so I'll keep reading through the thread as I have time and I'll do some research on Firebug and XHR requests when I get a chance. Once I'm up to speed I'll get in touch and we can do some debugging.

Originally Posted by Slugger

If my memory is correct, an external task (on a remote host or the same as the server) will complete, but when it tries to update the server with the status at the end it will fail. When the server restarts it will not know the task ever completed and will requeue it. There is a chance that the task client will fail out almost immediately on newer builds, I don't remember how I implemented the callback logic for clients to check to see if the server has requested the task to be terminated.

That's about what I figured. I figured that if it was a MediaShrink task for instance, then MediaShrink would plug along until finished. Then when the server was back on line, if MediaShrink was doing inPlace shrinking, then their would be no mpg left to re-queue. The thing that would be missing would be an entry in the Completed Tasks in SJQ. The tasks that could get ugly would be internal tasks halted mid-stride or things like comskip that create a file and modify it as they go along. If the process dies, then the files will exist, so that task won't be re-queued, but the original run may have been incomplete.

Thanks for the help and for this cool tool. I'm having fun learning to make it run.

[Skirge01]

Originally Posted by Slugger

If you don't mind letting me know what you discovered (i.e. SJQ bug or something else), that'd be appreciated.

Sure... It was a PEBKAC issue. SJQ is in the clear. I had selected the wrong episode in the debug the first time and kept running that one through. Since the debug entry field only shows the very beginning of the UNC path, I never bothered to scroll over to the right to verify the episode was correct each subsequent time. Unfortunately, that episode of L&O was shown on TNT, so the WNBCDT in the ruleset wasn't going to work no matter how hard I tried.