Problems with jobrun

We use jobrun extensively and as of last Friday, we are suddenly having problems with two jobs that use jobrun. They try to do it and return the message "Job not found in the active job pool". The target job does exist, is named correctly and is not disabled.

We can manually run the target job, and there were no changes made on Friday.

Help!

This is probably a silly question, but have you tried to restart the scheduler. Do you see any changes in job states?

We have done a scheduler service restart yes, at no point does the jobs in question appear disabled, we've also tried disabling and re-enabling them.

Ok. Do you get the same result when you use JobRun referring to a job id rather then job name?

I assume you can create a test job and try that.

// run job using job id
JobRun 55

// run job using job name
JobRun "Some Job"

By the way, in which mode the caller jobs are currently setup to run? Attached or detached mode? If detached, please uncheck that job property.

So I've tried to set up a script job to test this via the 24x7 remote control console (3.6.2 just like the master scheduler) and I'm getting a strange error on save remote;
UNable to create new job on remote host *compname*. Insufficient privileges to create this type of job.

The account I'm using to connect is in the administrators group within 24x7 job db security. It's not a windows account.

The jobs that are calling jobrun are detached but thats not the problem as we have another hundred or so jobs which do *exactly* the same thing that still do work.

Please check that the group Administrators in 24x7 settings (Tools -> Security -> Job Database Users and Permissions) still has permissions for everything.

If you don't have tracing enabled, please enable tracing option in the scheduler settings. You may need to do that locally. Stop the 24x7 service, start 24x7 in GUI mode, change trace option, close GUI and restart the service. Run the job featuring non-working JobRun then review debug.log for anomalies or errors. If you see suspicious messages in debug.log please post the relevant fragment of the log file.

I've checked that admins still has full access, it does, each box is gray and ticked.

I've turned on tracing, the failure to save a job from the remote control console is not shown in the debug, schedule, or master logs on the server.

Here's the debug from a JSP web console run of one of the offending jobs just now

