Plugin: SJQv4

[Slugger]

Originally Posted by rsagetv99

Hi slugger, I noticed my shows have not been getting comskipped and after further investigation it seems that I have a corrupt database.

This started around the time that my drive ran out of space and I deleted a bunch of LOB cache files - although I thought I did it when the system was down.

I have some full backups of my SageTV directory, so I should be able to restore if that is an option. Can you give me a quick run-down of the restore procedure?

2012-11-15 21:18:00,306 INFO  [TaskQueue]: Scheduling queue processor for ~8 seconds from now!
2012-11-15 21:18:08,306 INFO  [TaskQueue]: Running queue processor now!
2012-11-15 21:18:08,306 INFO  [TaskQueue]: Enforcing licensing restrictions... license is valid!
2012-11-15 21:18:08,306 ERROR [DataStore]: SQL Error
org.h2.jdbc.JdbcSQLException: General error: "java.lang.RuntimeException: page[227] data leaf table:56 entries:10 parent:40 keys:[438, 440, 442, 444, 446, 448, 450, 452, 454, 456] offsets:[1959, 1781, 1692, 1514, 1425, 1247, 1158, 980, 891, 713] parent 40 expected 42" [50000-145]
	at org.h2.message.DbException.getJdbcSQLException(DbException.java:327)
	at org.h2.message.DbException.get(DbException.java:156)
	at org.h2.message.DbException.convert(DbException.java:279)
	at org.h2.server.TcpServerThread.sendError(TcpServerThread.java:186)
	at org.h2.server.TcpServerThread.run(TcpServerThread.java:139)
	at java.lang.Thread.run(Unknown Source)
Caused by: java.lang.RuntimeException: page[227] data leaf table:56 entries:10 parent:40 keys:[438, 440, 442, 444, 446, 448, 450, 452, 454, 456] offsets:[1959, 1781, 1692, 1514, 1425, 1247, 1158, 980, 891, 713] parent 40 expected 42
	at org.h2.message.DbException.throwInternalError(DbException.java:226)
	at org.h2.index.PageDataIndex.getPage(PageDataIndex.java:233)
	at org.h2.index.PageDataNode.find(PageDataNode.java:164)
	at org.h2.index.PageDataIndex.find(PageDataIndex.java:270)
	at org.h2.index.IndexCursor.find(IndexCursor.java:136)
	at org.h2.table.TableFilter.next(TableFilter.java:310)
	at org.h2.command.dml.Select.queryFlat(Select.java:498)
	at org.h2.command.dml.Select.queryWithoutCache(Select.java:597)
	at org.h2.command.dml.Query.query(Query.java:257)
	at org.h2.command.dml.Query.query(Query.java:227)
	at org.h2.command.CommandContainer.query(CommandContainer.java:78)
	at org.h2.command.Command.executeQuery(Command.java:132)
	at org.h2.server.TcpServerThread.process(TcpServerThread.java:278)
	at org.h2.server.TcpServerThread.run(TcpServerThread.java:137)
	... 1 more

	at org.h2.engine.SessionRemote.done(SessionRemote.java:543)
	at org.h2.command.CommandRemote.executeQuery(CommandRemote.java:152)
	at org.h2.jdbc.JdbcStatement.executeQuery(JdbcStatement.java:77)
	at com.google.code.sagetvaddons.sjq.server.DataStore.getPendingTasks(DataStore.java:556)
	at com.google.code.sagetvaddons.sjq.server.TaskQueue$QueueProcessor.run(TaskQueue.java:98)
	at java.util.TimerThread.mainLoop(Unknown Source)
	at java.util.TimerThread.run(Unknown Source)

I would, but I've never done it nor tried to do it. What I'd do in this situation: Toast the db and start with a new, empty one. If you follow this wiki doc and connect directly to the H2 server. You might find some way to repair the db? I don't know, I don't know much about the H2 db server. I just attached to it because someone else had already written the plugin for it and it was available. Restoring a full Sage backup might get you back to a stable point, but then what else are you going to lose (non-SJQ related)? Honestly, in this case, I'd probably toast the db and start new.

[Skirge01]

Originally Posted by Slugger

Not sure what's producing those errors, but that's not coming from any code I've written. Starting to wonder if there's a port conflict on the system (i.e. something else running on the same port my plugins are trying to use)? Quick googling suggests that it's some other plugin producing it. Perhaps something using Apache ActiveMQ?

