Duplicate scheduler jobs running

From: daniel koehne <koehned_at_gmail.com>
Date: Thu, 21 Jul 2016 14:53:21 -0400
Message-ID: <CANJUyXDqXbcchhfYjLXEO7Y9rgoUKeJoOTTeCuKa01PMm+_xyA_at_mail.gmail.com>

Sorry for the long post. Since upgrading our databases to Oracle 12.1.0. 2 we have noticed that occasionally (8 times in the last 1.5 days, total jobs run approx 52000 for primary prod db) we have scheduler jobs run twice which causes problems like double billing. We did not see this problem with our 11.2.0.3 databases.

No RAC involved, all DB's are single instance with data guard physical standby at remote site. See below for specific version information.

job_queue_processes = 15
We don't see any evidence that the job_queue_processes setting is too low.

Here is an example job from yesterday that experienced the duplicate job problem:

Scheduler job definition (extracted using DBMS_METADATA.GET_DDL):

BEGIN
dbms_scheduler.create_job('"GET_FREQ_SCHED_INT_164"',

   job_type=>'PLSQL_BLOCK',
   job_action=>'BEGIN ois.px_int_inadv_log_p.get_freq_sched_int;END;',    number_of_arguments=>0,
   start_date=>TO_TIMESTAMP_TZ('30-SEP-2006 07.33.42.442580000 AM GMT','DD-MON-RRRR HH.MI.SSXFF AM TZR','NLS_DATE_LANGUAGE=english'),

   repeat_interval=> 'FREQ=MINUTELY',
   end_date=>NULL,
   job_class=>'"DEFAULT_JOB_CLASS"',
   enabled=>FALSE,
   auto_drop=>TRUE,
   comments=>NULL
);
dbms_scheduler.set_attribute('"GET_FREQ_SCHED_INT_164"','logging_level',DBMS_SCHEDULER.LOGGING_RUNS); dbms_scheduler.enable('"GET_FREQ_SCHED_INT_164"'); COMMIT;
END; Run 1:

   req start date: 20-JUL-16 08.23.42.198257000 PM GMT    actual start date: 20-JUL-16 08.23.42.248354000 PM GMT    run duration: +00 00:00:00.000000
   status: SUCCEEDED

Run 2:

   req start date: 20-JUL-16 08.24.42.249782000 PM GMT    actual start date: 20-JUL-16 08.24.42.997972000 PM GMT    run duration: +00 00:00:00.000000
   status: SUCCEEDED

*Run 3: This is the duplicate run, note that the start date is very close (.148446 seconds) to the previous run.*
* req start date: 20-JUL-16 08.24.42.999756000 PM GMT*

• actual start date: 20-JUL-16 08.24.43.146418000 PM GMT*
• run duration: +00 00:00:00.000000*
• status: SUCCEEDED*

Run 4:

   req start date: 20-JUL-16 08.25.42.147797000 PM GMT    actual start date: 20-JUL-16 08.25.43.627054000 PM GMT    run duration: +00 00:00:00.000000
   status: SUCCEEDED

Run 5:

   req start date: 20-JUL-16 08.26.42.629330000 PM GMT    actual start date: 20-JUL-16 08.26.45.226534000 PM GMT    run duration: +00 00:00:00.000000
   status: SUCCEEDED

The duplicate scheduler job problem appears to affect random jobs (i.e. it's not the same couple of jobs that are affected by this issue).

Oracle support suggested bug and applying patch (Patch 22071479: DBMS_SCHEDULER - REPEAT_INTERVAL => BYTIME CLUASE IS NOT WORKING AS EXPECTED) to fix.

I have applied the patch and it did not fix this duplicate scheduler jobs issue in our development database. So I am wondering where to go next as Oracle support hasn't been of much help to date.

I have two questions:

1. Has anyone else seen this scheduler behaviour? If so how did you resolve?
2. Is it possible to trace the job queue controller process? Oracle support has not been forthcoming with any answer to this question.

Thanks

   Daniel

PS: Here is our Oracle version information:

Oracle version: 12.1.0.2 Enterprise Edition OS: Red Hat Enterprise Linux Server release 6.4 (Santiago)

       2.6.32-358.6.1.el6.x86_64 #1 SMP Fri Mar 29 16:51:51 EDT 2013 x86_64 x86_64 x86_64 GNU/Linux

COMP_NAME VERSION STATUS

---------------------------------------- --------------- -----------

JServer JAVA Virtual Machine 12.1.0.2.0 VALID Oracle Database Catalog Views 12.1.0.2.0 VALID Oracle Database Java Packages 12.1.0.2.0 VALID Oracle Database Packages and Types 12.1.0.2.0 VALID Oracle Workspace Manager 12.1.0.2.0 VALID Oracle XDK 12.1.0.2.0 VALID
Oracle XML Database 12.1.0.2.0 VALID

SQL> select PATCH_ID, VERSION, action, action_time, description from DBA_REGISTRY_SQLPATCH order by action_time;

  PATCH_ID VERSION ACTION ACTION_TIME DESCRIPTION

---------- ------------------------- ---------------
----------------------------------------
----------------------------------------------------------------------------------------------------
  22139226 12.1.0.2     APPLY     24-MAY-16 04.40.49.245228 PM
 Database PSU 12.1.0.2.160119, Oracle JavaVM Component (Jan2016)
  21948354 12.1.0.2     APPLY     24-MAY-16 04.43.20.827736 PM
 Database Patch Set Update : 12.1.0.2.160119 (21948354)
  20528052 12.1.0.2     APPLY     24-MAY-16 04.43.20.841383 PM

--
http://www.freelists.org/webpage/oracle-l

Received on Thu Jul 21 2016 - 20:53:21 CEST