Trigger Issue...

  • Hi,

    I've a table that has a trigger for insert that executes the flowing statement:

    UPDATE ArtigoArmazem SET QtReservada = 0 FROM INSERTED I INNER JOIN LInhasdoc LD ON i.IdLinhasDoc = LD.Id WHERE ArtigoArmazem.Artigo = LD.Artigo

    The table ArtigoArmazem also has a trigger for update that initially had a cursor to update stocks quantities but I changed it to a "simple" UPDATE:

    -- OLD TRIGGER

    ALTER TRIGGER [dbo].[GCP_STK_ArtigoArmazem_UPD] ON [dbo].[ArtigoArmazem] FOR UPDATE

    AS

    SET NOCOUNT ON

    DECLARE @Artigo AS VARCHAR(50)

    DECLARE @StkActual AS FLOAT

    IF UPDATE(StkActual)

    BEGIN

    DECLARE curRegistos CURSOR LOCAL FORWARD_ONLY STATIC READ_ONLY FOR

    SELECT Artigo, StkActual FROM Deleted WHERE StkActual <> 0

    OPEN curRegistos

    FETCH NEXT FROM curRegistos INTO @Artigo, @StkActual

    WHILE @@FETCH_STATUS = 0

    BEGIN

    EXEC GCP_STK_ActualizaArtigo 'R', @Artigo, @StkActual

    FETCH NEXT FROM curRegistos INTO @Artigo, @StkActual

    END

    CLOSE curRegistos

    DEALLOCATE curRegistos

    DECLARE curRegistos CURSOR LOCAL FORWARD_ONLY STATIC READ_ONLY FOR

    SELECT Artigo, StkActual FROM Inserted

    OPEN curRegistos

    FETCH NEXT FROM curRegistos INTO @Artigo, @StkActual

    WHILE @@FETCH_STATUS = 0

    BEGIN

    EXEC GCP_STK_ActualizaArtigo 'I', @Artigo, @StkActual

    FETCH NEXT FROM curRegistos INTO @Artigo, @StkActual

    END

    CLOSE curRegistos

    DEALLOCATE curRegistos

    END

    GO

    ---- The SP GCP_STK_ActualizaArtigo just does an UPDATE on @Artigo and sets StkActual to StkActual + @StkActual if 'I' or StkActual - @StkActual id 'D'

    ----- NEW TRIGGER----

    CREATE TRIGGER [dbo].[GCP_STK_ArtigoArmazem_UPD] ON [dbo].[ArtigoArmazem] FOR UPDATE

    AS

    BEGIN

    SET NOCOUNT ON

    IF UPDATE(StkActual)

    BEGIN

    ;WITH res AS

    (

    SELECT Artigo, -StkActual AS StkActual FROM DELETED WHERE StkActual <> 0

    UNION ALL

    SELECT Artigo, StkActual FROM INSERTED

    ), res1 AS (

    SELECT Artigo, SUM(StkActual) Stk FROM res GROUP BY Artigo

    )

    UPDATE Artigo SET STKActual = STKActual + res1.Stk FROM res1 WHERE MovStock = 'S' AND Artigo.Artigo = res1.artigo

    END

    END

    When I run a trace to see what's happening I get with the OLD trigger a duration of half the new trigger and 900 reads vs 4900 reads with the new trigger!!!

    If I insert a RETURN statement just at the beginning of the new trigger the results are the same but if I let the RETURN and remove the rest of the SQL the result is the same as the old trigger.

    What can be causing this? The trigger's code shouldn't even be executed case UPDATE(stkActual) is false...

    Thanks,

    Pedro



    If you need to work better, try working less...

  • Just another strange thing happening with the triggers on the database....

    The GCP_VND_ActualizaDocumentoVenda_LinhasDocStatus procedure has an INSERT on a table that has a trigger.

    I start a server trace on the SP to monitor what's going on the database and get this:

    INSERT INTO [dbo].[LinhasDocStatus] ([IDLinhasDoc], [Quantidade], [QuantReserv], [QuantTrans], [EstadoTrans], [Fechado]) SELECT [ID], [QT], [QTR], [QTS], [ET], [FE] FROM [dbo].[#TmpLinhas] WHERE ([EBD] = 2 OR ([EBD] = 3 AND @bitDocNovo = 1))

    This statement takes 248ms to execute...

    The trigger code "fired" by the INSERT has an IF EXISTS with a SELECT and two UPDATE...

    * IF with SELECT: 0,169ms

    * UPDATE: 1,071ms

    * UPDATE: 7,287ms

    The SUM from the trigger time is way less than the time the INSERT says it takes to execute..

    So I disabled the trigger to see how long would the INSERT execute just by itself.... 13,39ms!!!

    So, math made, the INSERT 13,39ms + SUM(Trigger) 9ms gives 23ms... but the INSERT with the trigger takes 248ms.. 10x more...

    Can anyone tell me how to figure what's going on the database?!

    The scenarios are the same on both cases since I restore the database and do an index rebuild and statistics update every time and clear the cache and buffers...

    Thanks,

    Pedro



    If you need to work better, try working less...

  • I ran SQL Profiler on the GCP_VND_ActualizaDocumentoVenda_LinhasDocStatus procedure with all the events and data checked...

    I've a big table to analyse but I don't know what to search for... It even has the execution plans...

    But still I noticed:

    The SUM of Duration inside the trigger is 440 (EventClass 45 and 43 for the INSERT) and the Duration of the INSERT that fires the trigger is 1173 (EventClass 45).

    ?!?!

    With the trigger disabled the GCP_VND_ActualizaDocumentoVenda_LinhasDocStatus procedure duration is 188, that is "close" the the 200 from the duration with the trigger enabled.

    Thanks,

    Pedro



    If you need to work better, try working less...

  • It's difficult to say exactly what is going on without access to the database, but there is an overhead of putting the rows for inserted and deleted to the version store. I would not expect it to as high as in your examples, though.

    [font="Times New Roman"]Erland Sommarskog, SQL Server MVP, www.sommarskog.se[/font]

  • I have the full trace from profiler with events 12, 41, 43, 45, 122, 146 and 168....

    But dont say much... or at least I dont know how to look at them... just the times...

    Thanks,

    Pedro



    If you need to work better, try working less...

  • I realiased that my post was a little terse, so I should try to qualify it a bit.

    Say that you have a trace which captures SP:StmtCompleted. Say that you inside a stored procedure call a longer stored procedure that is not in the cache. Most likely you will find that StartTime for StmtCompleted for the EXEC statement and the first statement in the procedure will be quite a few milliseconds apart. This time span represents the overhead to call the procedure. This includes time for passing parameters, setting up table variables and most of all to compile the procedure.

    The same applies for a trigger, but for a trigger there is also the overhead for setting up the inserted/deleted tables. This overhead can be seen in a trace as well, as the difference between StartTime for the statement that fires the trigger and the StartTime for the first statement in the trigger. However, if the statement that fires the trigger takes time to execute in itself, the waters get quite muddled.

    Now, there is one more thing to notice about your trace: you include the events Showplan XML, Showplan XML Statistics Profile and Showplan XML For Query Compile, and if you include these events things like durations are distorted considerably, because they incur a very significant overhead. If you remove these events, you will see completely different numbers for duration.

    You should use trace for these events in production evironments, except for very short periods. Tracing for these events can badly degrade the overall performance for your system. Note that even if you filter for a specifc spid, all processes start generating information for this event, and this is very costly. Believe me. I've sanka customer system that way. Very embarrassing.

    [font="Times New Roman"]Erland Sommarskog, SQL Server MVP, www.sommarskog.se[/font]

  • But my "biggest" problem is the issue on the first post...

    I have a trigger with a cursor that calls a procedure and changed it to an update statement...

    The one with the cursor has less reads, way less, than the update statement even having the condition to exit if the field hasn't changed...

    They both should do the same, nothing, just the IF UPDATE(StkActual) and exit but the one with the UPDATE statement is taking longer...

    Thanks,

    Pedro



    If you need to work better, try working less...

  • Do you make the same observations, even if you do not include the showplan events in the trace?

    [font="Times New Roman"]Erland Sommarskog, SQL Server MVP, www.sommarskog.se[/font]

  • Erland Sommarskog (9/18/2013)


    Do you make the same observations, even if you do not include the showplan events in the trace?

    Yep. The data from the first post only had event 12 and 45 (profiler's default for tuning).

    Pedro



    If you need to work better, try working less...

  • I don't really have any more ideas that I have offered previously (and in which I don't believe fully). Did you compare StartTime for the INSERT statement with the StartTime for the first statement in the trigger? Also, in the trace where are the reads listed?

    Could you attach the trace where this is happening?

    [font="Times New Roman"]Erland Sommarskog, SQL Server MVP, www.sommarskog.se[/font]

  • Hi,

    Sorry, just saw the message now (spent the day at a MS workshop).

    Tomorrow when I arrive at the office I'll post the 2 trace data:

    1. Current trigger (that uses a cursor and calls an SP)

    2. Updated trigger (uses SQL directly).

    I'll just catch events 12 and 45. Are there any more necessary (43, 168, ...)?

    Thanks,

    Pedro



    If you need to work better, try working less...

  • 10 and 41 are good to include as well.

    Since you are tracing a single statement (plus triggers), sp_sqltrace can be useful. It's available on my web site:

    http://www.sommarskog.se/sqlutil/sqltrace.html

    [font="Times New Roman"]Erland Sommarskog, SQL Server MVP, www.sommarskog.se[/font]

  • Hi,

    Just added an Excel file with the full trace with the original trigger and the changed trigger (that should be faster, and in "simple" UPDATE tests to the table it is much, much faster).

    I also added a 3rd sheet with a side by side comparison of the code I find strange...

    The statement UPDATE AA SET QtReservada = 0 FROM Inserted I INNER ... executes inside a trigger and fires another trigger, I don't know if this might be the problem source (trigger inside triggers is badddd).

    But the truth is that with the slow ArtigoArmazem trigger (the 1st on the SQL script attachment) it's much faster than the improved trigger (2,25ms vs 55,7ms).

    So I made a test... I changed the new trigger and added a RETURN statement right at the top.... same result...

    The I removed the rest of the trigger code, just left the RETURN... fast again....

    Does SQL have an issue with the WITH statement or something??! I made a test and removed the WITH and replaced it with a subquery but still slow...

    It's the same database, I just keep changing the trigger code and executing the traces so nothing to do with indexes, or whatever... Statistics are updated, indexes full rebuild...

    What can be causing this issue with the triggers?!

    Further on the trace the trigger is used again and the new one is faster with less reads, since it's used... In this case it's used but does nothing since the StkActual column isn't updated...

    Thanks,

    Pedro



    If you need to work better, try working less...

  • If you look closer the in the after-trigger trace, you will find that it is only the first invocation that takes a longer time. Furthermore, if you look close at the times, you will find this:

    This statement fires the trigger:

    UPDATE AA SET QtReservada = 0 FROM Inserted I INNER JOIN LinhasDoc LD ON LD.Id=I.IdLinhasDoc INNER JOIN ArtigoArmazem AA ON AA.Artigo=LD.Artigo --BID: 583194

    It starts executing at 2013-09-20 10:44:00.187

    The first command in the contested trigger is SET NOCOUNT ON, and this command starts executing at 2013-09-20 10:44:00.240. (You need to look at the SET NOCOUNT ON that are a few lines above, since you have xxx:Completed events.

    This is typically what you see when a module is compiled. Since the new trigger includes a more complex query than the old trigger it takes longer time to compile, but if the plan stays in cache, this overhead can be neglected.

    [font="Times New Roman"]Erland Sommarskog, SQL Server MVP, www.sommarskog.se[/font]

  • Erland Sommarskog (9/20/2013)This is typically what you see when a module is compiled. Since the new trigger includes a more complex query than the old trigger it takes longer time to compile, but if the plan stays in cache, this overhead can be neglected.

    Thanks, I noticed that when I removed the DBCC commands the execution with the new trigger was faster, but for performance measures I always do the DBCC... Or should I just do the DBCC for the data cache (if there's just that one)?

    Maybe just http://technet.microsoft.com/en-us/library/ms187762.aspx.

    Thanks,

    Pedro



    If you need to work better, try working less...

Viewing 15 posts - 1 through 15 (of 18 total)

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