Slow AutoSys event processing compared to previous day, because slow database as a result of Oracle changing execution plan and how to identify such plan changes

Products

• Autosys Workload Automation

Issue/Introduction

Often we end up with situations where AutoSys operations are slower compared to the previous day and potentially some queries start showing up as taking much longer.  Behavior might also look like events are getting processed slower (example: it's taking much longer to change a job status)

Errors like below might indicate similar problems:

[07/13/2025 11:10:03.6672] CAUAJM_W_10998 Performance warning: Below query execution time has exceeded the DBLibThresholdTime configuration value. Elapsed time [87] seconds:
[07/13/2025 11:10:03.6673] CAUAJM_I_18031 Event Server: <AUTOPDB>  Completed Query: <SELECT j.joid, j.job_type, j.job_name, j.as_applic, j.as_group, s.status, s.status_time from ujo_job j join ujo_job_status s on s.joid = j.joid and s.job_ver = j.job_ver where j.joid>:I_I_1 and j.is_active=:I_I_2 and j.is_currver=:I_I_3  and (j.job_name like :I_S_4 escape :I_S_5 and coalesce(j.job_name,:I_S_6) != :I_S_7) order by j.job_name ASC NULLS FIRST  <<0,1,1,'%abc%','!',' ',' '>>>

       

[07/12/2025 05:43:46]      CAUAJM_E_18412 The database client has been interrupted while query execution is in progress.
[07/12/2025 05:43:46]      CAUAJM_E_18400 An error has occurred while interfacing with ORACLE.
[07/12/2025 05:43:46]      CAUAJM_E_18401 Function <doExecute> invoked from <execute> failed <929>
[07/12/2025 05:43:47]      CAUAJM_E_18416 Event Server: <ORACLE>  Failed Query: <BEGIN :RetVal := ujo_setup_next (:I_clean_send_flag, :I_joid, :I_eoid1, :I_eoid2, :I_killold, :I_event_text, :I_next_time_gmt, :I_clean_prev_evt, :I_next_end, :I_date_cond, :I_autoserv, :I_next_ms_eoid, :I_next_ms_time, :I_next_mc_eoid, :I_next_mc_time); END; <<1,123456,'ACE0m399oo00','',0,'Event was scheduled based on job definition.',1752354060,1,0,1,'ACE','',0,'',0>>>

 

Environment

AutoSys with Oracle Database

Resolution

In such a case, if the same query was taking much lesser time previously, database admin can check if Oracle changed the way it is obtaining the data now (there by making it slower). 

 

• Below SQL can be run to identify SQL execution plan changes in the past 24 hours, against schema name AEDBADMIN:

SET LONG 20000  -- add this line also, if executing via SQLPlus

WITH sql_plan_history AS (
    -- 1. Gather distinct (SQL_ID, PLAN_HASH_VALUE) combinations
    --    for the specified schema within the last 24 hours,
    --    along with their first/last observed times, and aggregated programs.
    SELECT
        s.sql_id,
        s.plan_hash_value,
        MIN(sn.begin_interval_time) AS first_seen_time,
        MAX(sn.begin_interval_time) AS last_seen_time,
        COUNT(DISTINCT sn.snap_id) AS num_snapshots_with_plan,
        -- Aggregate distinct program names associated with this SQL_ID and PLAN_HASH_VALUE
        -- within the historical snapshots.
        LISTAGG(DISTINCT s.module, '; ') WITHIN GROUP (ORDER BY s.module) AS programs_running_this_plan
    FROM
        dba_hist_sqlstat s
    JOIN
        dba_hist_snapshot sn ON s.snap_id = sn.snap_id
    WHERE
        sn.begin_interval_time >= SYSDATE - INTERVAL '48' HOUR --shows changes in past 24 hours
        AND s.parsing_schema_name = UPPER('aedbadmin') --change this to your schema name
    GROUP BY
        s.sql_id,
        s.plan_hash_value
),
changed_sql_ids AS (
    -- 2. Identify SQL_IDs that had more than one distinct PLAN_HASH_VALUE
    --    within the selected time frame. These are the ones where the plan changed.
    SELECT
        sql_id
    FROM
        sql_plan_history
    GROUP BY
        sql_id
    HAVING
        COUNT(DISTINCT plan_hash_value) > 1
)
-- 3. Retrieve details for all identified plans that experienced a change,
--    including the SQL text, programs, and a summary of the plan's root operation.
SELECT
    sph.sql_id,
    sph.plan_hash_value,
    TO_CHAR(sph.first_seen_time, 'YYYY-MM-DD HH24:MI:SS') AS plan_first_seen,
    TO_CHAR(sph.last_seen_time, 'YYYY-MM-DD HH24:MI:SS') AS plan_last_seen,
    sph.num_snapshots_with_plan,
    sph.programs_running_this_plan, -- Added program names here
    st.sql_text,                    -- The actual SQL text
    -- Subquery to get the root operation of the plan (gives a hint about the overall access path)
    (
        SELECT
            p.operation || ' ' || p.options
        FROM
            dba_hist_sql_plan p
        WHERE
            p.sql_id = sph.sql_id
            AND p.plan_hash_value = sph.plan_hash_value
            AND p.id = 0 -- Root operation typically has ID 0
            AND ROWNUM = 1
    ) AS root_plan_operation_summary
FROM
    sql_plan_history sph
JOIN
    changed_sql_ids csi ON sph.sql_id = csi.sql_id
JOIN
    dba_hist_sqltext st ON sph.sql_id = st.sql_id -- Join DBA_HIST_SQLTEXT here
ORDER BY
    sph.sql_id,
    sph.first_seen_time;

 

• This shows output like below:

• For each SQL_ID / PLAN_HASH_VALUE in question, you can now run another query to identify the real plan

SELECT *
FROM TABLE(DBMS_XPLAN.DISPLAY_AWR(
    sql_id          => '<<SQL_ID>>', --replace this with real SQL_ID
    plan_hash_value => <<Plan_Hash_Value>>,   --replace this with the plan_hash_value
    format          => 'ALLSTATS LAST' -- Use 'TYPICAL', 'ALL', 'ALLSTATS LAST' for more details
));

 

• For example, in the case of 06qdgzyct1r6p from the above output, as there are 2 different plans, you would have to run below type of query 2 times to identify all the plans for it, for each plan_hash_value:

SELECT *
FROM TABLE(DBMS_XPLAN.DISPLAY_AWR(
    sql_id          => '06qdgzyct1r6p',
    plan_hash_value => 629848426,
    format          => 'ALLSTATS LAST' 
));

 

Thereafter, engage DBA to identify which plan is the best one and have the DBA PIN that plan to make the queries perform faster.  These plans can also be compared from once database instance to another to see which one has a better plan to make use of that plan.  DBAs often save, export a plan from one database and import it into another before configuring it to use the new plan.