Anomalies with the now() function

On Thu, Nov 17, 2005 at 12:30:36PM -0000, Byrne Kevin-kbyrne01 wrote:

I have a trigger set up on a db - when a row is added to a certain
table (say Table A) in my db the trigger calls a function and then the
function enters another line in a related table (say Table B). Here's
the problem, the first addition to Table A may show the time of the
addition as, for example 19:01:53. This is correct. The second addition,
triggered by the first additon, shows a time of say 19:01:10! The
addition of the row to Table B uses the now() function to determine the
time the new row is added to the table. This should in theory match the
time (to within a few milliseconds at least) the first row was added,
since the trigger is immediate. However, I am seeing major time
differences? How reliable is now() - has anyone seen anything similar ?

now() doesn't advance during transactions and all statements are
wrapped in a transaction whether you explicitly start one or not,
so if you used now() for both inserts then the timestamps should
be identical regardless of how much time passed between the outer
insert and the one in the trigger. If you want wall time then
use timeofday().

How are you setting the timestamp for the insert to Table A? If
you're getting the timestamp in client code or from timeofday()
then that could explain the discrepancy: Table A gets "now" in the
sense of wall time, while Table B gets "now" in the sense of whenever
the transaction froze its notion of the current time, which may
have been a while earlier.

If that explanation doesn't fit with what you're doing then please
post a self-contained example that exhibits the behavior you're
seeing.

--
Michael Fuhr

Byrne Kevin-kbyrne writes:

I have a trigger set up on a db - when a row is added to a certain
table (say Table A) in my db the trigger calls a function and then the
function enters another line in a related table (say Table B). Here's
the problem, the first addition to Table A may show the time of the
addition as, for example 19:01:53. This is correct. The second
addition, triggered by the first additon, shows a time of say
19:01:10! The addition of the row to Table B uses the now() function
to determine the time the new row is added to the table. This should
in theory match the time (to within a few milliseconds at least) the
first row was added, since the trigger is immediate. However, I am
seeing major time differences? How reliable is now() - has anyone seen
anything similar ?

Very reliable: now() always returns the timestamp of the transaction
start. Maybe your timestamp on Table A is created by other means,
possibly timeofday()?

--

I don't know about this particular problem, but I find in programming
in general it's always best to pass in the value of now as a
parameter, and pass it on to functions you are calling, thus avoiding
problems with mismatching values.

But as Andreas says the values should be the same within the same
transaction, at least that's what I thought.

David

[Please copy the mailing list on replies and please don't change
the Subject header. I've restored the original subject and am
copying the list on this reply. I'll look at this when I get a
chance, but maybe somebody else will answer before then.]

On Mon, Nov 21, 2005 at 05:28:30PM -0000, Byrne Kevin-kbyrne01 wrote:

Thank you for your response and I would be intereted in your opinion on a further explanation of my problem:

The first table table (call it Table A) gets the timestamp using timeofday - and assuming what you say below is true - Table B will take now() as start of transaction time - so I can understand that part where they could be different but considering that for moServer every operation happens in a single txn, following will be the case

Moserver receives the event - timestamps it as 't1'
-- time lapse before moserver computes the transation and gives it to odbc.
Txn_begin- now() gets frozen to 't2'
Insert - now() should put it as 't2'
Txn_end()- done.

So firstly t2 should always be > t1 and the difference could be a few seconds but we found sometimes t2 < t1!..

The query is done through odbc ( I think that might be additionally causing some strange behaviour?)..

What do you think?

--
Michael Fuhr

On 11/21/05, Michael Fuhr <mike@fuhr.org> wrote:

[Please copy the mailing list on replies and please don't change
the Subject header. I've restored the original subject and am
copying the list on this reply. I'll look at this when I get a
chance, but maybe somebody else will answer before then.]

On Mon, Nov 21, 2005 at 05:28:30PM -0000, Byrne Kevin-kbyrne01 wrote:

Thank you for your response and I would be intereted in your opinion on a further explanation of my problem:

The first table table (call it Table A) gets the timestamp using timeofday - and assuming what you say below is true - Table B will take now() as start of transaction time - so I can understand that part where they could be different but considering that for moServer every operation happens in a single txn, following will be the case

Moserver receives the event - timestamps it as 't1'
-- time lapse before moserver computes the transation and gives it to odbc.
Txn_begin- now() gets frozen to 't2'
Insert - now() should put it as 't2'
Txn_end()- done.

where is the server in moserver or in another machine you reach with
the odbc connection? if there are two machines involved maybe the
first time you get the time ;) is from one machine and the second time
from the other...

just an idea...

So firstly t2 should always be > t1 and the difference could be a few seconds but we found sometimes t2 < t1!..

The query is done through odbc ( I think that might be additionally causing some strange behaviour?)..

What do you think?

--
Michael Fuhr

---------------------------(end of broadcast)---------------------------
TIP 2: Don't 'kill -9' the postmaster

--
Atentamente,
Jaime Casanova
(DBA: DataBase Aniquilator ;)