Plugin: Sage Job Queue (SJQ) v3

[ohpleaseno]

hey Slugger,

any idea why SJQ would not let mediashrink finish out it's job? it will encode my video, but then just hangup on the file moving out of the work folder that media shrink creates and not move on from there.

[nyplayer]

Originally Posted by ohpleaseno

hey Slugger,

any idea why SJQ would not let mediashrink finish out it's job? it will encode my video, but then just hangup on the file moving out of the work folder that media shrink creates and not move on from there.

Speaking from experience with SJQ and Media shrink this is not a SJQ problem... what SJQ does is run the task and waits until the task completes or fails. It has nothing to do with the actual encoding and moving of the file from the work-folder to the Sage folder.


What you need to do is save the logs from mediashrink and post for penguin.

PS I have had problems with Mediashrink creating MP4 with closed captions where it fails on the mp4 merge. I stopped using mediashrink instead use handbrake by itself... through batch file.

[ohpleaseno]

I'm still confused as to why I have no problem with Mediashrink using drag and drop, but it hangs up when I use SJQ. I figured it would be a mediashrink problem, but I thought it was worth a shot anyway to ask over here.

thanks!

[Slugger]

SJQ simply creates a process and waits for it to complete. I don't use mediashrink myself, so I have no experience with it, but SJQ just creates the process and waits for it to finish. As nyplayer said, you will want to pursue the issue with penguin.

[ohpleaseno]

can I have SJQ call for the console window of a program it is running to expose itself instead of running in the background?

[Slugger]

Negative. All you can do in Java is create the process and grab its output, which is what I already do and I log that output back to the SJQ server for viewing.

[jakfech]

