Tony Rogerson's ramblings on SQL Server

Just picked the majority of my crop, grown in a mixture of green house and garden here in Harpenden just north of London in the UK.

Its the effort of about 8 plants at a price of about £1.50.

I know the small ones are lethal as my wife made a big pan of soup and only put one in there and it was really hot :).

Anybody got any ideas what to do with them? I'm going to try and create some chillie oil by putting some in olive oil.

Did you know that when you use the INSERTED and DELETED system materialised tables in a FOR (AFTER) trigger they are actually materialised from the transaction log (LDF file). Why is this bad? Transaction log writing is sequential in nature and for optimum performance no other processes should be writing to the disk the transaction log is on (even other transaction logs for other databases), that way the disk head will be in exactly the correct position for the next write thereby reducing the latency for disk writes thereby allowing your transaction to commit faster.

But, did you also know that ALTER TABLE <blah> DISABLE TRIGGER <blah> only disables the functionality of the trigger, something else is going on that causes the same underlying additional writes to the transaction log which is the overhead of using the trigger, for instance I have a straight UPDATE, without the trigger it writes 843Kbytes to the transaction log, with the trigger it writes 80,028Kbytes – yes, that’s a tad more! Even disabling the trigger still causes the 80Mbytes to be written to the transaction log.

Note: I’m keeping this entry purely SQL Server 2000 (SP4 and SP4 with 2187 applied) tested on multiple servers; I’ll update for 2005 shortly, 2005 should use tempdb instead because of the version store.

Here is the script:-

Set up:-

CREATE DATABASE [play] ON  PRIMARY

( NAME = N'play', FILENAME = N'f:\MSSQL\MSSQL\data\play.mdf' , SIZE = 512000KB , FILEGROWTH = 10240KB )

 LOG ON

( NAME = N'play_log', FILENAME = N'f:\MSSQL\MSSQL\data\play_log.ldf' , SIZE = 512000KB , FILEGROWTH = 10240KB )

GO

EXEC dbo.sp_dbcmptlevel @dbname=N'play', @new_cmptlevel=80

GO

ALTER DATABASE [play] SET RECOVERY FULL

GO

create table mytest (

    id  int not null    identity primary key clustered,

    trade_quantity  int not null,

    pad_row char(4000) not null

)

create table summary (

    trade_quantity int not null

)

insert summary values( 0 )

set nocount on

declare @i int

set @i = 1

while @i <= 10000

begin

    insert mytest ( trade_quantity, pad_row ) values( @i, 's' )

    set @i = @i + 1

end

go

Ok, now the fun part; first lets test a straight update without the trigger.

select *

from ::fn_virtualfilestats( 20, 2 )

go

update mytest

    set trade_quantity = trade_quantity + 1,

        pad_row = cast( trade_quantity as char(4000) )

go

select *

from ::fn_virtualfilestats( 20, 2 )

go

Now, remember to substitute 20 with DB_ID() !

Results:-

--  NumberReads = 0

--  NumberWrites= 15

--  BytesWritten= 843KBytes

--  BytesRead   = 0

That’s good, we have only written to the LDF.

Now the trigger code, this is common logic, it updates a summary table; note – this additional write and materialisation from the LDF would also be there even if you are just querying the INSERTED and DELETED tables aka referential integrity triggers.

create trigger trg_test on mytest FOR update

as

begin

    update summary

        set trade_quantity = ( trade_quantity -

                             ( select sum( trade_quantity )

                               from deleted ) )

                           + ( select sum( trade_quantity )

                               from inserted )

end

go

And now the results…

select *

from ::fn_virtualfilestats( 20, 2 )

go

update mytest

    set trade_quantity = trade_quantity + 1,

        pad_row = cast( trade_quantity as char(4000) )

go

select *

from ::fn_virtualfilestats( 20, 2 )

go

--  NumberReads = 1344

--  NumberWrites= 1373

--  BytesWritten=  80,084KBytes

--  BytesRead   = 157,958KBytes

Look, we have had to do 157Mbytes of read FROM the LDF but also the write requirement has now grown from 843Kbytes to an astonishing 80Mbytes!

Now disable the trigger and try the test again…

alter table mytest disable trigger trg_test

go

select *

from ::fn_virtualfilestats( 20, 2 )

go

update mytest

    set trade_quantity = trade_quantity + 1,

        pad_row = cast( trade_quantity as char(4000) )

