Plugin: Sage Job Queue (SJQ) v3

[FidgetyRat]

I set up a test last night where I recorded 2 shows. 1 random cartoon, and a movie. When the time period where the moves were allowed to take place was hit, it moved the cartoon successfully, but failed to move the movie. I was wonding if you could help me figure out why this hapened. Same rule, 2 recordings same day, one failed.

The GOOD transfer.

Thu Jun 17 00:01:18 EDT 2010
Source: \\TeaVii\Recordings\Chowder-HandsonaBigMixerTheBlastRaz-3433867-0.mpg
Target: \\Ambry\SageTV\Recordings
Renaming source file... DONE!
Copying source file to target directory... DONE!
Deleting source media object in SageTV... DONE!
Renaming target file... DONE!
Creating SageTV media object for target file... DONE!
Relinking target file to SageTV airing... DONE!
Deleting source file... DONE!
Copying artifacts... DONE!
Archive operation completed SUCCESSFULLY!
Thu Jun 17 00:03:01 EDT 2010

The BAD Transfer

java.io.IOException: Deletion of source failed!
	at com.google.code.sagetvaddons.sjq.server.tasks.TvArchiver.delSourceMedia(TvArchiver.java:645)
	at com.google.code.sagetvaddons.sjq.server.tasks.TvArchiver.run(TvArchiver.java:360)
	at com.google.code.sagetvaddons.sjq.server.InternalTaskClient.moveRec(InternalTaskClient.java:169)
	at com.google.code.sagetvaddons.sjq.server.InternalTaskClient.performTask(InternalTaskClient.java:114)
	at com.google.code.sagetvaddons.sjq.server.InternalTaskClient.run(InternalTaskClient.java:61)
	at java.lang.Thread.run(Unknown Source)
Thu Jun 17 00:03:01 EDT 2010
Source: \\TeaVii\Recordings\EvanAlmighty-3485556-0.mpg
Target: \\Ambry\SageTV\Recordings
Renaming source file... DONE!
Copying source file to target directory... DONE!
Deleting source media object in SageTV... FAILED!
Rolling back archival attempt due to a step failing!
Deleting target file... DONE!
Renaming source file... DONE!
Deleting target media object in SageTV... ALREADY DONE!
Recreating source media object in SageTV... ALREADY DONE!
Relinking source media object to airing object... DONE!
Rollback completed SUCCESSFULLY!

It seems to me like SageTV had some kind of internal lock, that the file itself was transferred, but _MOVEREC could not update sage's database, so it rolled back, deleted the archived recording, and everted back to normal.

For additional information, this rule was executed 4 times last night (every 2 hours automatically) and it failed all 4 times. This also raises eyebrows as I do not allow SJQ to retry failed attempts without my intervention. Not sure why this tried 4 times when it should have given up after the first. (Actually, I see now, that each time the _MOVEREC fails, it assigns a new object ID, so that must be why it repeats).

[Slugger]

You've pretty much identified the problem. SJQ tried to delete the old entry in wiz.bin and it failed (Sage returned false/wouldn't do it). You'd have to enable Sage debug logging and see if it logs any reason as to why the delete attempt failed. The rollback should be using the same media id as the original so it shouldn't be retrying a failed attempt. Though a quick look at the code confuses me a little so I could see how it might be creating a new media file on each rollback.

Anyway, I'd suggest enabling debug logging and trying to find out why SJQ can't delete that one media object from wiz.bin and hopefully fix that issue. That should get you going again. With some API changes provided in Sage v7, I have plans to modify this task to support these new API features, which will allow for moving of multi-segment recordings and remove the need to copy the files and create new media objects, etc. Just not sure when I'll get around to it.

[FidgetyRat]

Thanks.

Unfortunately things got really funky and the recording ended up getting orphaned. Since it was just a test file, I ended up deleting it early this morning. I'll keep my eye on future recordings to see if it happens again.

[FidgetyRat]

Is there a way to know or configure which directories file cleaner is run against? It doesn't seem to run on my NAS storage. My guess is you have it set to only work on recording directories defined in sage?

[Slugger]

Originally Posted by FidgetyRat

Is there a way to know or configure which directories file cleaner is run against? It doesn't seem to run on my NAS storage. My guess is you have it set to only work on recording directories defined in sage?

Yes, it only runs on recording directories. However, if you're on Sage v7 then I'd recommend clearing out those settings and installing my Sage Artifact Delete plugin. That plugin will work on any directory. The file cleaner in SJQ will be removed in a future version (superseded by the SAD plugin).

[Jackal24]

Ok. I am new to SJQ and am not a programmer, but I have been able to get it to work using comskip on certain shows.