I started out using mediashrink but wanted more control. I then created a script to call handbrake (note: I haven't retried with 0.94), but handbrake couldn't read all of my recordings. So I fell back to mencoder which I've used at previous jobs for automated video transcoding. Mencoder doesn't do closed captioning or multiple audio streams. So I may end up first trying handbrake and using mencoder only if handbrake fails.

I'm finishing my transition from Beyond to Sage. Without SJQ I'd never have finally committed to changing. I want all HD and more customizability. So Sage is the way to go. I plan to post my full SJQ configuration (including scripts) as a tutorial. Until then:

My script requires Python 2.6 (+ the win32 package on Windows). It currently only runs on Windows but Mac/Linux support is stubbed out in case someone needs it. I recommend using the ActivePython installer for Windows.

Server:
# Mencoder
# (if the file is not actively recording, and this file came from a tuner,
# it is a scheduled recording or a live or an intelligent recording older than 3 hours,
# and the filename ends with mpeg, mpg or ts,
# and it is over 500MB, and a comskip file exists,
# a transcoding file does not exist [the file extension for temporary output files
# during the conversion process],
# and an avi, divx, mkv or mp4 does not exist)
if [IsObjMediaFile == true && $.IsFileCurrentlyRecording{} == false && $.IsTVFile{} == true && ($.IsNotManualOrFavorite{} == false || ($.IsFileCurrentlyRecording{} == false && MediaAge >= "3H")) && (Filename =$ ".mpeg" || Filename =$ ".mpg" || Filename =$ ".ts") && MediaSize > "500M" && FileExists == "%d%\\%p%.edl" && FileExists != "%d%\\%p%.transcoding" && (FileExists != "%d%\\%p%.avi" && FileExists != "%d%\\%p%.divx" && FileExists != "%d%\\%p%.mkv" && FileExists != "%d%\\%p%.mp4")]
{
:PRIORITY 5
MENCODER
}

# Delete mpg files where a avi, divx, mkv or mp4 file exists (the mpg has been compressed)
# (if this file is not being watched, and it came from a tuner,
# an mpg exists, # and a avi, divx, mkv or mp4 file exists)
if [IsObjMediaFile == true && IsViewingMedia == false && $.IsTVFile{} == true && $.IsFileCurrentlyRecording{} == false && FileExists == "%d%\\%p%.mpg" && (FileExists == "%d%\\%p%.avi" || FileExists == "%d%\\%p%.divx" || FileExists == "%d%\\%p%.mkv" || FileExists == "%d%\\%p%.mp4")]
{
:PRIORITY 15
:SCANMEDIA "true"
DELETEMPG
}

Client:
MENCODER
{
//Max of 1 worker at the same time
:MAX 1
//This requires 66% of the system's resources
:RESOURCES 66
//This task can only run for the 3 times the video's length (the script should kill it at 275%)
:MAXRUNRATIO 3.0
//Explicitly check for return code 0
:RETURNCODE 0
"python \"C:\\Programs\\sjq3\\MPlayer\\launch_mencoder.py\" --input-file \"%c%\" --max-duration-percentage 275 --perform-service-wrapper-process-check --perform-local-sage-process-check"
}

DELETEMPG
{
//Max of 5 workers at the same time
:MAX 5
//This requires 5% of the system's resources
:RESOURCES 5
//Run for 1 minute max
:MAXRUN 1
"python \"C:\\Programs\\sjq3\\Scripts\\delete.py\" \"%d%\\%p%.mpg\""
}

(change you paths to where ever you extract the attached scripts. Also, the above assumes Python is on your PATH)

You can get mencoder from here:
http://downloads.sourceforge.net/pro...se_mirror=iweb

Attached is a zip containing:
launch_mencoder.py -- the main script
program_options.py -- where you set your transcoding options
And a zip containing:
delete.py -- An "if exists, delete file" script

What can launch_mencoder.py do? It launches mencoder and monitors it. It writes all its output to a file named XXX.mencoder_python_log (which remains if the transcoding fails). It can be set to check if the Sage process is running and shut down mencoder if it shuts down or its process ID changes. Same with the service wrapper (wrapper.exe). It can also check for a remotely running Sage instance (I use sagex to do this but any URL that changes each time Sage launches). It can be configured with a max run time and to operate on files only above a certain length. It also checks the resulting converted file to ensure its length is within a certain percentage (3% by default) of the original (I had some trouble with handbrake getting partially done).

The idea is catch all possible errors and avoid a whole bunch of transcoding processes launching (in the case that Sage or SJQ clients get restarted).

Hopefully this can be of use to someone besides me

[jakfech]

Originally Posted by Slugger

SJQ should be calling the task multiple times, once for each file segment. So if a recording was split into 2 parts, SJQ should pass file-0.mpg to the first command then run the command again with file-1.mpg. If it's not, it's a regression (this definitely used to work like this). Note that if the task failed for an earlier segment then the remaining segments will not be processed, but instead the task is just halted and marked as failed.

Thanks, Slugger. I imagine the problem is on my end. I will recreate the situation and turn up the logging level and see what I can find. Thanks for the response (and being ahead of me ).

[Slugger]

My first attempt to fix the 'Database is locked' errors is now available in snapshot 664. I've introduced the ability for threads to request exclusive access to the database and while a thread has such access, all others are blocked. This should undoubtedly prevent the database is locked errors.

My initial implementation deadlocked the app, which was not totally unexpected, but I studied the code quite thoroughly and I believe I've removed all the deadlock scenarios from the code, but that's where I need everyone else to help out with testing. Please install snapshot 664 and do your worst to it, so to speak. If the SJQ server appears to become non-responsive then look at the sjq.log file and pay particular attention to SJQ's issuance of the exclusive DataStore connection:

2009-11-28 16:18:43,477 INFO  [DataStore]: Thread 'SJQ-LogCleaner' is seeking an exclusive DataStore connection!
2009-11-28 16:18:43,477 INFO  [DataStore]: Thread 'SJQ-LogCleaner' is waiting for an exclusive DataStore connection! [AVAIL=4; MAX=5; WAIT=0ms]
2009-11-28 16:18:43,477 INFO  [DataStore]: Thread 'SJQ-LogCleaner' is waiting for an exclusive DataStore connection! [AVAIL=4; MAX=5; WAIT=0ms]
2009-11-28 16:18:44,398 INFO  [DataStore]: Thread 'SJQ-LogCleaner' has received an exclusive DataStore connection! [WAIT=921ms]
2009-11-28 16:18:44,414 INFO  [LogCleaner]: LogCleaner instance finished [16ms]
2009-11-28 16:18:44,414 INFO  [DataStore]: 'SJQ-LogCleaner' has returned its exclusive DataStore connection!

The key is that when the exclusive connection is given, it must be returned otherwise the app will deadlock. As I said, I'm fairly certain I've weeded out the areas where deadlock can occur, but obviously more testers will confirm that. Please report back your results.

[evilpenguin]

So strange thing i'm seeing, keep in mind i'm just speculating here, is that jobs over ~3 hours might be getting interference from whatever stdin SJQ is giving them.

1) People have had problems with SJQ where Handbrake was getting killed via phantom stdin input and its not unusual for a job to go over 3 hours. I don't see this error on my machine, but I modified my dev version to not pass on stdin command a while ago.
2) I'm getting what look like hangs on Comskip when I run live on football games which run ~4 hours at about the 2.5 hour mark. I know Comskip can also be paused via a single key presses over stdin so it looks like that might be happening.

