Click here to monitor SSC
SQLServerCentral is supported by Red Gate Software Ltd.
 
Log in  ::  Register  ::  Not logged in
 
 
 
        
Home       Members    Calendar    Who's On


Add to briefcase 12»»

Trigger Issue... Expand / Collapse
Author
Message
Posted Monday, September 16, 2013 8:37 AM


Mr or Mrs. 500

Mr or Mrs. 500Mr or Mrs. 500Mr or Mrs. 500Mr or Mrs. 500Mr or Mrs. 500Mr or Mrs. 500Mr or Mrs. 500Mr or Mrs. 500

Group: General Forum Members
Last Login: Friday, December 19, 2014 10:10 AM
Points: 526, Visits: 1,163
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...
Post #1495122
Posted Tuesday, September 17, 2013 5:19 AM


Mr or Mrs. 500

Mr or Mrs. 500Mr or Mrs. 500Mr or Mrs. 500Mr or Mrs. 500Mr or Mrs. 500Mr or Mrs. 500Mr or Mrs. 500Mr or Mrs. 500

Group: General Forum Members
Last Login: Friday, December 19, 2014 10:10 AM
Points: 526, Visits: 1,163
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...
Post #1495447
Posted Tuesday, September 17, 2013 6:01 AM


Mr or Mrs. 500

Mr or Mrs. 500Mr or Mrs. 500Mr or Mrs. 500Mr or Mrs. 500Mr or Mrs. 500Mr or Mrs. 500Mr or Mrs. 500Mr or Mrs. 500

Group: General Forum Members
Last Login: Friday, December 19, 2014 10:10 AM
Points: 526, Visits: 1,163
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...
Post #1495467
Posted Tuesday, September 17, 2013 4:05 PM


SSC Eights!

SSC Eights!SSC Eights!SSC Eights!SSC Eights!SSC Eights!SSC Eights!SSC Eights!SSC Eights!

Group: General Forum Members
Last Login: Friday, December 12, 2014 1:02 AM
Points: 823, Visits: 753
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.

Erland Sommarskog, SQL Server MVP, www.sommarskog.se
Post #1495713
Posted Wednesday, September 18, 2013 2:36 AM


Mr or Mrs. 500

Mr or Mrs. 500Mr or Mrs. 500Mr or Mrs. 500Mr or Mrs. 500Mr or Mrs. 500Mr or Mrs. 500Mr or Mrs. 500Mr or Mrs. 500

Group: General Forum Members
Last Login: Friday, December 19, 2014 10:10 AM
Points: 526, Visits: 1,163
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...
Post #1495807
Posted Wednesday, September 18, 2013 4:34 AM


SSC Eights!

SSC Eights!SSC Eights!SSC Eights!SSC Eights!SSC Eights!SSC Eights!SSC Eights!SSC Eights!

Group: General Forum Members
Last Login: Friday, December 12, 2014 1:02 AM
Points: 823, Visits: 753
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.


Erland Sommarskog, SQL Server MVP, www.sommarskog.se
Post #1495835
Posted Wednesday, September 18, 2013 4:44 AM


Mr or Mrs. 500

Mr or Mrs. 500Mr or Mrs. 500Mr or Mrs. 500Mr or Mrs. 500Mr or Mrs. 500Mr or Mrs. 500Mr or Mrs. 500Mr or Mrs. 500

Group: General Forum Members
Last Login: Friday, December 19, 2014 10:10 AM
Points: 526, Visits: 1,163
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...
Post #1495838
Posted Wednesday, September 18, 2013 6:24 AM


SSC Eights!

SSC Eights!SSC Eights!SSC Eights!SSC Eights!SSC Eights!SSC Eights!SSC Eights!SSC Eights!

Group: General Forum Members
Last Login: Friday, December 12, 2014 1:02 AM
Points: 823, Visits: 753
Do you make the same observations, even if you do not include the showplan events in the trace?

Erland Sommarskog, SQL Server MVP, www.sommarskog.se
Post #1495885
Posted Wednesday, September 18, 2013 7:48 AM


Mr or Mrs. 500

Mr or Mrs. 500Mr or Mrs. 500Mr or Mrs. 500Mr or Mrs. 500Mr or Mrs. 500Mr or Mrs. 500Mr or Mrs. 500Mr or Mrs. 500

Group: General Forum Members
Last Login: Friday, December 19, 2014 10:10 AM
Points: 526, Visits: 1,163
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...
Post #1495927
Posted Wednesday, September 18, 2013 3:31 PM


SSC Eights!

SSC Eights!SSC Eights!SSC Eights!SSC Eights!SSC Eights!SSC Eights!SSC Eights!SSC Eights!

Group: General Forum Members
Last Login: Friday, December 12, 2014 1:02 AM
Points: 823, Visits: 753
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?


Erland Sommarskog, SQL Server MVP, www.sommarskog.se
Post #1496153
« Prev Topic | Next Topic »

Add to briefcase 12»»

Permissions Expand / Collapse