Now I am trying to get it to work with handbrake. Below are my files. When I run it on a program, it goes into the active queue and then straight to the failed section. I'm not sure where the problem is, so I would love some help.

Ruleset Editor:

// TESTTESTTESTTESTTESTTEST
if [IsObjMediaFile == true && $.IsTVFile{} == true && $.IsAiringHDTV{} == false && ($.GetShowTitle{} =% "History Detectives")] {
CODEIT
}

client:

CODEIT {
:RESOURCES 51
:CPU "BELOWNORMAL"
:MAXRUNRATIO 3
:MAX 1
"\"C:/handbrake/encode.bat\" \"%c%\""
}

encode.bat

cd \handbrake
handbrakecli.exe -i %1 -o "c:\ttt\%~n1.mp4" --preset="AppleTV"
if not exist "c:\ttt\%~n1.mp4" goto failure
exit 0
:failure
exit 1

[FidgetyRat]

Originally Posted by Jackal24

it goes into the active queue and then straight to the failed section. I'm not sure where the problem is, so I would love some help.

If you click on the entry in the failed list, it will have a "show log" option. This should contain whatever error causing it to go to the failed list.


I ran another test last night, this time with 2 cartoons and 1 movie.

Cartoon #1: transferred fine. *but another error*
Cartoon #2: failed due to the sage database delete error I mentioned earlier, but ended up finally transferring after a retry.
Movie: failed due to sage database error. Never made it.


Cartoon 1: which transferred fine has a _MOVEREC at priority 100 and then an _UNARCHIVE at priority 0. I guess the _MOVEREC assigns a new recording ID, so the _UNARCHIVE fails with the following:

"WARN [TaskQueue]: Wanted to return object media/3495249, but didn't because SageTV API returns null for that object now (did you delete it before it was assigned to a task client?)"

Also note, that once this manual file was transferred, it lost its manual recording status, so it now looks like a live-tv recording.