I started looking into other plugins and the first one I noticed was SageTV H2 Database and that it uses 3 ports. Your plugin is also the only one showing as using that, so I assume SJQ installed it. Do those ports also need to be opened up for LAN (or WAN) access?

I also found that the sagex-api references the default 8080 port for http, which I have Jetty set to use https only and on a different port, so I never opened up 8080. I edited the firewall for that.

I also found that SageAlert was throwing some errors about missing files, so I uninstalled and reinstalled that one. I took a quick look at the logs after reinstalling and it's throwing a lot of "defined resource path does not exist" errors. It's also complaining about a missing sagealert.properties file, which I can't locate manually either. I thought that would have been reinstalled during the plugin reinstall. I'll attach the log file when I get home.

One last thing... can you delete a task completely via the UI? For example, I created a "comskip" task and it does show up as selectable, but I don't see how I could delete it if I wanted to recreate it from scratch. I'm probably just overlooking it.

[rsagetv99]

Originally Posted by Slugger

I would, but I've never done it nor tried to do it. What I'd do in this situation: Toast the db and start with a new, empty one. If you follow this wiki doc and connect directly to the H2 server. You might find some way to repair the db? I don't know, I don't know much about the H2 db server. I just attached to it because someone else had already written the plugin for it and it was available. Restoring a full Sage backup might get you back to a stable point, but then what else are you going to lose (non-SJQ related)? Honestly, in this case, I'd probably toast the db and start new.

OK, so how do I toast it? Will I be able to keep my tasks? I can still see the tasks listed in the gui, but nothing ever gets queued...

[Slugger]

Originally Posted by rsagetv99

OK, so how do I toast it? Will I be able to keep my tasks? I can still see the tasks listed in the gui, but nothing ever gets queued...

Your task definitions should be safe, they come from each agent's props file. You will lose your task history - what's been done, logs, etc. That's all stored in the db.

Toasting the db... you'll have to google H2 database and see what it has to say. I've never had to do it and I don't know off the top of my head so we're about even on the knowledge level there so I defer to google.

[Slugger]

Originally Posted by Skirge01

I started looking into other plugins and the first one I noticed was SageTV H2 Database and that it uses 3 ports. Your plugin is also the only one showing as using that, so I assume SJQ installed it. Do those ports also need to be opened up for LAN (or WAN) access?

SJQ lists H2 as a dependency. So installing SJQ forced the Sage plugin manager to install H2. See the subtle difference?

I also found that the sagex-api references the default 8080 port for http, which I have Jetty set to use https only and on a different port, so I never opened up 8080. I edited the firewall for that.

Shouldn't matter, my code only ever communicates via RMI, which is port 1098. I don't use http(s) services from sagex for anything. Other plugins might, and allowing https only may or may not cause problems.

I also found that SageAlert was throwing some errors about missing files, so I uninstalled and reinstalled that one. I took a quick look at the logs after reinstalling and it's throwing a lot of "defined resource path does not exist" errors. It's also complaining about a missing sagealert.properties file, which I can't locate manually either. I thought that would have been reinstalled during the plugin reinstall. I'll attach the log file when I get home.

If plugins aren't installing all files properly then that's a Sage plugin issue that needs to be resolved. Uninstall/reinstall usually fixes that up, but maybe not.

One last thing... can you delete a task completely via the UI? For example, I created a "comskip" task and it does show up as selectable, but I don't see how I could delete it if I wanted to recreate it from scratch. I'm probably just overlooking it.

You definitely can via the the web ui for SJQ... load a client's task definition, the page that follows has a "delete task" link. I'm pretty sure the STVi allows it somehow as well, but I don't remember.

[rsagetv99]

Originally Posted by Slugger

Your task definitions should be safe, they come from each agent's props file. You will lose your task history - what's been done, logs, etc. That's all stored in the db.

Toasting the db... you'll have to google H2 database and see what it has to say. I've never had to do it and I don't know off the top of my head so we're about even on the knowledge level there so I defer to google.

Is there a db file that I can replace from a previous backup, or can I just replace one from the installation download?

[Skirge01]

