Skip to Main Content

Database Software

Announcement

For appeals, questions and feedback about Oracle Forums, please email oracle-forums-moderators_us@oracle.com. Technical questions should be asked in the appropriate category. Thank you!

Job started with dbms_scheduler starting with delay

1031306Aug 10 2016 — edited Aug 24 2016

Hi everbody,

I am currently facing an inconsistent issue using dbms_scheduler on one of our database (DB version is 12.1.0.2.0) and I have no idea about the reason of that problem. I performed different kind of tests those past days to try identifying the reason and how to reproduce it at will but did not succeed. Let me explain my problem. We are executing a job using dbms_scheduler package without specifying any start date. On one of our database, the job is correctly created but does not start immediately. The delay before it starts is really variable. However, once the job ran for the 1st time, I can drop the job and create it again and this time it starts immediately.

At the moment I have absolutely no idea about how to explain that delay and why it is not occuring once initial job started. At the real beginning I suspected that it has something to do with timezones (session time zone is set to +02:00, db time zone is set to +02:00 and scheduler default time zone attribute is set to PST8PDT) but it seems not to be the case since the problem does not occur again if I let the first job getting started before restarting it without chaning any settings.

To illustrate this more in details, I created a script that launches 20 scheduler jobs in parallel, 10 of them without specifying a start date and 10 with a start date defined. At the time I ran the script, none of them started immediately. In beetween I started two more jobs manually and again none of them started. Approximatively 30 minutes after I executed the script, all the jobs started. And here again, I dropped all of them and executed the script again and this time all of them started as expected.

For more details you will find below the script and the two sets of results.

The is the script I executed :

DECLARE

  c_job constant varchar2(30) := 'SCHED_JOB';

BEGIN

  for i in 1 .. 20 loop

 

    IF i < 11 THEN

      dbms_scheduler.create_job(job_name        => c_job || '_' || i,

                                job_type        => 'PLSQL_BLOCK',

                                job_action      => 'BEGIN NULL; END;',

                                repeat_interval => 'FREQ=DAILY',

                                enabled         => true);

    ELSE

      dbms_scheduler.create_job(job_name        => c_job || '_' || i,

                                job_type        => 'PLSQL_BLOCK',

                                job_action      => 'BEGIN NULL; END;',

                                start_date      => systimestamp +

                                                   numtodsinterval(2,

                                                                   'MINUTE'),

                                repeat_interval => 'FREQ=DAILY',

                                enabled         => true);

    END IF;

 

    dbms_lock.sleep(10);

   

    if i = 10 then

      dbms_lock.sleep(30);

    end if;

 

  end loop;

END;

The first round produced the following results :

JOB_NAME      START_DATE                            LAST_START_DATE                       DELAY                        ENABLED   RUN_COUNT

============  ===================================   ===================================   ===========================  ========  =========

SCHED_JOB_1   10-AUG-16 02.46.50.402488 AM PST8PDT  10-AUG-16 03.14.23.216697 AM PST8PDT  +000000000 00:27:32.814209   TRUE      1

SCHED_JOB_2   10-AUG-16 02.47.00.433335 AM PST8PDT  10-AUG-16 03.14.23.277966 AM PST8PDT  +000000000 00:27:22.844631   TRUE      1

SCHED_JOB_3   10-AUG-16 02.47.10.448383 AM PST8PDT  10-AUG-16 03.14.23.293654 AM PST8PDT  +000000000 00:27:12.845271   TRUE      1

SCHED_JOB_4   10-AUG-16 02.47.20.461944 AM PST8PDT  10-AUG-16 03.14.23.349307 AM PST8PDT  +000000000 00:27:02.887363   TRUE      1

SCHED_JOB_5   10-AUG-16 02.47.30.474960 AM PST8PDT  10-AUG-16 03.14.23.389721 AM PST8PDT  +000000000 00:26:52.914761   TRUE      1

SCHED_JOB_6   10-AUG-16 02.47.40.487998 AM PST8PDT  10-AUG-16 03.14.23.387199 AM PST8PDT  +000000000 00:26:42.899201   TRUE      1

