After insert/update/delete timing

  • Hi Experts, I've got a "trivial" task to log changes made by various applications to two related tables - [OrderHead] and [OrderLines]. At least two separate applications may be manipulating these tables concurrently, but never for any given order at the same time, thanks to special table holding order id lock for the length of transaction. It is confirmed that (with exception to inserting new order head) each app will always first insert/update/delete [OrderLines] and then update/delete [OrderHead] as a last step.

    I created two after update/insert/delete triggers which merely send new record with changes and getdate() timestamp to another set of tables: [OrderHeadLog] and [OrderLinesLog] each time a change occurs. My task demands that timestamps stay in sync between the two log tables and reflect the "true" course of update events. In theory this should work.

    Contrary to my expectation, I'm finding that sometimes the [OrderHeadLog] receives records prior to [OrderLinesLog]. For example, consider real-world example:

    1) an order gets deleted by deleting all lines first

    2) then the head is deleted

    3) then the same order is re-added again

    4) some new lines created

    5) new head updated

    However my log records may stack up in a totally different order from received timestamp perspective:

    1) head is deleted

    2) the same head is re-added again

    3) new lines created

    4) head updated

    5) lines deleted

    Digging further I realized that log records may sometimes get inconsistently delayed in time making the getdate() result out-of-sync. Any idea why is this happening and is there a way to obtain a "true record update" timestamp inside the trigger?

    One more thing, I set both triggers to fire first in the "Z" order by means of sp_settriggerorder proc to avoid timing impact of other after-triggers attached to the same tables. There are no triggers defined on the two log tables and they are defined as very simple heaps.

    Appreciate your help in advance.

    // Denis

  • denis.p (6/22/2011)


    ...Digging further I realized that log records may sometimes get inconsistently delayed in time making the getdate() result out-of-sync. Any idea why is this happening and is there a way to obtain a "true record update" timestamp inside the trigger?

    What specifically is using getdate()? column default? if trigger, which one? Also, how many triggers are there?

    I've never used the proc before but from BOL article for sp_settriggerorder:

    Specifies the AFTER triggers that are fired first or last. The AFTER triggers that are fired between the first and last triggers are executed in undefined order.

    There are no special teachers of virtue, because virtue is taught by the whole community.
    --Plato

  • Hi, first of all my thanks for responding.

    There are two tables - Lines and Heads, and there are two triggers - one for each table.

    Both are defined as "after-" triggers, for update, insert and delete. Each time one of the monitored tables receive some update the triggers merely save new record snapshot to a corresponding log table: LinesLog for Lines and HeadLog for Head. So here how it goes:

    Lines --- (update/insert/delete) ---> trigger ----> insert to LinesLog

    Head --- (update/insert/delete) ---> trigger ----> insert to HeadLog

    As you can see two completely separate update tracks.

    Now, the Lines table always receives updates prior to Head table. The only exception is when Head table receives new order record (records in Lines table are foreign-keyd to Head table), then the lines are created after, and yet followed by inevitable update to Head table.

    The getdate() (getutcdate() in my case) is called inside each trigger to fill in log records timestamp (a column in each log table).

    With sp_settriggerorder I ensure that no other trigger in the chain for Lines and Head may delay execution of my logging triggers.

    Hopefully this makes more sense now.

    What I'm observing is that despite the update timing for Head and Lines, the timestamps in the log table may show out of sequence, as though head is updated before lines. Again, this seems to take place intermittently, very rarely actually. I wonder if this has to do with asynchronous trigger call nature, and if so whether there is recommended workaround.

    Cheers // Denis

  • denis.p (6/24/2011)


    Hi, first of all my thanks for responding.

    There are two tables - Lines and Heads, and there are two triggers - one for each table.

    Both are defined as "after-" triggers, for update, insert and delete. Each time one of the monitored tables receive some update the triggers merely save new record snapshot to a corresponding log table: LinesLog for Lines and HeadLog for Head. So here how it goes:

    Lines --- (update/insert/delete) ---> trigger ----> insert to LinesLog

    Head --- (update/insert/delete) ---> trigger ----> insert to HeadLog

    As you can see two completely separate update tracks.

    Now, the Lines table always receives updates prior to Head table. The only exception is when Head table receives new order record (records in Lines table are foreign-keyd to Head table), then the lines are created after, and yet followed by inevitable update to Head table.

    The getdate() (getutcdate() in my case) is called inside each trigger to fill in log records timestamp (a column in each log table).

    With sp_settriggerorder I ensure that no other trigger in the chain for Lines and Head may delay execution of my logging triggers.

    Hopefully this makes more sense now.

    What I'm observing is that despite the update timing for Head and Lines, the timestamps in the log table may show out of sequence, as though head is updated before lines. Again, this seems to take place intermittently, very rarely actually. I wonder if this has to do with asynchronous trigger call nature, and if so whether there is recommended workaround.

    Cheers // Denis

    Color me confused :unsure:

    You say "with sp_settriggerorder I ensure that no other trigger in the chain for Lines and Head may delay execution of my logging triggers", yet you say "there are two triggers - one for each table". I am looking to find out what other triggers are on the table, in total how many triggers are on each table besides the logging triggers and what actions are each of them handling?

    Regarding this:

    I wonder if this has to do with asynchronous trigger call nature, and if so whether there is recommended workaround.

    Triggers are not asynchronous. They are included in the same transaction of the action they are handling. For example if you insert data into a table and there is an AFTER INSERT trigger on your table, the trigger has the opportunity to rollback the work done by the INSERT trigger that caused it to fire, i.e. they are synchronous.

    My initial guess is that you may have triggers making data changes that are causing other triggers to fire creating what is presenting itself as a sequencing problem, which is why I want to know what other triggers are out there. Just for the record, I don't use triggers often, but when I do, I never add more than one trigger on a given to handle a given action so I can avoid complicated trigger scenarios.

    There are no special teachers of virtue, because virtue is taught by the whole community.
    --Plato

  • My initial guess is that you may have triggers making data changes that are causing other triggers to fire creating what is presenting itself as a sequencing problem, which is why I want to know what other triggers are out there. Just for the record, I don't use triggers often, but when I do, I never add more than one trigger on a given to handle a given action so I can avoid complicated trigger scenarios.

    Sorry, I didn't realize at first where you going with this. You might have a valid point here. Let me take a careful look at these other triggers to see if they may be responsible for any cross-updates.

    Unfortunately some triggers have been deployed by other solution vendors for integration purposes, so I don't have a luxury to remove them (although I wish I could :))

    I'll get beck with you shortly.

    Thanks // Denis

  • I apologize for delay on this one. Apparently one of the apps was sending records out of sequence. We fixed the problem, the issue is closed. Thank you for the clues you provided. BR // Denis

  • Thanks for posting back, happy you got it sorted 🙂

    There are no special teachers of virtue, because virtue is taught by the whole community.
    --Plato

Viewing 7 posts - 1 through 7 (of 7 total)

You must be logged in to reply to this topic. Login to reply