Tomorrow i'm gonna write a tool that just loops/logs STDIN and runs as a SJQ job for a few hours and see if I can catch anything strange happening. Just a heads up to see if you have any ideas in advance.

Edit: nm, thought I was onto something, but looks like Comskip doesn't have a pause command. Time for some alternate debugging...

[nyplayer]

Slugger.

snapshot 664 seems to fix the DB locks. I did get some waits on exclusive... but it cleaned up when it got exclusive control and I had no DB locks.

[Slugger]

Originally Posted by nyplayer

Slugger.

snapshot 664 seems to fix the DB locks. I did get some waits on exclusive... but it cleaned up when it got exclusive control and I had no DB locks.

Yeah, having to wait for that exclusive connection isn't unexpected. Actually, it could be rather common if the log cleaner is triggered while tasks are running or clients are connected to the server. The key is that the log cleaner will happily block until it's able to get an exclusive connection then it'll do its thing. And, of course, while a thread has an exclusive connection the rest of the app blocks until it's returned.

My local build I'm running now includes an additional fix that moves the db vacuum process (the process that frees unused disk space from the db file) into a separate thread and the vacuum process also requests an exclusive connection (the vacuum process is another one that can be rather slow and cause db lock exceptions). I'm seeing the log cleaner and the vacuum process simultaneously request the exclusive connection and it's all working as expected.

So I'm fairly confident that I've eliminated the cause of the db locked errors through the use of the exclusive connection, but keeping the rest of the app concurrent and zippy by using a non-exclusive db connection where possible. Of course, this is all pending more feedback from others.

My local build contains the vacuum thread fix/enhancement, which also reduces the vacuum frequency to once a month instead of once a week. It also includes the noise reduction on the log file by turning down a lot of the INFO messages to DEBUG level. I've kept a few places at INFO level until I get more feedback on this 664 build, but as it is now, the amount of data dumped to the log is way down (like probably cut by at least 80%). All of these fixes are checked in, I just haven't uploaded the build to the project site yet as I'm waiting for more feedback on 664 first. I really want some feedback on the db fixes in 664 before throwing another build up there for people to move to.

[Slugger]

Originally Posted by Slugger

SJQ should be calling the task multiple times, once for each file segment. So if a recording was split into 2 parts, SJQ should pass file-0.mpg to the first command then run the command again with file-1.mpg. If it's not, it's a regression (this definitely used to work like this). Note that if the task failed for an earlier segment then the remaining segments will not be processed, but instead the task is just halted and marked as failed.

Originally Posted by jakfech

Thanks, Slugger. I imagine the problem is on my end. I will recreate the situation and turn up the logging level and see what I can find. Thanks for the response (and being ahead of me ).

Turns out a regression did creep in during my initial v3 work. Starting with v3, SJQ would run the command for each file segment, but the media variables would always be set to use the values of file segment zero (file-0.mpg) and even though the command would run multiple times for each segment, the value of the media vars would always represent the first segment value.

The fix is contained in r668. I haven't uploaded a new build to the project site yet as I'm still waiting for feedback on the specific db fixes in 664 so just grab the next snapshot that's posted as long as it's numbered 668 or higher then this fix will be in there.

[jakfech]

