Story of Sysdate

It started at 5pm, because all interesting production issues start at 5pm. As the on-call DBA, I recieved an alert about over used undo tablespace on one of our databases. First thing to do in such case is check v$transaction for transactions that have been running for a while. Turned out that v$transaction is empty.

The next suspect was the monitor itself. Maybe there is a bug in the query that checks undo tablespace usage? Checking the query, I noticed two interesting things:
1. It reported over 3G of used undo tablespace, while I know we only have 2G.
2. It contained the following lovely gem (completely unrelated to the post, but too cute not to mention): case when to_number(value) < 3600 then to_number(value)/60/1440 else to_number(value)/3600/24 end
Clearly the query needed some debugging, and I set to the task.

I usually start debugging by breaking the query into component subqueries and verifying that they give the expected results. This time, I started with the part that calculates the amount of undo bytes we need to keep due to our retention policy. The following query gave me all the undo history on the system. Not just the rows that were within our retention policy:

SELECT
to_char(begin_time,'dd-mm-yyyy hh24:mi:ss'),to_char(end_time,'dd-mm-yyyy hh24:mi:ss'),undoblks,txncount
FROM
V$UNDOSTAT US
WHERE
US.BEGIN_TIME >= SYSDATE - (
select
to_number(value)/(60*60*24)
from
v$parameter
where
name='undo_retention');

Very strange. The calculation looks right. Lets go all the way back to basics:
SQL> select to_char(SYSDATE,'dd-mm-yyyy hh24:mi:ss') from dual ;
TO_CHAR(SYSDATE,'DD
-------------------
02-03-2004 22:23:24

This is not an undo issue anymore. What happened to my sysdate? The documentation says that sysdate gets the date from the host OS. So I start there:
[oracle@vvsdb01 ~]$ date
Mon Mar 17 18:40:31 PDT 2008

OS looks fine. What about timestamp?
SQL> select sysdate from dual;
SYSDATE
--------------------
02 Mar 2004 22:23:24
SQL> select current_timestamp from dual;
CURRENT_TIMESTAMP
---------------------------------------------------------------------------
17-MAR-08 05.48.49.846746 PM -07:00

Timestamp is fine, but now senior DBA noticed that the sysdate time didn’t change at all since the last time we looked at sysdate. Surely more than few minutes passed? Quick search revealed a previously unknown system parameter – fixed_date. FIXED_DATE enables you to set a constant date that SYSDATE will always return instead of the current date.


SQL> show parameter FIX

NAME TYPE VALUE
———————————— ———– ——————————
fixed_date string 02-MAR-04
Yes. We had that. Checking the alert log to see when it happened:
Mon Mar 17 16:48:51 2008
ALTER SYSTEM SET fixed_date='2004-03-02 22:23:24' SCOPE=BOTH;

We caught it right on time! Lets fix it fast:
ALTER SYSTEM SET fixed_date=NONE SCOPE=BOTH;

And now how did it happen? We had the time it happened, so we checked /var/log/secure for matching ssh logins and got the IP.
The IP was of my own machine. I was completely flabbergasted for quite some time. But I think I reconstructed how it happened:
I was reading about some initialization parameters on this site, and I have a nasty habit of playing with the mouse while reading. I must have selected about half of that page. Then I remembered that I had other work to do and proceeded to copy-paste from vim window to sqlplus. Turned out that I didn’t really copy from vim, and when I pasted into sqlplus, I actually pasted half of that webpage. I saw that I got a bunch of errors because I just pasted a bunch of random sentences into sqlplus, so I cursed a bit and tried copying from vim again. What I did not notice was that among the other things I pasted by mistake was:

SQL> alter session set nls_date_format = 'dd.mon.yyyy hh24:mi:ss';
alter system set fixed_date='2004-03-02 22:23:24';
select sysdate from dual;
SYSDATE
-------------------
02.mar.2004 22:23:24
Session altered.

the problem was right there in my terminal screen all along!

Advertisements

10 Comments on “Story of Sysdate”

  1. Noons says:

    Excellent detective work, Chen!

    Been stuck with unexpected contents of paste buffer myself a few times, I can relate to this so well!

  2. dombrooks says:

    When you consider other more destructive commands that you could have copied and pasted, sounds like a lucky escape.

  3. prodlife says:

    Dominic,
    Indeed a lucky escape! This could have been a much much more expensive lesson.

  4. Interesting. Did it show up in any alert log monitor?

  5. prodlife says:

    We don’t monitor for alter system in the alert log.

    Good idea. We should definitely be doing that.

  6. Asif Momen says:

    Yea, even we don’t monitor “alter system” in the alert log. I think, we should do.

  7. Sidhu says:

    Oh God…interesting…it happens many times…Excellent crack down…

  8. […] you know about fixed_date 刚刚看到Gwen Shapira关于Fixed_date的叙述, […]

  9. jametong says:

    Well done, I referenced this to my site.

  10. Ori Peleg says:

    Very nice war story!!!


Leave a Reply

Fill in your details below or click an icon to log in:

WordPress.com Logo

You are commenting using your WordPress.com account. Log Out / Change )

Twitter picture

You are commenting using your Twitter account. Log Out / Change )

Facebook photo

You are commenting using your Facebook account. Log Out / Change )

Google+ photo

You are commenting using your Google+ account. Log Out / Change )

Connecting to %s