30/09/2009 12:21:09.724 0 0 0 DEBUG [THREAD 7992] JobEngine - RUN - Processing job #1302; Job type:S; Async: false
30/09/2009 12:21:09.739 0 0 0 DEBUG [THREAD 7992] ScriptEngine Instance 14788352 - SharedObjectGet - Script Library SUCCESSFUL
30/09/2009 12:21:09.895 0 0 0 DEBUG [THREAD 7992] ScriptEngine Instance 14788352 - Script Library found 44 statements.
30/09/2009 12:21:10.020 0 0 0 DEBUG [THREAD 7992] ScriptEngine Instance 14788352 - Stack depth: 1
30/09/2009 12:21:11.505 0 0 0 DEBUG [THREAD 7992] Run: WaitFor return code: 0
30/09/2009 12:21:11.520 0 0 0 DEBUG [THREAD 7992] Run: OK
30/09/2009 12:21:11.708 0 0 0 DEBUG [THREAD 7992] ScriptEngine Instance 113318448 destroyed
30/09/2009 12:21:11.724 0 0 0 DEBUG [THREAD 7992] UE - JOB_RUN: Starting job Postlink_PL100_out:30
30/09/2009 12:21:11.927 2 1302 0 DEBUG [THREAD 7992] Postlink_PL100_out:20: An error occurred while executing automation script: Line 13: Job 'Postlink_PL100_out:30' not found in the active job pool.
30/09/2009 12:21:11.942 0 0 0 DEBUG [THREAD 7992] Processing notification event of type 2
30/09/2009 12:21:11.942 0 0 0 DEBUG [THREAD 7992] ScriptEngine Instance 14788352 destroyed
30/09/2009 12:21:12.177 2 1302 0 DEBUG [THREAD 7992] Postlink_PL100_out:20: Remote job execution error. Exit code: -1. An error occurred while executing automation script: Line 13: Job 'Postlink_PL100_out:30' not found in the active job pool.
30/09/2009 12:21:12.177 0 0 0 DEBUG [THREAD 7992] Gateway: Job #1302 - remote process ended with exit code: -1
30/09/2009 12:21:12.177 0 0 0 DEBUG [THREAD 7992] Gateway: Job #1302 - Thread ended
30/09/2009 12:21:12.395 2 1302 0 DEBUG [THREAD 7992] Postlink_PL100_out:20: Remote job failed. Exit code: -1. An error occurred while executing automation script: Line 13: Job 'Postlink_PL100_out:30' not found in the active job pool.
30/09/2009 12:21:12.395 0 0 0 DEBUG [THREAD 7992] [default] Queue Manager: Disconnecting from agent LOCAL
30/09/2009 12:21:12.395 0 0 0 DEBUG [THREAD 7992] Processing notification event of type 2
30/09/2009 12:21:12.630 2 0 0 DEBUG [THREAD 7992] 24x7 Scheduler: Internal Error #6/95 occurred in getperformancedata while executing getperformancedata. Error: Invalid DataWindow row/column specified
30/09/2009 12:21:12.630 2 0 0 DEBUG [THREAD 7992] Internal Error #6/95 occurred in getperformancedata while executing getperformancedata. Error: Invalid DataWindow row/column specified
30/09/2009 12:21:13.177 2 0 0 DEBUG [THREAD 7992] 24x7 Scheduler: Internal Error #6/6 occurred in writeperformancedata while executing writeperformancedata. Error: Invalid DataWindow row/column specified
30/09/2009 12:21:13.192 2 0 0 DEBUG [THREAD 7992] Internal Error #6/6 occurred in writeperformancedata while executing writeperformancedata. Error: Invalid DataWindow row/column specified
30/09/2009 12:21:13.192 0 0 0 DEBUG [THREAD 7992] Job #-1 - saving job perfornance data
30/09/2009 12:21:13.427 2 0 0 DEBUG [THREAD 7992] 24x7 Scheduler: Internal Error #6/8 occurred in writeperformancedata while executing writeperformancedata. Error: Invalid DataWindow row/column specified
30/09/2009 12:21:13.442 2 0 0 DEBUG [THREAD 7992] Internal Error #6/8 occurred in writeperformancedata while executing writeperformancedata. Error: Invalid DataWindow row/column specified
30/09/2009 12:21:13.708 2 0 0 DEBUG [THREAD 7992] 24x7 Scheduler: Internal Error #6/8 occurred in writeperformancedata while executing writeperformancedata. Error: Invalid DataWindow row/column specified
30/09/2009 12:21:13.708 2 0 0 DEBUG [THREAD 7992] Internal Error #6/8 occurred in writeperformancedata while executing writeperformancedata. Error: Invalid DataWindow row/column specified
30/09/2009 12:21:13.911 2 0 0 DEBUG [THREAD 7992] 24x7 Scheduler: Internal Error #6/8 occurred in writeperformancedata while executing writeperformancedata. Error: Invalid DataWindow row/column specified
30/09/2009 12:21:13.911 2 0 0 DEBUG [THREAD 7992] Internal Error #6/8 occurred in writeperformancedata while executing writeperformancedata. Error: Invalid DataWindow row/column specified
30/09/2009 12:21:14.146 2 0 0 DEBUG [THREAD 7992] 24x7 Scheduler: Internal Error #6/8 occurred in writeperformancedata while executing writeperformancedata. Error: Invalid DataWindow row/column specified
30/09/2009 12:21:14.161 2 0 0 DEBUG [THREAD 7992] Internal Error #6/8 occurred in writeperformancedata while executing writeperformancedata. Error: Invalid DataWindow row/column specified
30/09/2009 12:21:14.349 2 0 0 DEBUG [THREAD 7992] 24x7 Scheduler: Internal Error #6/8 occurred in writeperformancedata while executing writeperformancedata. Error: Invalid DataWindow row/column specified
30/09/2009 12:21:14.364 2 0 0 DEBUG [THREAD 7992] Internal Error #6/8 occurred in writeperformancedata while executing writeperformancedata. Error: Invalid DataWindow row/column specified
30/09/2009 12:21:14.567 2 0 0 DEBUG [THREAD 7992] 24x7 Scheduler: Internal Error #6/8 occurred in writeperformancedata while executing writeperformancedata. Error: Invalid DataWindow row/column specified
30/09/2009 12:21:14.567 2 0 0 DEBUG [THREAD 7992] Internal Error #6/8 occurred in writeperformancedata while executing writeperformancedata. Error: Invalid DataWindow row/column specified
30/09/2009 12:21:14.786 2 0 0 DEBUG [THREAD 7992] 24x7 Scheduler: Internal Error #6/8 occurred in writeperformancedata while executing writeperformancedata. Error: Invalid DataWindow row/column specified
30/09/2009 12:21:14.786 2 0 0 DEBUG [THREAD 7992] Internal Error #6/8 occurred in writeperformancedata while executing writeperformancedata. Error: Invalid DataWindow row/column specified
30/09/2009 12:21:14.989 2 0 0 DEBUG [THREAD 7992] 24x7 Scheduler: Internal Error #6/8 occurred in writeperformancedata while executing writeperformancedata. Error: Invalid DataWindow row/column specified
30/09/2009 12:21:14.989 2 0 0 DEBUG [THREAD 7992] Internal Error #6/8 occurred in writeperformancedata while executing writeperformancedata. Error: Invalid DataWindow row/column specified
30/09/2009 12:21:15.224 2 0 0 DEBUG [THREAD 7992] 24x7 Scheduler: Internal Error #6/8 occurred in writeperformancedata while executing writeperformancedata. Error: Invalid DataWindow row/column specified
30/09/2009 12:21:15.239 2 0 0 DEBUG [THREAD 7992] Internal Error #6/8 occurred in writeperformancedata while executing writeperformancedata. Error: Invalid DataWindow row/column specified
30/09/2009 12:21:15.442 2 0 0 DEBUG [THREAD 7992] 24x7 Scheduler: Internal Error #6/8 occurred in writeperformancedata while executing writeperformancedata. Error: Invalid DataWindow row/column specified
30/09/2009 12:21:15.442 2 0 0 DEBUG [THREAD 7992] Internal Error #6/8 occurred in writeperformancedata while executing writeperformancedata. Error: Invalid DataWindow row/column specified
30/09/2009 12:21:15.646 2 0 0 DEBUG [THREAD 7992] 24x7 Scheduler: Internal Error #6/8 occurred in writeperformancedata while executing writeperformancedata. Error: Invalid DataWindow row/column specified
30/09/2009 12:21:15.646 2 0 0 DEBUG [THREAD 7992] Internal Error #6/8 occurred in writeperformancedata while executing writeperformancedata. Error: Invalid DataWindow row/column specified
30/09/2009 12:21:15.864 2 0 0 DEBUG [THREAD 7992] 24x7 Scheduler: Internal Error #6/8 occurred in writeperformancedata while executing writeperformancedata. Error: Invalid DataWindow row/column specified
30/09/2009 12:21:15.880 2 0 0 DEBUG [THREAD 7992] Internal Error #6/8 occurred in writeperformancedata while executing writeperformancedata. Error: Invalid DataWindow row/column specified
30/09/2009 12:21:16.083 2 0 0 DEBUG [THREAD 7992] 24x7 Scheduler: Internal Error #6/8 occurred in writeperformancedata while executing writeperformancedata. Error: Invalid DataWindow row/column specified
30/09/2009 12:21:16.114 2 0 0 DEBUG [THREAD 7992] Internal Error #6/8 occurred in writeperformancedata while executing writeperformancedata. Error: Invalid DataWindow row/column specified
30/09/2009 12:21:16.349 2 0 0 DEBUG [THREAD 7992] 24x7 Scheduler: Internal Error #6/8 occurred in writeperformancedata while executing writeperformancedata. Error: Invalid DataWindow row/column specified
30/09/2009 12:21:16.349 2 0 0 DEBUG [THREAD 7992] Internal Error #6/8 occurred in writeperformancedata while executing writeperformancedata. Error: Invalid DataWindow row/column specified
30/09/2009 12:21:16.552 2 0 0 DEBUG [THREAD 7992] 24x7 Scheduler: Internal Error #6/8 occurred in writeperformancedata while executing writeperformancedata. Error: Invalid DataWindow row/column specified
30/09/2009 12:21:16.552 2 0 0 DEBUG [THREAD 7992] Internal Error #6/8 occurred in writeperformancedata while executing writeperformancedata. Error: Invalid DataWindow row/column specified
30/09/2009 12:21:16.771 2 0 0 DEBUG [THREAD 7992] 24x7 Scheduler: Internal Error #6/8 occurred in writeperformancedata while executing writeperformancedata. Error: Invalid DataWindow row/column specified
30/09/2009 12:21:16.771 2 0 0 DEBUG [THREAD 7992] Internal Error #6/8 occurred in writeperformancedata while executing writeperformancedata. Error: Invalid DataWindow row/column specified
30/09/2009 12:21:16.974 2 0 0 DEBUG [THREAD 7992] 24x7 Scheduler: Internal Error #6/8 occurred in writeperformancedata while executing writeperformancedata. Error: Invalid DataWindow row/column specified
30/09/2009 12:21:16.974 2 0 0 DEBUG [THREAD 7992] Internal Error #6/8 occurred in writeperformancedata while executing writeperformancedata. Error: Invalid DataWindow row/column specified

