Home > Software engineering >  Why does my first call to current_timestamp produce a later time than the second call?
Why does my first call to current_timestamp produce a later time than the second call?

Time:11-12

I'm trying to write a PL/SQL unit test (using utPLSQL) which makes sure that a certain procedure updates a timestamp value in a table.

The test structure is somewhat like this:

PROCEDURE my_fancy_test IS
    v_test_start_time TIMESTAMP;
    v_timestamp_in_table TIMESTAMP;
BEGIN
    v_test_start_time := CURRENT_TIMESTAMP;

    -- Make some assertions
    -- ...

    -- Call the procedure which - amongst other changes - sets a TIMESTAMP column to CURRENT_TIMESTAMP
    -- The procedure updates the time like so:
    UPDATE mytable SET lastchange = CURRENT_TIMESTAMP WHERE id = 42;

    -- Test if the date was set to a current timestamp
    SELECT lastchange INTO v_timestamp_in_table FROM mytable WHERE id = 42;
    ut.expect( v_timestamp_in_table ).to_be_greater_or_equal( v_test_start_time );

END;

To my surprise, this test always (or maybe just very often) fails since the timestamp which gets stored in the procedure variable is a couple of milliseconds later (newer) than the timestamp which gets queried in the UPDATE statement.

Does anyone know the reason for this? Do PL/SQL procedures and SQL queries

I could of course add a one second "epsilon" or something, but I'd like to understand first if there are other similar cases I need to keep in mind when writing unit tests like that.

CodePudding user response:

If the table is declared with a TIMESTAMP data type of lower precision than created by CURRENT_TIMESTAMP then the inserted value will be rounded to the appropriate precision:

CREATE TABLE mytable (
  lastchange TIMESTAMP(0)
);
INSERT INTO mytable VALUES (NULL);

Then:

DECLARE
  v_test_start_time TIMESTAMP;
  v_timestamp_in_table TIMESTAMP;
BEGIN
  v_test_start_time := CURRENT_TIMESTAMP;

  UPDATE mytable
  SET   lastchange = v_test_start_time
  RETURNING lastchange INTO v_timestamp_in_table;

  DBMS_OUTPUT.PUT_LINE( 'Time:          ' || v_test_start_time);
  DBMS_OUTPUT.PUT_LINE( 'Time in table: ' || v_timestamp_in_table);
END;
/

Outputs:

Time:          2021-11-11 14:42:01.400733
Time in table: 2021-11-11 14:42:01.000000

Then the time in the table has been rounded down.


You can fix it by declaring the variables to have the same data type (and precision) as the table:

DECLARE
  v_test_start_time    mytable.lastchange%TYPE;
  v_timestamp_in_table mytable.lastchange%TYPE;
BEGIN
  v_test_start_time := CURRENT_TIMESTAMP;

  UPDATE mytable
  SET   lastchange = v_test_start_time
  RETURNING lastchange INTO v_timestamp_in_table;

  DBMS_OUTPUT.PUT_LINE( 'Time:          ' || v_test_start_time);
  DBMS_OUTPUT.PUT_LINE( 'Time in table: ' || v_timestamp_in_table);
END;
/

Which outputs:

Time:          2021-11-11 14:42:01.
Time in table: 2021-11-11 14:42:01.

db<>fiddle here

CodePudding user response:

Everything is working as intended - I simply tested the wrong timestamp column (there's a last change date, and a last transferred date, which I didn't know since I "inherited" the procedure to be tested from an employee who has quit).

The "last change" date was (in this case) the date where the test inserted the test data, which happens in a separate procedure which gets called before the test.

Therefore the last change is in fact supposed to be a couple of milliseconds before the start of the test case. Changing the code to use the "last transferred" date fixed it for this test.

  • Related