Slugger, thanks for the help so far. (I'll return to the other issues shortly.) I managed to get an agent to be recognized and a task assigned, however, it came back as "returned" in just a couple of seconds. Looking at the logs, I see:

javax.script.ScriptException: javax.script.ScriptException: groovy.lang.MissingPropertyException: No such property: stdout for class: java.lang.System

This is from code you suggested, so I changed my script to this:

consumeProcessOutput(System.stdout, System.stderr)

I have no clue what these are supposed to look like and copied yours verbatim. Was I supposed to choose one from the parenthesis?

Here's the entire code:

// I'm fairly certain your parenthesis don't match up, I don't have access to a groovy parser at the moment so
// this may still not be right, but I'm fairly certain what you pasted is invalid; I tried to fix it with the naked eye

Object mediaFile = MediaFileAPI.GetMediaFileForID(SJQ4_METADATA.get("SJQ4_ID").toInteger()) 
String channel = AiringAPI.GetAiringChannelName(mediaFile) 

/*
   Building the file name from the SJQ env vars is fine, but you already have the media file object so
   you might find it easier/more reliable to use the MediaFileAPI functions to extract the file name.
   But then again, if this is working for you then that's fine.
*/
String file = SJQ4_METADATA.get("SJQ4_PATH") + SJQ4_METADATA.get("SJQ4_LAST_SEGMENT") 
String fileType = SJQ4_METADATA.get("SJQ4_LAST_SEGMENT_TYPE") 

if(channel ==~ /WABCDT|WCBSDT|WNBCDT|WPIXDT|SYFYHD|TNTHD|USAHD|SPIKEHD|FXHD/) { 
    println "Running PRIMARYHDSKIP" 
    println file 
    def command = ['C:/comskip/comskip.exe', '--ini=C:/comskip/comskit-PRIMARYHD.ini', file].execute()
    consumeProcessOutput(System.stdout, System.stderr)
    command.waitFor() 
    if (command.exitValue())
        return 1 
    else
        return 0 
} else if(channel ==~ /WNYWDT/) { 
	println "Running WYNWDTSKIP" 
	println file 
	def command = ['C:/comskip/comskip.exe', '--ini=C:/comskip/comskip-WNYWDTSKIP.ini', file].execute() 
	consumeProcessOutput(System.stdout, System.stderr) 
	command.waitFor() 
	if (command.exitValue())
            return 1 
	else
            return 0 
} else if(channel ==~ /HSTRYHD/) { 
	println "Running HSTRYHDSKIP" 
	println file 
	def command = ['C:/comskip/comskip.exe', '--ini=C:/comskip/comskip-HSTRYSKIP.ini', file].execute() 
	consumeProcessOutput(System.stdout, System.stderr) 
	command.waitFor() 
	if (command.exitValue())
            return 1 
	else
            return 0 
} else if(channel !=~ /WNYWDT|WABCDT|WCBSDT|WNBCDT|WPIXDT|SYFYHD|TNTHD|USAHD|SPIKEHD|FXHD|HSTRYHD|HBO.*|ACMAXHD|5MAXHD|HDNETMV|MAX.*|MOMAX|STZ.*|ENC.*|SHO.*|TMC.*|PPV.*/) {
	println "Running PRIMARYHDSKIP (Default)" 
	println file 
	def command = ['C:/comskip/comskip.exe', '--ini=C:/comskip/comskip-PRIMARYHDSKIP.ini', file].execute() 
	consumeProcessOutput(System.stdout, System.stderr) 
	command.waitFor() 
	if (command.exitValue())	
            return 1 
	else
            return 0 
} else {
        println 'Not running comskip for this recording!'
        return 0
}

This is what happens when non-programmers get a hold of code.

[Skirge01]

Here's the log files I promised. They've gotten pretty big and a bunch of changes have been made since they started, so I tried to limit it to about the last hour or so.

[Slugger]

Originally Posted by rsagetv99

Is there a db file that I can replace from a previous backup, or can I just replace one from the installation download?

SJQ creates the db on the fly on initial startup if it doesn't exist. You will need to delete the existing db. You will have to google how to do that for H2. If you're still having problems in a couple days when I return from out of town then I might be able to assist more then.

[Slugger]

Originally Posted by Skirge01

Slugger, thanks for the help so far. (I'll return to the other issues shortly.) I managed to get an agent to be recognized and a task assigned, however, it came back as "returned" in just a couple of seconds. Looking at the logs, I see:

javax.script.ScriptException: javax.script.ScriptException: groovy.lang.MissingPropertyException: No such property: stdout for class: java.lang.System

This is from code you suggested, so I changed my script to this:

consumeProcessOutput(System.stdout, System.stderr)

I have no clue what these are supposed to look like and copied yours verbatim. Was I supposed to choose one from the parenthesis?

Here's the entire code:

// I'm fairly certain your parenthesis don't match up, I don't have access to a groovy parser at the moment so
// this may still not be right, but I'm fairly certain what you pasted is invalid; I tried to fix it with the naked eye

Object mediaFile = MediaFileAPI.GetMediaFileForID(SJQ4_METADATA.get("SJQ4_ID").toInteger()) 
String channel = AiringAPI.GetAiringChannelName(mediaFile) 

/*
   Building the file name from the SJQ env vars is fine, but you already have the media file object so
   you might find it easier/more reliable to use the MediaFileAPI functions to extract the file name.
   But then again, if this is working for you then that's fine.
*/
String file = SJQ4_METADATA.get("SJQ4_PATH") + SJQ4_METADATA.get("SJQ4_LAST_SEGMENT") 
String fileType = SJQ4_METADATA.get("SJQ4_LAST_SEGMENT_TYPE") 

if(channel ==~ /WABCDT|WCBSDT|WNBCDT|WPIXDT|SYFYHD|TNTHD|USAHD|SPIKEHD|FXHD/) { 
    println "Running PRIMARYHDSKIP" 
    println file 
    def command = ['C:/comskip/comskip.exe', '--ini=C:/comskip/comskit-PRIMARYHD.ini', file].execute()
    consumeProcessOutput(System.stdout, System.stderr)
    command.waitFor() 
    if (command.exitValue())
        return 1 
    else
        return 0 
} else if(channel ==~ /WNYWDT/) { 
	println "Running WYNWDTSKIP" 
	println file 
	def command = ['C:/comskip/comskip.exe', '--ini=C:/comskip/comskip-WNYWDTSKIP.ini', file].execute() 
	consumeProcessOutput(System.stdout, System.stderr) 
	command.waitFor() 
	if (command.exitValue())
            return 1 
	else
            return 0 
} else if(channel ==~ /HSTRYHD/) { 
	println "Running HSTRYHDSKIP" 
	println file 
	def command = ['C:/comskip/comskip.exe', '--ini=C:/comskip/comskip-HSTRYSKIP.ini', file].execute() 
	consumeProcessOutput(System.stdout, System.stderr) 
	command.waitFor() 
	if (command.exitValue())
            return 1 
	else
            return 0 
} else if(channel !=~ /WNYWDT|WABCDT|WCBSDT|WNBCDT|WPIXDT|SYFYHD|TNTHD|USAHD|SPIKEHD|FXHD|HSTRYHD|HBO.*|ACMAXHD|5MAXHD|HDNETMV|MAX.*|MOMAX|STZ.*|ENC.*|SHO.*|TMC.*|PPV.*/) {
	println "Running PRIMARYHDSKIP (Default)" 
	println file 
	def command = ['C:/comskip/comskip.exe', '--ini=C:/comskip/comskip-PRIMARYHDSKIP.ini', file].execute() 
	consumeProcessOutput(System.stdout, System.stderr) 
	command.waitFor() 
	if (command.exitValue())	
            return 1 
	else
            return 0 
} else {
        println 'Not running comskip for this recording!'
        return 0
}

This is what happens when non-programmers get a hold of code.

System.out and System.err (not System.stdout and System.stderr). Let me know if you're still having problems and I'll peek at the logs when I return from out of town.

[Skirge01]

Originally Posted by Slugger

System.out and System.err (not System.stdout and System.stderr). Let me know if you're still having problems and I'll peek at the logs when I return from out of town.

Thanks a million, Slugger. That seems to have done it. Sorry you have to deal with amateurs like me.

Also, for anyone who might decide to try and reuse this (God help them!), I also needed to edit the "file" string to include a final backslash because Sage doesn't add them. I did it by making the following change:

Old:

String file = SJQ4_METADATA.get("SJQ4_PATH") + SJQ4_METADATA.get("SJQ4_LAST_SEGMENT")

New:

String file = SJQ4_METADATA.get("SJQ4_PATH") + "\\" + SJQ4_METADATA.get("SJQ4_LAST_SEGMENT")

[Skirge01]

Now that I've got that worked out (after lots of help), I'm moving onto the next item I'd like SJQ to handle. Is there a script to reschedule SD programs to record their HD versions when it airs and delete the SD recording? I had this in SJQ3 and I saw someone else asked about it around page 7 of this thread, but I didn't see any code posted for the task.

[rsagetv99]

Originally Posted by Slugger

SJQ creates the db on the fly on initial startup if it doesn't exist. You will need to delete the existing db. You will have to google how to do that for H2. If you're still having problems in a couple days when I return from out of town then I might be able to assist more then.

That helped, thanks.

For those interested, I stopped Sage, deleted everything in the sjq\sjq4.lbos.db directory as well as deleting the sjq.log, all of the sjq.log.(n) log files, and the two .db files (sjq4ht.db and sjq4.trace.db). Once that was completed I restarted Sage and checked the logs and the Queue and could see that everything was working again.

Also, to be a little safer you could move the files listed above into a backup folder before you delete them to be sure that it does not break anything when Sage comes up.

[Slugger]

Originally Posted by Skirge01

Now that I've got that worked out (after lots of help), I'm moving onto the next item I'd like SJQ to handle. Is there a script to reschedule SD programs to record their HD versions when it airs and delete the SD recording? I had this in SJQ3 and I saw someone else asked about it around page 7 of this thread, but I didn't see any code posted for the task.

Thought I ported that to groovy, but I don't see it in my repo of scripts. Check for replies to the original request in this thread. Did I reply with a script? I feel like I've written it, but I don't have it handy. Basically, you just need to scan all existing SD recordings, search the EPG for future HD airings, then schedule the HD airing to record. Optionally, delete the SD recording.

[Skirge01]

Originally Posted by Slugger

Thought I ported that to groovy, but I don't see it in my repo of scripts. Check for replies to the original request in this thread. Did I reply with a script? I feel like I've written it, but I don't have it handy. Basically, you just need to scan all existing SD recordings, search the EPG for future HD airings, then schedule the HD airing to record. Optionally, delete the SD recording.

I didn't see it, but I'll search again. LOL! You make it sounds so easy!

Any idea why I keep getting messages about "Process killed by SJQ" for tasks which actually completed successfully. They seem to be ending with a "returned" status (and then getting processed again), so I'm wondering if I have something messed up with the rcmin/rcmax values or in the script. I tried reversing those two values in SJQ, but it doesn't seem to have helped.

[Slugger]

Your task has a max runtime set on it and that run time is too short. Either disable the max run time or increase it so it's sufficiently long for the expected run time of the task.

[Skirge01]

Originally Posted by Slugger

Your task has a max runtime set on it and that run time is too short. Either disable the max run time or increase it so it's sufficiently long for the expected run time of the task.

The maxtime is set to the default of 86400 and it's failing in about 21.1 minutes, so that shouldn't be the culprit. I did find the maxtimeratio set to 1.0, but the wiki said that's not implemented, so I originally left that at the default. Just for the heck of it, I upped that to 3.0. I also enabled the sysmsgonfail so that I'd get a notice and email (via SageAlert) exactly when one fails.

I'll let these run overnight and see what kind of messages (and how many) I have in the morning. Would a "0" disable the maxtime or should I just comment it out? I'll try disabling that in the morning, assuming I still have failures.

[Skirge01]

Since SJQ is still apparently killing these tasks, I increased the maxtime to 604800 (1 week) and upped the maxtimeratio to 5.0. One comskip task ran for nearly 6 hours, so I also reduced the number of tasks which can run to just one for now.

Strangely, I didn't get an email on the "returned" tasks. I guess that doesn't count as a failure of the exe?

[Slugger]

Originally Posted by Skirge01

Since SJQ is still apparently killing these tasks, I increased the maxtime to 604800 (1 week) and upped the maxtimeratio to 5.0. One comskip task ran for nearly 6 hours, so I also reduced the number of tasks which can run to just one for now.

The ratio is never used. If it's still being killed then I'd like to know how long it runs before being killed. If it's a short time then it could be an issue with the commons-exec lib, but unfortunately I don't have enough log statements in that area of the code to really track it down without a new build.

Strangely, I didn't get an email on the "returned" tasks. I guess that doesn't count as a failure of the exe?

Correct.

[Skirge01]

Originally Posted by Slugger

The ratio is never used. If it's still being killed then I'd like to know how long it runs before being killed. If it's a short time then it could be an issue with the commons-exec lib, but unfortunately I don't have enough log statements in that area of the code to really track it down without a new build.

With just one task running, it ran from 15:21 to 16:51 and 15 seconds after finishing, it started it again. I'll post back the times for this latest run to see if it's the exact same 90 minutes. If it holds true, that would mean it should be done at 18:21.

I am curious about something, though. Is there a way to know if SJQ is successfully killing the task? I ask because I could swear that I once killed a task after only a few minutes and it still ran to completion over an hour later.

EDIT: Right on schedule, it stopped after 90 minutes and then started again.

EDIT #2: It also doesn't appear that SJQ literally kills the process, as I killed the one from above and the next task started, while the original one is still running in task manager.