Let's start with the most important.

The messages in the log seem to be confusing, so, please correct me if I'm wrong
Job #1302 named "Postlink_PL100_out:20" is attempting to start job named "Postlink_PL100_out:30" Both are supposed to be local jobs. Yet "Postlink_PL100_out:20" job is running as a remote job connecting to the local instance of the scheduler using remote agent connection - because the Agent property of that job is set to LOCAL, not [Local] and you happen to have an agent profile with the LOCAL name or an instance of 24x7 running in the Remote Agent mode on the system. The "remote" is a quite special mode. To resolve this issue, please fix the Agent property of the "Postlink_PL100_out:20" job and set it to nothing or set it to [Local].

I don't yet know what is leading to getperformancedata/writeperformancedata errors. If this is not very important to you, I suggest to disable the Job Performance Statistic collection option in the scheduler Options until the cause is found and fixed. Right now failing performance procedures can cause anomalies in the job processing.

If you want to check the cause of Remote Console failing to create new jobs, please enable the same tracing option in the console and reproduce the error. Let's take a look at the debug.log file from the Remote Console system.

Most likely, the weird errors in job performance data collection procedures are side effects of the job code running in a wrong place. These errors can be safely ignored. There is no need to disable the Job Performance Collection option, please ignore the previous suggestion.

