Skip to Main Content
  • Questions
  • Procedure call behaves differently through SQL plus and DBMS_JOB

Breadcrumb

Question and Answer

Tom Kyte

Thanks for the question, Johny.

Asked: February 17, 2009 - 11:20 am UTC

Last updated: February 19, 2009 - 12:16 pm UTC

Version: 9.2.0

Viewed 1000+ times

You Asked

Hi Tom,

I have creaetd a small procedure, which uses another subroutine to write the log to a table.

But the time it is recording to the log table is different, if I call through DBMS_JOB and SQL plus.

The trace from DBMS_JOB is always 1 hour behind, even though both are using the same procedure test_eventlog_write.

This is the systemtiestamp and localtimestamp
S
ELECT SYSDATE, SYSTIMESTAMP, LOCALTIMESTAMP
FROM DUAL

Sysdate 11.02.2009 12:19:18
Systimestamp 11/02/2009 12:19:18.642857 +00:00
localtimestamp 11/02/2009 13:19:18.642864


Following is the whole script for this scenario.


Any advice would be much appreciated.

Johny Alex


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

-- Create the table to hold all the logs
CREATE TABLE TEST_EVENTLOG
(
SSIADMIN_EVENT_TIME TIMESTAMP(6),
SSIADMIN_EVENT_LOG VARCHAR2(2000 BYTE)
);


-- Create a procedure to write to the above table
CREATE OR REPLACE PROCEDURE test_eventlog_write (message1 VARCHAR)
AUTHID CURRENT_USER
IS
PRAGMA AUTONOMOUS_TRANSACTION;
BEGIN
INSERT INTO test_eventlog
VALUES (LOCALTIMESTAMP, message1);

COMMIT;
END test_eventlog_write;



-- My Actual procedure, which internally calls the above procedure.
CREATE OR REPLACE PROCEDURE test_proc_call (
i_line1 IN VARCHAR2 DEFAULT 'Value at Line 1 ',
i_line2 IN VARCHAR2 DEFAULT 'Value at Line 2 ',
i_line3 IN VARCHAR2 DEFAULT 'Value at Line 3 '
)
AUTHID CURRENT_USER
IS
loc_message VARCHAR2 (2000);
BEGIN
loc_message := i_line1 || ': :' || i_line2 || ': :' || i_line3;


-- Call the procedure to write the logs to test_event_log table
test_eventlog_write (loc_message);

END test_proc_call;
/



-- Call the test procedure directly through SQL plus
begin
test_proc_call();
end;

-- See the result
select * from test_eventlog
order by 1 desc



--- Call the same procedure through an Oracle Job, which runs in every 10 seconds ========

SET serveroutput on
VARIABLE jobno NUMBER

DECLARE
jobcount NUMBER := 0;
BEGIN
SELECT COUNT (*)
INTO jobcount
FROM user_jobs t
WHERE t.what = 'test_proc_call;';

IF jobcount >= 1
THEN
DBMS_OUTPUT.put_line
('test_proc_call is already running, Please stop test_proc_call before starting again'
);
ELSE
DBMS_JOB.submit (:jobno,
'test_proc_call;',
SYSDATE,
'sysdate + (10 / (24 * 60 * 60))'
);
COMMIT;
END IF;
END;
/


-- See the reult, it is one hour behind than my local time
SELECT *
FROM test_eventlog
ORDER BY 1 DESC



--
SELECT SYSDATE, SYSTIMESTAMP, LOCALTIMESTAMP
FROM DUAL

Sysdate 11.02.2009 12:19:18
Systimestamp 11/02/2009 12:19:18.642857 +00:00
localtimestamp 11/02/2009 13:19:18.642864




============ Remove the job

SET serveroutput on

DECLARE
jobno_tmp INTEGER;
BEGIN
SELECT t.job
INTO jobno_tmp
FROM user_jobs t
WHERE t.what = 'test_proc_call;';

DBMS_JOB.remove (jobno_tmp);
COMMIT;
DBMS_OUTPUT.put_line ('Job Removed');
EXCEPTION
WHEN OTHERS
THEN
raise_application_error (-20001,
'Job does not Exists' || SQLERRM (SQLCODE)
);
END;
/

and Tom said...

either

a) YOUR timezone environment variable is set wrong
b) the account that starts the database's timezone is wrong



and it sounds like the account that starts the database is wrong.

When you use sqlplus locally - you fork and exec the Oracle dedicated server, it inherits it's environment from YOU.

the job queue process inherits it's environment from the account that started the database.

Consider:


[tkyte@dellpe ~]$ export TZ=EST
[tkyte@dellpe ~]$ plus

SQL*Plus: Release 10.2.0.4.0 - Production on Thu Feb 19 12:09:15 2009

Copyright (c) 1982, 2007, Oracle.  All Rights Reserved.


Connected to:
Oracle Database 10g Enterprise Edition Release 10.2.0.4.0 - Production
With the Partitioning, OLAP, Data Mining and Real Application Testing options

ops$tkyte%ORA10GR2> select to_char(sysdate,'hh24:mi:ss') from dual;

TO_CHAR(
--------
12:09:25

ops$tkyte%ORA10GR2> exit
Disconnected from Oracle Database 10g Enterprise Edition Release 10.2.0.4.0 - Production
With the Partitioning, OLAP, Data Mining and Real Application Testing options
[tkyte@dellpe ~]$ export TZ=PST
[tkyte@dellpe ~]$ plus

SQL*Plus: Release 10.2.0.4.0 - Production on Thu Feb 19 17:09:31 2009

Copyright (c) 1982, 2007, Oracle.  All Rights Reserved.


Connected to:
Oracle Database 10g Enterprise Edition Release 10.2.0.4.0 - Production
With the Partitioning, OLAP, Data Mining and Real Application Testing options

ops$tkyte%ORA10GR2> select to_char(sysdate,'hh24:mi:ss') from dual;

TO_CHAR(
--------
17:09:32



the dedicated server just makes an OS call to ask "what time is it".



If you were to connect via sqlplus through the LISTENER (and the dedicated server is spawned by the listener, not your sqlplus session) you would likely see the same "wrong time"

Your server is misconfigured and that needs to be fixed - but beware, it'll be like setting the clock to a different time and you might have application issues (the same date will happen twice or an hour will go entirely missing all of a sudden!)

Is this answer out of date? If it is, please let us know via a Comment

More to Explore

VLDB

If you are new to partitioning, check out Connor McDonald's introduction series here.

VLDB

Documentation set on VLDB and Partitioning.