SCHED_JOB_7   10-AUG-16 02.47.50.501093 AM PST8PDT  10-AUG-16 03.14.23.422157 AM PST8PDT  +000000000 00:26:32.921064   TRUE      1

SCHED_JOB_8   10-AUG-16 02.48.00.513977 AM PST8PDT  10-AUG-16 03.14.23.432078 AM PST8PDT  +000000000 00:26:22.918101   TRUE      1

SCHED_JOB_9   10-AUG-16 02.48.10.528526 AM PST8PDT  10-AUG-16 03.14.25.408602 AM PST8PDT  +000000000 00:26:14.880076   TRUE      1

SCHED_JOB_10  10-AUG-16 02.48.20.543438 AM PST8PDT  10-AUG-16 03.14.25.434170 AM PST8PDT  +000000000 00:26:04.890732   TRUE      1

SCHED_JOB_11  10-AUG-16 11.51.00.564523 AM +02:00   10-AUG-16 12.14.25.439819 PM +02:00   +000000000 00:23:24.875296   TRUE      1

SCHED_JOB_12  10-AUG-16 11.51.10.582506 AM +02:00   10-AUG-16 12.14.25.559511 PM +02:00   +000000000 00:23:14.977005   TRUE      1

SCHED_JOB_13  10-AUG-16 11.51.20.597491 AM +02:00   10-AUG-16 12.14.25.445298 PM +02:00   +000000000 00:23:04.847807   TRUE      1

SCHED_JOB_14  10-AUG-16 11.51.30.602501 AM +02:00   10-AUG-16 12.14.25.417029 PM +02:00   +000000000 00:22:54.814528   TRUE      1

SCHED_JOB_15  10-AUG-16 11.51.40.617527 AM +02:00   10-AUG-16 12.14.25.423883 PM +02:00   +000000000 00:22:44.806356   TRUE      1

SCHED_JOB_16  10-AUG-16 11.51.50.632637 AM +02:00   10-AUG-16 12.14.25.738749 PM +02:00   +000000000 00:22:35.106112   TRUE      1

SCHED_JOB_17  10-AUG-16 11.52.00.646539 AM +02:00   10-AUG-16 12.14.25.419311 PM +02:00   +000000000 00:22:24.772772   TRUE      1

SCHED_JOB_18  10-AUG-16 11.52.10.661492 AM +02:00   10-AUG-16 12.14.25.428480 PM +02:00   +000000000 00:22:14.766988   TRUE      1

SCHED_JOB_19  10-AUG-16 11.52.20.676620 AM +02:00   10-AUG-16 12.14.25.514454 PM +02:00   +000000000 00:22:04.837834   TRUE      1

SCHED_JOB_20  10-AUG-16 11.52.30.691537 AM +02:00   10-AUG-16 12.14.25.577455 PM +02:00   +000000000 00:21:54.885918   TRUE      1

SCHED_JOB_21  10-AUG-16 11.53.22.176249 AM +02:00   10-AUG-16 12.14.25.553580 PM +02:00   +000000000 00:21:03.377331   TRUE      1

SCHED_JOB_22  10-AUG-16 12.09.13.039047 PM +02:00   10-AUG-16 12.14.36.047749 PM +02:00   +000000000 00:05:23.008702   TRUE      1

All the data here above have been picked up as is from view user_scheduler_jobs except column DELAY which is simply the difference between LAST_START_DATE and START_DATE

Then, as I said, I dropped again all jobs and executed the script again. This time I got the following results :

JOB_NAME      START_DATE                            LAST_START_DATE                       DELAY                        ENABLED   RUN_COUNT

============  ===================================   ===================================   ===========================  ========  =========

SCHED_JOB_1   10-AUG-16 04.50.51.608888 AM PST8PDT  10-AUG-16 04.50.55.559027 AM PST8PDT  +000000000 00:00:03.950139   TRUE      1

SCHED_JOB_2   10-AUG-16 04.51.01.626190 AM PST8PDT  10-AUG-16 04.51.04.561778 AM PST8PDT  +000000000 00:00:02.935588   TRUE      1