go

select *

from ::fn_virtualfilestats( 20, 2 )

go

--  NumberReads = 8

--  NumberWrites= 1355

--  BytesWritten= 80,082KBytes

--  BytesRead   = 32KBytes

The number of reads and bytes read has dramatically reduced now, but look at the number of bytes written – its still 80Mbytes! Stone me J I was expecting bytes written to be back to 843Kbytes!!

Lets drop the trigger and see what happens…

drop trigger trg_test

go

select *

from ::fn_virtualfilestats( 20, 2 )

go

update mytest

    set trade_quantity = trade_quantity + 1,

        pad_row = cast( trade_quantity as char(4000) )

go

select *

from ::fn_virtualfilestats( 20, 2 )

go

--  NumberReads = 0

--  NumberWrites= 15

--  BytesWritten= 843KBytes

--  BytesRead   = 0KBytes

Yep, back to normal now.

The amount of data written varies because in the non-trigger situation SQL Server is clever enough to only write to the log what needs to be changed, so it doesn't write the whole row, that is born out by running this statement multiple times, the first causes more writes because it has more 'changes' to do.

When you have a trigger, because you may require INSERTED and DELETED system materialised tables then it has to put down the whole row to the transaction log (I think it's worse than that, it needs to put down the old and new rows to the log), this is because the INSERTED and DELETED tables are in column terms a copy of the base table, they do only contain the rows being processed, but you start to see why the trigger is so much more hefty.

Why disabling the trigger is not giving the minimalistic behaviour I’m not sure, there must be some internal storage engine requirement because the trigger is there; but to summarise – if you are using triggers please be aware of the above behaviour; if you have long running batch jobs that use triggers that you disable before commencing it is best to drop the trigger first rather than disabling it.

Also - be aware of things that use triggers, for instance merge replication!

Did you know SQL Server is clever enough not to log stuff it doesn't really need to.

So, this statement ->

UPDATE mytest 
   SET smallcol = smallcol + 1
     , somedata = somedata
WHERE id = @i

Is the same as writing this ->

It’s quite difficult to work out if your kit will support the load that you want to put on it. Through my consultancy years I’ve often been in the position of trying to determine whether an existing system will be capable of scaling up to more users and more data – this is a difficult task, but there are methods.

In this article I suggest a method for determining the performance and ability of your hardware in servicing the write load for your system, specifically determining how many updates/inserts/deletes can be done with the performance of the transaction log being the only factor, so discounting concurrency (for the moment!).

We need to consider a couple of things before going any further, firstly an INSERT / UPDATE / DELETE is not complete and SQL Server will not allow the process to continue until it has been told that the data physically resides on in the transaction log on the disk (the LDF file), the MDF is written in a different matter, the throughput of INSERT’s, UPDATE’s and DELETE’s is directly related to how fast you can get data into the LDF on disk whereas the MDF is written in a different manner – dirty pages (changes) are batched up and written as a big burst of data around checkpoint time or when the SQL Server decides it needs the pages for some other data so has to write them out to disk.

Straight to the test, create a test database, change G: to where you want to test your transaction log performance and E: to your MDF file; try and keep them separate especially for this test but in practice writing to the transaction log is almost purely sequential and the MDF random so you want the transaction log on its own disks where nothing will be changing the disk head position.

CREATE DATABASE [IOMeter] ON  PRIMARY

( NAME = N'IOMeter', FILENAME = N'e:\IOMeter.mdf' , SIZE = 1048576KB , FILEGROWTH = 1024KB )

 LOG ON

( NAME = N'IOMeter_log', FILENAME = N'g:\IOMeter_log.ldf' , SIZE = 1048576KB , FILEGROWTH = 10%)

GO

EXEC dbo.sp_dbcmptlevel @dbname=N'IOMeter', @new_cmptlevel=90

GO

GO

ALTER DATABASE [IOMeter] SET RECOVERY FULL

GO

ALTER DATABASE [IOMeter] SET PAGE_VERIFY CHECKSUM 

GO

Let’s create our test table, this can be one of your own tables, in fact if you have the time you could actually use your own schema and test a specific stored procedure performance etc. but for this example I just want to illustrate some log behaviour so I’ll use a simple table…

USE IOMeter

GO

CREATE TABLE mytest (

    id  int not null identity primary key clustered,

    somedata char(4000) not null

)

GO

CREATE TABLE io_results (

    test_name varchar(100) not null,

    entry_date  datetime    not null default( getdate() ),

    write_ios   int         not null,

    write_bytes bigint      not null,

    transaction_size int    not null,

    ios_per_row decimal( 10, 3 ) not null,

    ios_per_xact decimal( 10, 3 ) not null,

    bytes_per_io decimal( 10, 3 ) not null,

    mbytes_per_sec decimal( 10, 3 ) not null,

    rows int not null,

    commits int not null,

    duration_seconds int not null

)

Now for the test, the is your test harness, if you are going to use your own stuff then I would suggest putting it in another stored procedure and replace the INSERT mytest with a call to your stored procedure.

CREATE PROC test_perf

    @test_name varchar(100),

    @tran_batch_size int

AS

BEGIN

    SET NOCOUNT ON

    IF @@TRANCOUNT > 0

        ROLLBACK            --  Make sure no transaction open

    WAITFOR DELAY '00:00:05'    --  System settle, helps seperate stuff in PERFMON

    TRUNCATE TABLE mytest

    CHECKPOINT                  --  Write any dirty pages to disk

    DBCC DROPCLEANBUFFERS       --  Empty data cache

    DBCC FREEPROCCACHE          --  Empty execution cache

    ALTER DATABASE IOMeter SET RECOVERY SIMPLE

    CHECKPOINT

    ALTER DATABASE IOMeter SET RECOVERY FULL

    WAITFOR DELAY '00:00:05'    --  System settle, helps seperate stuff in PERFMON

    DECLARE @i int

    DECLARE @c int

    SET @i = 1

    SET @c = 0

    SELECT 'START' AS op, GETDATE() AS op_time, *

    INTO #filestats

    FROM ::fn_virtualfilestats( db_id(), 2 )

    BEGIN TRAN

    WHILE @i <= 100000

    BEGIN

        INSERT mytest ( somedata ) VALUES( CAST( @i AS char(4000) ) )

        IF @i % @tran_batch_size = 0

        BEGIN

            SET @c = @c + 1

            COMMIT TRAN

            IF @i < 100000

                BEGIN TRAN

        END

        SET @i = @i + 1

    END

    IF @@TRANCOUNT > 0

        COMMIT TRAN

    INSERT #filestats (

        op, op_time, DbId, FileId, TimeStamp, NumberReads, BytesRead,

        IoStallReadMS, NumberWrites, BytesWritten,

        IoStallWriteMS, IoStallMS, BytesOnDisk, FileHandle )

    SELECT 'END', getdate(), DbId, FileId, TimeStamp, NumberReads, BytesRead,

        IoStallReadMS, NumberWrites, BytesWritten,

        IoStallWriteMS, IoStallMS, BytesOnDisk, FileHandle

    FROM ::fn_virtualfilestats( db_id(), 2 )

    INSERT io_results (

        test_name,

        write_ios,

        write_bytes,

        transaction_size,

        ios_per_row,

        ios_per_xact,

        bytes_per_io,

        mbytes_per_sec,

        rows,

        commits,

        duration_seconds )

    SELECT @test_name,

           Write_IOs   = e.NumberWrites - s.NumberWrites,

           Write_Bytes = e.BytesWritten - s.BytesWritten,

           transaction_size = @tran_batch_size,

           IOs_Per_Row = CAST( (e.NumberWrites - s.NumberWrites) AS decimal( 10, 3 ) ) / 100000,

           IOs_Per_Xact= CAST( (e.NumberWrites - s.NumberWrites) AS decimal( 10, 3 ) ) / @c,

           Bytes_Per_IO= CAST( ( e.BytesWritten - s.BytesWritten ) AS decimal( 20, 3 ) ) / (e.NumberWrites - s.NumberWrites),

           MBytes_Per_Sec = ( CAST( ( e.BytesWritten - s.BytesWritten ) AS decimal( 20, 3 ) ) / DATEDIFF( second, s.op_time, e.op_time ) ) / 1048576,

           Rows        = (SELECT COUNT(*) FROM mytest),

           Commits     = @c,

           duration_seconds = datediff( second, s.op_time, e.op_time )

    FROM #filestats s

        CROSS JOIN #filestats e

    WHERE s.op = 'START'

      AND e.op