Обсуждение: Odd transaction timestamp sequence issue
PostgreSQL 8.1.2 on i386-portbld-freebsd6.0, compiled by GCC cc (GCC) 3.4.4 [FreeBSD] 20050518 We have triggers on each of our tables that create audit table entries on each insert/update/delete. The audit table (in addition to containing information about the change that was made) contains a timestamp field and a serial as the primary key. The timestamp is generated by calling now() inside the audit trigger, so should contain the timestamp of when the transaction (that yielded the insert/update/delete) began. We have a single (and very important) table that we perform the majority of our operations on..I'll simplify the definition of the table to this: CREATE TABLE thetable ( id int8 NOT NULL DEFAULT nextval('thetable_id_seq'::regclass), flag char(1) NOT NULL, state char(8) NOT NULL } we have a scenario where a batch process takes records from this table in a certain state and one by one, moves them to a new state. update thetable set state='COMPLETE', flag='X' where state='INITIAL' and id=? Another batch process is looking for any records in that new state...and then updates certain elements of it. update thetable set flag='Y' where id in (select id from thetable where state='COMPLETE') This update statement is run as it's own transaction (there is nothing else done in the transaction). The audit logs for some transactions show something very odd. For example, for id 210210 we have an audit trail that looks like this... audit_id record_id when column old_val new_val -------- ----------- -------------- ------- ------- ------- 1 210210 2006-04-20 12:49:03.92 state INITIAL COMPLETE 2 210210 2006-04-20 12:49:03.74 flag X Y By looking at the timestamps, the second update started BEFORE the first update even though the second update cannot occur if the state hasn't been changed and committed by the first one! Even weirder is that the order of the sequence (audit_id) shows them occurring in the opposite order.... Am I missing something obvious here?
Jeff Amiel <jamiel@istreamimaging.com> writes: > For example, for id 210210 we have an audit trail that looks like this... > audit_id record_id when column old_val > new_val > -------- ----------- -------------- ------- ------- > ------- > 1 210210 2006-04-20 12:49:03.92 state INITIAL > COMPLETE > 2 210210 2006-04-20 12:49:03.74 flag X Y > By looking at the timestamps, the second update started BEFORE the first > update even though the second update cannot occur if the state hasn't > been changed and committed by the first one! How is the "when" column determined? You did not show it in your SQL commands. If it's being driven off now() or CURRENT_TIMESTAMP, then the above isn't all that surprising, because the value is the time of transaction start not the time at which the update was made. regards, tom lane
On Fri, Apr 21, 2006 at 09:43:55AM -0500, Jeff Amiel wrote: > PostgreSQL 8.1.2 on i386-portbld-freebsd6.0, compiled by GCC cc (GCC) > 3.4.4 [FreeBSD] 20050518 > > We have triggers on each of our tables that create audit table entries > on each insert/update/delete. > The audit table (in addition to containing information about the change > that was made) contains a timestamp field and a serial as the primary key. > The timestamp is generated by calling now() inside the audit trigger, so > should contain the timestamp of when the transaction (that yielded the > insert/update/delete) began. now() returns the same time throughout the transaction i.e. the transaction start time. If you want a time independant of transaction status, perhaps you want timeofday(). Check the docs for the specifics. Have a nice day, -- Martijn van Oosterhout <kleptog@svana.org> http://svana.org/kleptog/ > From each according to his ability. To each according to his ability to litigate.
Вложения
it is done using now().... But what I don't understand is how the transaction that started first could 'see' the record that hadn't been changed yet by the initial update to 'COMPLETE'? I thought: "Each transaction sees a snapshot (database version) as of its starttime, no matter what other transactions are doing while it runs" > How is the "when" column determined? You did not show it in your SQL > commands. > > If it's being driven off now() or CURRENT_TIMESTAMP, then the above > isn't all that surprising, because the value is the time of transaction > start not the time at which the update was made. > >
Jeff Amiel <jamiel@istreamimaging.com> writes: > I thought: > "Each transaction sees a snapshot (database version) as of its > starttime, no matter what other transactions are doing while it runs" That's a correct statement in SERIALIZABLE mode, but in the default READ COMMITTED mode, it's more complicated --- a new snapshot is taken for each command within a transaction. See the docs. regards, tom lane