SCHED_JOB_3   10-AUG-16 04.51.11.637261 AM PST8PDT  10-AUG-16 04.51.14.776588 AM PST8PDT  +000000000 00:00:03.139327   TRUE      1

SCHED_JOB_4   10-AUG-16 04.51.21.669327 AM PST8PDT  10-AUG-16 04.51.24.820751 AM PST8PDT  +000000000 00:00:03.151424   TRUE      1

SCHED_JOB_5   10-AUG-16 04.51.31.684345 AM PST8PDT  10-AUG-16 04.51.34.744447 AM PST8PDT  +000000000 00:00:03.060102   TRUE      1

SCHED_JOB_6   10-AUG-16 04.51.41.699047 AM PST8PDT  10-AUG-16 04.51.44.829841 AM PST8PDT  +000000000 00:00:03.130794   TRUE      1

SCHED_JOB_7   10-AUG-16 04.51.51.713127 AM PST8PDT  10-AUG-16 04.51.54.753883 AM PST8PDT  +000000000 00:00:03.040756   TRUE      1

SCHED_JOB_8   10-AUG-16 04.52.25.942772 AM PST8PDT  10-AUG-16 04.52.28.411455 AM PST8PDT  +000000000 00:00:02.468683   TRUE      1

SCHED_JOB_9   10-AUG-16 04.52.35.952088 AM PST8PDT  10-AUG-16 04.52.37.565170 AM PST8PDT  +000000000 00:00:01.613082   TRUE      1

SCHED_JOB_10  10-AUG-16 04.52.45.966319 AM PST8PDT  10-AUG-16 04.52.47.582280 AM PST8PDT  +000000000 00:00:01.615961   TRUE      1

SCHED_JOB_11  10-AUG-16 01.55.25.976490 PM +02:00   10-AUG-16 01.55.26.197918 PM +02:00   +000000000 00:00:00.221428   TRUE      1

SCHED_JOB_12  10-AUG-16 01.55.35.991527 PM +02:00   10-AUG-16 01.55.36.183384 PM +02:00   +000000000 00:00:00.191857   TRUE      1

SCHED_JOB_13  10-AUG-16 01.55.45.997592 PM +02:00   10-AUG-16 01.55.46.193751 PM +02:00   +000000000 00:00:00.196159   TRUE      1

SCHED_JOB_14  10-AUG-16 01.55.56.013568 PM +02:00   10-AUG-16 01.55.56.183583 PM +02:00   +000000000 00:00:00.170015   TRUE      1

SCHED_JOB_15  10-AUG-16 01.56.07.675531 PM +02:00   10-AUG-16 01.56.10.359418 PM +02:00   +000000000 00:00:02.683887   TRUE      1

SCHED_JOB_16  10-AUG-16 01.56.17.694521 PM +02:00   10-AUG-16 01.56.20.385800 PM +02:00   +000000000 00:00:02.691279   TRUE      1

SCHED_JOB_17  10-AUG-16 01.56.27.707464 PM +02:00   10-AUG-16 01.56.30.387835 PM +02:00   +000000000 00:00:02.680371   TRUE      1

SCHED_JOB_18  10-AUG-16 01.56.37.720529 PM +02:00   10-AUG-16 01.56.40.607265 PM +02:00   +000000000 00:00:02.886736   TRUE      1

SCHED_JOB_19  10-AUG-16 01.56.47.733503 PM +02:00   10-AUG-16 01.56.50.362353 PM +02:00   +000000000 00:00:02.628850   TRUE      1

SCHED_JOB_20  10-AUG-16 01.56.57.747511 PM +02:00   10-AUG-16 01.57.00.377383 PM +02:00   +000000000 00:00:02.629872   TRUE      1

As you can see here, all jobs started in a few seconds only.

Can anyone help me understanding this strange behavior please ?

Comments
Locked Post
New comments cannot be posted to this locked post.
Post Details
Locked on Sep 21 2016
Added on Aug 10 2016
16 comments
7,379 views