Great. I might grab the source and try it out. Thanks, Slugger.

[Slugger]

Originally Posted by jakfech

Great. I might grab the source and try it out. Thanks, Slugger.

If you do attempt to build from source, you can follow the SageAlert build document - both projects build basically the same. If I were to write a similar doc for SJQ, I would literally just copy, rename it and replace 'SageAlert' with 'SJQ' throughout the doc.

One slight change in the 'Run the Build' section: To build the zip for deployment in SJQ, the target name is 'zip' not 'dist' so where it says to run 'ant dist' simply replace it with 'ant zip'. Other than that, the doc should work verbatim to build SJQ from source. If you do try and that's not the case please let me know of any updates and I'll probably make a copy of the doc for SJQ.

[Slugger]

I wanted to wait for more feedback on 664, but I've made too many changes over the last few days to hold back a new snapshot any longer. Snapshot 671 is now available:

• Move database vacuum process into a separate thread; reduce run frequency to once a month
• Turn down the logging output, reduce the noise in the logs (still some noise from areas that are still being worked on, but output down at least 60%, prob closer to 80%)
• r668: Fix regression bug where media vars were not being updated properly for tasks with multiple file segments
• Fix bug with client :MAX option where lowering the value below the number of active runs would confuse the task queue and the queue would stop honouring the :MAX setting
• Fix a bug where File objects were not being properly converted to MediaFile objects before substituting media vars in some circumstances; causing an error condition in the parsers
• Add two new options for client task blocks: :NOCLIENT prevents a client from accepting a task while there are clients and/or extenders connected to the SageTV server; :NORECORDING Same thing except ensure there are no active recordings

I'm still waiting for more feedback on 664 (specifically the db locked errors). I'm kind of assuming no news is good news?

[kevine]

I was wondering if anybody had ideas on how to use SJQ for the various stages of recording conversion I wish to accomplish.

I have comskip running and am looking to:
Manually verify the cuts comskip has found with Videoredo and save the commercial cut video to a subdirectory.

Automatically:
copy file back over original (here is where I think SJQ cannot help me)
handbrake to ipod format on a client machine leaving cut MPG
then mediashrink to it's final format in place and replace MPG

My thought was to create text files to indicated the stage the conversion process it is in:
XYZ.MPG
XYZ.IPOD indicating it has been commercial cut and waiting for the IPOD conversion.
XYZ.MEDIASHRINK indicating it has been converted to ipod, awaiting mediashrink conversion.

[Slugger]

Should be able to do it all, but you will have to use "dummy" (text) files as markers for the step you're on and use the FileExists test in SJQ to check which step you should be performing. Should also be able to do the copy over, but that's always an iffy step because the copy over could fail if, for example, the file were being used by something else (i.e. someone else was watching the recording). You'd have to be very careful to ensure the copy over was successful and only create the text file after you're sure the copy over was completed properly.

[kevine]

Originally Posted by Slugger

:NORECORDING Same thing except ensure there are no active recordings

I know you just put this out there but I have a request for a change. If this came with options before and after a specified time it would be more useful. For example, Handbrake sometimes takes 2-3 times the media length to convert some files. It would be great if it could limit it by:{No recordings happening from now until 3 x target media length}. This way if it begins transcoding a 30 minute program, 30-60 minutes later it would not interfere with another recording just starting.

[kevine]

Originally Posted by Slugger

Should be able to do it all, but you will have to use "dummy" (text) files as markers for the step you're on and use the FileExists test in SJQ to check which step you should be performing. Should also be able to do the copy over, but that's always an iffy step because the copy over could fail if, for example, the file were being used by something else (i.e. someone else was watching the recording).

How does SJQ perform actions on file objects not in the medial library? Are you talking about blindly copying the entire directory back with a batch file? How would you do the copy back?

Originally Posted by Slugger

You'd have to be very careful to ensure the copy over was successful and only create the text file after you're sure the copy over was completed properly.

See this is where I thought SJQ could do this task. Because if it failed, the next line of code does not run. So:

pseudocode in the client:

copy xyz.mpg to sagetvDirectory
create ipod text file

Ipod text file would not actually happen if the copy did not work. No?