So yes, indeed we have a remote agent profile called Local, but the funny thing is that I didn't create it. I've removed it

We upgraded from 3.4 to 3.6.2 a few weeks ago, before that we used the local console running in parallel with the service to create and modify jobs mostly.

3.6.2 seems to behave slightly differently in that I don't seem to be able to run an automatically notimered instance of 24x7 locally on the server with the service still running to do creation and modification of jobs like I could with 3.4. Changes made when starting up 24x7 with the service running appear to be saved, but aren't.

So we started using the remote control console, which seemed good as it now seems to be able to run jobs on the master scheduler with no context issues like it used to have.

I would suspect that the remote control console put the local RA profile in but if that is the case then why those two jobs? We didn't even look at them at all let alone change them with the RC console.

I've turned off perf stats and tracing for now and will try to reproduce the permission error

How can I turn on remote control tracing? Tools/options is greyed out when I open remote control.

Please use the following method: start the local scheduler, change options as needed; shutdown the scheduler, and then start the RC.

I've turned on debug in tools/options on local sched and started up RC as recommended, tried to create a job and got the perms error. Where should the debug log be?

This and other log files should be created in the 24x7 home folder. In addition to the global trace settings, you may also need to check "Trace enabled "option in the Remote Host Profile which you use in RC to connect to the scheduler.