Cartoon 2:
This one initially failed due to the unable to delete from sage database and rollback error. When it failed, it caused the .edl to be cleaned up by your SAD plugin (since _MOVEREC deletes the original from sage). comskip then had to re-run and later in the evening the _MOVEREC was called again and this time it worked. (As we mentioned earlier _MOVEREC seems to be creating a separate ID after the move which causes the failed job to keep repeating...


Movie
This is another odd case. It tried twice to move the video and failed both times. As with the cartoon, comskip had to be re-run because the .edl got wiped by the _MOVEREC triggering a delete. Where this gets really bad is that the recording lost its manual recording status, so this fails:

Evaluating '$.IsNotManualOrFavorite{} == "false"' == false

Therefore, my comskip rule will never be allowed to run on it, and without comskip, it will not move to the NAS.




I wish I could have some "sage" insight to what is going on inside the _MOVEREC command, but right now considering the extremely low chance of it working, and the bad side effects such as losing recording flags, I'd label this command as broken.



Is there any alternative to relocating files that doesn't use this command? Would it just be safer to call a batch command to copy the files over, and then let sage's auto media rescan find the new location? I'm pretty sure sage automatically updates the original database files with the new file path during a rescan. When I have reinstalled sage in the past, it found all my recordings regardless of their new home.

[Slugger]

Originally Posted by FidgetyRat

If you click on the entry in the failed list, it will have a "show log" option. This should contain whatever error causing it to go to the failed list.


I ran another test last night, this time with 2 cartoons and 1 movie.

Cartoon #1: transferred fine. *but another error*
Cartoon #2: failed due to the sage database delete error I mentioned earlier, but ended up finally transferring after a retry.
Movie: failed due to sage database error. Never made it.


Cartoon 1: which transferred fine has a _MOVEREC at priority 100 and then an _UNARCHIVE at priority 0. I guess the _MOVEREC assigns a new recording ID, so the _UNARCHIVE fails with the following:

"WARN [TaskQueue]: Wanted to return object media/3495249, but didn't because SageTV API returns null for that object now (did you delete it before it was assigned to a task client?)"

Also note, that once this manual file was transferred, it lost its manual recording status, so it now looks like a live-tv recording.

Ok, that's sort of a bug in that I'd say I'd expect it to work like you do, but it doesn't because of the fact that, in the current implementation, in order to move a file you have to delete the old media object in the Sage db and create a new one. The fact that it loses its manual flag is a side effect caused by Sage, not SJQ.

Good news: Sage v7 provides API enhancements to make this task a lot easier/safer to run in that I can reuse the same media id, etc.

Bad news: My time is at a premium these days so I wouldn't hold my breath as to when I'll implement the new algorithm for Sage v7.

Good news: I'm always willing to accept patches from anyone willing to fix it up.

Cartoon 2:
This one initially failed due to the unable to delete from sage database and rollback error. When it failed, it caused the .edl to be cleaned up by your SAD plugin (since _MOVEREC deletes the original from sage). comskip then had to re-run and later in the evening the _MOVEREC was called again and this time it worked. (As we mentioned earlier _MOVEREC seems to be creating a separate ID after the move which causes the failed job to keep repeating...

_MOVEREC creates a new id because this was necessary in Sage v6.x. SAD will cleanup 30 seconds after the delete is triggered. That's how it works, unfortunately.

As the docs make very clear, _MOVEREC is experimental. Personally, I use it daily and have never had problems, but I don't claim it's perfect.

Movie
This is another odd case. It tried twice to move the video and failed both times. As with the cartoon, comskip had to be re-run because the .edl got wiped by the _MOVEREC triggering a delete. Where this gets really bad is that the recording lost its manual recording status, so this fails:

Evaluating '$.IsNotManualOrFavorite{} == "false"' == false

Therefore, my comskip rule will never be allowed to run on it, and without comskip, it will not move to the NAS.

Yeah, again, that's a side effect caused by Sage. Really nothing I can do here.

I wish I could have some "sage" insight to what is going on inside the _MOVEREC command, but right now considering the extremely low chance of it working, and the bad side effects such as losing recording flags, I'd label this command as broken.

The source code is here (again, I'm always willing to accept patches). And based on everything you've provided, I'd argue the command itself isn't broken - as a matter of fact it tries to do what it's suppose to do and when it encounters an error (unable to delete entry in wiz.bin) then it rolls back the operation and restores your recording (as best it can given the side effects caused by the core). What's "broken" is that for whatever reason Sage API calls to delete media objects are failing when they shouldn't (as far as I can tell). Again, I'll suggest that you enable Sage debug logging and look for clues as to why that API call is failing. Fix the failing API call and the _MOVEREC task should succeed.

Is there any alternative to relocating files that doesn't use this command? Would it just be safer to call a batch command to copy the files over, and then let sage's auto media rescan find the new location? I'm pretty sure sage automatically updates the original database files with the new file path during a rescan. When I have reinstalled sage in the past, it found all my recordings regardless of their new home.

Yes, you can just move the files and let Sage rediscover them. It's not immediate, but it should work. Sage v7 also provides better support for doing what _MOVEREC does, but, as I've said, I just have to find the time to do it. Unfortunately, since _MOVEREC works perfectly for me along with the fact that time is at a premium for my Sage projects these days, I don't see me taking the time to "fix" this anytime in the immediate future (i.e. next month or two). However, I will eventually update it.

[FidgetyRat]

Thanks. I hear you on no time anymore. I wish I had the smarts to patch it for you, but unfortunately I too lack the time.

I think for now I'll write a copy script to move the files and let the periodic media rescan notice they moved and adjust accordingly. I'll give that a try tonight.

[bikesquid]

Originally Posted by Jackal24

Ok.
Now I am trying to get it to work with handbrake. Below are my files. When I run it on a program, it goes into the active queue and then straight to the failed section. I'm not sure where the problem is, so I would love some help.

I think you're missing a '/d' on your change directory command... if you're changing drive letters.... without that you'll bounce fast.

Just a thought: As you want this to run after comskip and doing so is straightforward in a batch file, why not setup the initial rule to split off the whole process, a 'comskip and handbrake' ruleset that will then do things in order via a single batch file?
Something like:
Ruleset

// TESTTESTTESTTESTTESTTEST
if [IsObjMediaFile == true && $.IsTVFile{} == true && $.IsAiringHDTV{} == false && ($.GetShowTitle{} =% "History Detectives")] {
CODEIT
}

Client

CODEIT {
:RESOURCES 51
:CPU "BELOWNORMAL"
:MAXRUNRATIO 3
:MAX 1
:RETURNCODE 0
"\"C:\\Program Files\\Comskip\\comskipHB.bat\" \"%c%\""

ComskipHB.bat

C:\Program Files\Comskip\comskip.exe %1
if errorlevel 1 goto hb
exit 0

:hb
cd /D C:\handbrake
handbrakecli.exe -i %1 -o "c:\ttt\%~n1.mp4" --preset="AppleTV"
if not exist "c:\ttt\%~n1.mp4" goto failure
exit 0

:failure
exit 1

[Jackal24]

Thanks for the help. As far as putting comskip in the batch file, I run comskip on a different subset of files. For example, a lot of the shows I will transcode are from PBS and therefore don't need comskip.

[Slugger]

Originally Posted by FidgetyRat

Thanks. I hear you on no time anymore. I wish I had the smarts to patch it for you, but unfortunately I too lack the time.

I think for now I'll write a copy script to move the files and let the periodic media rescan notice they moved and adjust accordingly. I'll give that a try tonight.

Good news (for you)/bad news (for me): My system tried its first _MOVEREC task since upgrading to 7.0.11 and it failed in the exact same manner as you've reported.

Why is this good news? This is going to be fixed a whole lot quicker now...

NOTE: The _MOVEREC task is definitely useless in SageTV 7.0.11. It may have become useless in a previous beta, but I will not be rolling back to find out. If you're on 7.0.11 then you should stop using the _MOVEREC task immediately!

A fix won't be immediately, but probably within the next week or so.

[FidgetyRat]

So far the use of the batch scripts is working out great. Sage is relinking as expected throughout the night, and any flags that are not getting set are easy enough to detect and fix. Pretty nifty plugin.


Is there an option to detect if a recording is being watched? I see there is on to see if server or client are watching "media" but it doesn't indicate whether or not its the file in question. I'd rather not attempt to move a recording on the off chance someone is up past 12am watching. If not, I can shift it to 3am worst case.

[Slugger]

Originally Posted by FidgetyRat

So far the use of the batch scripts is working out great. Sage is relinking as expected throughout the night, and any flags that are not getting set are easy enough to detect and fix. Pretty nifty plugin.


Is there an option to detect if a recording is being watched? I see there is on to see if server or client are watching "media" but it doesn't indicate whether or not its the file in question. I'd rather not attempt to move a recording on the off chance someone is up past 12am watching. If not, I can shift it to 3am worst case.

No such test currently exists. Additions to the API in v7 will make this test possible to implement safely, I believe. I'd recommend opening an issue ticket at the project site in order for me to remember to have a look when time permits.

[Slugger]

It's amazing how fast things get fixed when it breaks my setup.

New SJQ build (871) now in repository. Fixes the _MOVEREC task to work properly with SageTV v7.x. Note, however, that _MOVEREC should still be considered an experimental feature, but with that said the new implementation for _MOVEREC is much more simplistic. All it does now is move the recording to its destination, move the artifacts then schedule a rescan so the core picks up the new location.

I'd actually really like someone to review the code and provide feedback. Initial testing looks good.

Basic overview of what _MOVEREC now does:

• Moves ALL file segments to target dir (supports moving of multi-segment recordings)
• If any segment fails to move then any other segments copied are moved back
• After all segments are successfully moved, find artifacts for those segments and move them to the target dir; artifacts that fail to move are logged, but it's not a fatal error (i.e. nothing is rolled back)
• After all file moves are completed, schedule a rescan of the media dirs by the core. This is delayed 30 mins in order to let other possible _MOVEREC tasks in the queue complete. Instead of triggering a scan after each _MOVEREC, each one resets the timer to 30 mins so as not to trigger a bunch of successive media scans
• After a media scan is run, any media objects that were successfully moved are then deleted from wiz.bin

[FidgetyRat]

Just wanted to let you know that I updated my server configs to use the new version you just released and test the _MOVEREC. I just triggered it on 5 recordings and they all moved to the drive. I'll have to wait the 30 minutes to see if the rescan finds them all, but at least the transfer worked.

Update: The Rescan just completed. Seems to have worked fine for the 6 recordings I moved including their EDLs. Sage seems to have adapted through the rescan with no problems.

[graywolf]

Situation: Wife wants to record both showings of a show daily via favorites. Then later, verify/watch 1st showing and if "good" (no blips due to bad weather, "Special News Alerts", etc) then archive that one and delte the 2nd recording, otherwise check 2nd to verify good and archive that one.

Was working using 2 Favorites restricted by Hour/Channel because it turns out the ShowID was SH and not EP so episodes were not unique. Now it appears that has changed and the EPG now has EP for the ShowID and only the first recording is happening.

So, after the 1st showing occurs, if I have a Task which uses MANUALREC, would that then have the 2nd Favorite pop in and then record? Or would the 2nd not record because even though 1st was changed to Manual, Sage still knows it was recorded already?

Or would I use RESCHED SAMECHANNEL NODELETE to accomplish the same thing?

Not at home currently to test.

[Slugger]

MANUALREC definitely won't work. The core will still see it's already recorded the show id and ignore it.

RESCHED w/ NODELETE SAMECHANNEL should work because it'll reschedule it as a manual recording, which will override the fact that the show id is already recorded.

[graywolf]

OK. Got a RESCHED task setup. Will see how it works.

One other question, my wife usually pads this show by 1 min (start/end). Any means of maintaining that with the RESCHED task? or another task/method?

[Slugger]

Originally Posted by graywolf

OK. Got a RESCHED task setup. Will see how it works.

One other question, my wife usually pads this show by 1 min (start/end). Any means of maintaining that with the RESCHED task? or another task/method?

Nothing in SJQ to handle this. You'd have to write your own custom task to do this.