October 17, 2008 at 6:57 am
Hello,
I am using multiple SqlBulkCopy objects within multiple threads to write data into one common database table. The data is obtained via a custom DataReader implemented to read from a common data source.
So now I´m starting 3, 4 or 5 threads almost at the same time to write into the same data table and most times this all works out perfectly. But sometimes a deadlock occurrs on the server and one of the .WriteToServer(Datareader)-calls breaks with an exception.
So I am wondering how this can happen ? I am referencing the same target table on the server - so in my opinion it may happen that one transaction block the others - but there should never be a deadlock because there is no cyclic dependency of used ressources.
Or am I wrong with my assumptions ?
Does anyone have an idea what happens in this case ? Or did anyone experience the same problem ?
Thanks in advance for any ideas,
Juergen
October 17, 2008 at 8:30 am
I can provide you a number of theories about what may or may not be causing this. The best way to determine for certain why you are getting the deadlock is to enable some trace flags on the SQL Server and have it log the deadlock graph to the ErrorLog when it occurs. This will contain the exact reason for the deadlock. The trace flags to enable depends on what version of SQL Server you are on. If you are on SQL Server 2000, then you can run
DBCC TRACEON (1204, 3605, -1)
DBCC TRACEON (1205, 3605, -1)
On SQL Server 2005:
DBCC TRACEON (1222, 3605, -1)
When the deadlock occurs, it will write a detailed graph of what happened to the SQL Server ErrorLog. Once you have the graph, turn the trace flags off with DBCC TRACEOFF, using the same information in the parenthesis that you used to turn them on. If you want to take a stab at understanding the graph on your own, I would recommend reading Bart Duncans Blog posts:
http://blogs.msdn.com/bartd/attachment/747119.ashx
http://blogs.msdn.com/bartd/archive/2006/09/13/Deadlock-Troubleshooting_2C00_-Part-2.aspx
Otherwise post the graph details from the errorlog back in this thread and we can better assist you.
Jonathan Kehayias | Principal Consultant | MCM: SQL Server 2008
My Blog | Twitter | MVP Profile
Training | Consulting | Become a SQLskills Insider
Troubleshooting SQL Server: A Guide for Accidental DBAs[/url]
October 17, 2008 at 11:43 am
Hello,
Thanks for your assistance. I will read the articles you provided as they seem to be very interesting. But I still could need some help in interpreting the error log for this time...
Here is the log :
2008-10-17 18:58:03.38 spid13s deadlock-list
2008-10-17 18:58:03.38 spid13s deadlock victim=process44ed708
2008-10-17 18:58:03.38 spid13s process-list
2008-10-17 18:58:03.38 spid13s process id=process44ed708 taskpriority=0 logused=0 waitresource=OBJECT: 5:1749581271:0 waittime=3182 ownerId=75533 transactionname=SetCnstNotTrusted lasttranstarted=2008-10-17T18:58:00.200 XDES=0x802bf970 lockMode=Sch-M schedulerid=4 kpid=2996 status=suspended spid=54 sbid=0 ecid=0 priority=0 trancount=1 lastbatchstarted=2008-10-17T18:57:57.147 lastbatchcompleted=2008-10-17T18:57:57.147 clientapp=TestDataSource hostname=WIN-92BWPBPPZ6R hostpid=844 loginname=WIN-92BWPBPPZ6R\Administrator isolationlevel=read committed (2) xactid=68692 currentdb=5 lockTimeout=4294967295 clientoption1=671088672 clientoption2=128056
2008-10-17 18:58:03.38 spid13s executionStack
2008-10-17 18:58:03.38 spid13s frame procname=adhoc line=1 sqlhandle=0x0200000061c9a220c564361e00f44b52a3d489c34a4ace28
2008-10-17 18:58:03.38 spid13s insert bulk [SCHEMA].[TableName] ([Col1] UniqueIdentifier, [Col2] DateTime2(3), [Col3] BigInt, [Col4] BigInt, [Col5] Float, [Col6] NVarChar(256) COLLATE SQL_Latin1_General_CP1_CI_AS, [Col7] DateTime2(3))
2008-10-17 18:58:03.38 spid13s inputbuf
2008-10-17 18:58:03.38 spid13s insert bulk [SCHEMA].[TableName] ([Col1] UniqueIdentifier, [Col2] DateTime2(3), [Col3] BigInt, [Col4] BigInt, [Col5] Float, [Col6] NVarChar(256) COLLATE SQL_Latin1_General_CP1_CI_AS, [Col7] DateTime2(3))
2008-10-17 18:58:03.38 spid13s process id=process44b9048 taskpriority=0 logused=0 waitresource=OBJECT: 5:1749581271:0 waittime=268 ownerId=82800 transactionname=SetCnstNotTrusted lasttranstarted=2008-10-17T18:58:03.117 XDES=0x8198e3b0 lockMode=Sch-M schedulerid=2 kpid=3752 status=suspended spid=56 sbid=0 ecid=0 priority=0 trancount=1 lastbatchstarted=2008-10-17T18:57:58.143 lastbatchcompleted=2008-10-17T18:57:58.143 clientapp=TestDataSource hostname=WIN-92BWPBPPZ6R hostpid=844 loginname=WIN-92BWPBPPZ6R\Administrator isolationlevel=read committed (2) xactid=68793 currentdb=5 lockTimeout=4294967295 clientoption1=671088672 clientoption2=128056
2008-10-17 18:58:03.38 spid13s executionStack
2008-10-17 18:58:03.38 spid13s frame procname=adhoc line=1 sqlhandle=0x0200000061c9a220c564361e00f44b52a3d489c34a4ace28
2008-10-17 18:58:03.38 spid13s insert bulk [SCHEMA].[TableName] ([Col1] UniqueIdentifier, [Col2] DateTime2(3), [Col3] BigInt, [Col4] BigInt, [Col5] Float, [Col6] NVarChar(256) COLLATE SQL_Latin1_General_CP1_CI_AS, [Col7] DateTime2(3))
2008-10-17 18:58:03.38 spid13s inputbuf
2008-10-17 18:58:03.38 spid13s insert bulk [SCHEMA].[TableName] ([Col1] UniqueIdentifier, [Col2] DateTime2(3), [Col3] BigInt, [Col4] BigInt, [Col5] Float, [Col6] NVarChar(256) COLLATE SQL_Latin1_General_CP1_CI_AS, [Col7] DateTime2(3))
2008-10-17 18:58:03.38 spid13s process id=process44d2bc8 taskpriority=0 logused=0 waitresource=OBJECT: 5:1749581271:0 waittime=2552 ownerId=78323 transactionname=SetCnstNotTrusted lasttranstarted=2008-10-17T18:58:00.827 XDES=0x81bad970 lockMode=Sch-M schedulerid=3 kpid=4012 status=suspended spid=52 sbid=0 ecid=0 priority=0 trancount=1 lastbatchstarted=2008-10-17T18:57:56.267 lastbatchcompleted=2008-10-17T18:57:56.267 clientapp=TestDataSource hostname=WIN-92BWPBPPZ6R hostpid=844 loginname=WIN-92BWPBPPZ6R\Administrator isolationlevel=read committed (2) xactid=68600 currentdb=5 lockTimeout=4294967295 clientoption1=671088672 clientoption2=128056
2008-10-17 18:58:03.38 spid13s executionStack
2008-10-17 18:58:03.38 spid13s frame procname=adhoc line=1 sqlhandle=0x0200000061c9a220c564361e00f44b52a3d489c34a4ace28
2008-10-17 18:58:03.38 spid13s insert bulk [SCHEMA].[TableName] ([Col1] UniqueIdentifier, [Col2] DateTime2(3), [Col3] BigInt, [Col4] BigInt, [Col5] Float, [Col6] NVarChar(256) COLLATE SQL_Latin1_General_CP1_CI_AS, [Col7] DateTime2(3))
2008-10-17 18:58:03.38 spid13s inputbuf
2008-10-17 18:58:03.38 spid13s insert bulk [SCHEMA].[TableName] ([Col1] UniqueIdentifier, [Col2] DateTime2(3), [Col3] BigInt, [Col4] BigInt, [Col5] Float, [Col6] NVarChar(256) COLLATE SQL_Latin1_General_CP1_CI_AS, [Col7] DateTime2(3))
2008-10-17 18:58:03.38 spid13s process id=process44d3288 taskpriority=0 logused=0 waitresource=OBJECT: 5:1749581271:0 waittime=272 ownerId=82789 transactionname=SetCnstNotTrusted lasttranstarted=2008-10-17T18:58:03.103 XDES=0x8d032c60 lockMode=Sch-M schedulerid=3 kpid=3680 status=suspended spid=55 sbid=0 ecid=0 priority=0 trancount=1 lastbatchstarted=2008-10-17T18:57:57.647 lastbatchcompleted=2008-10-17T18:57:57.647 clientapp=TestDataSource hostname=WIN-92BWPBPPZ6R hostpid=844 loginname=WIN-92BWPBPPZ6R\Administrator isolationlevel=read committed (2) xactid=68747 currentdb=5 lockTimeout=4294967295 clientoption1=671088672 clientoption2=128056
2008-10-17 18:58:03.38 spid13s executionStack
2008-10-17 18:58:03.38 spid13s frame procname=adhoc line=1 sqlhandle=0x0200000061c9a220c564361e00f44b52a3d489c34a4ace28
2008-10-17 18:58:03.38 spid13s insert bulk [SCHEMA].[TableName] ([Col1] UniqueIdentifier, [Col2] DateTime2(3), [Col3] BigInt, [Col4] BigInt, [Col5] Float, [Col6] NVarChar(256) COLLATE SQL_Latin1_General_CP1_CI_AS, [Col7] DateTime2(3))
2008-10-17 18:58:03.38 spid13s inputbuf
2008-10-17 18:58:03.38 spid13s insert bulk [SCHEMA].[TableName] ([Col1] UniqueIdentifier, [Col2] DateTime2(3), [Col3] BigInt, [Col4] BigInt, [Col5] Float, [Col6] NVarChar(256) COLLATE SQL_Latin1_General_CP1_CI_AS, [Col7] DateTime2(3))
2008-10-17 18:58:03.38 spid13s process id=process44b8e08 taskpriority=0 logused=0 waitresource=OBJECT: 5:1749581271:0 waittime=2682 ownerId=77894 transactionname=SetCnstNotTrusted lasttranstarted=2008-10-17T18:58:00.700 XDES=0x81001740 lockMode=Sch-M schedulerid=2 kpid=3856 status=suspended spid=53 sbid=0 ecid=0 priority=0 trancount=1 lastbatchstarted=2008-10-17T18:57:56.650 lastbatchcompleted=2008-10-17T18:57:56.650 clientapp=TestDataSource hostname=WIN-92BWPBPPZ6R hostpid=844 loginname=WIN-92BWPBPPZ6R\Administrator isolationlevel=read committed (2) xactid=68630 currentdb=5 lockTimeout=4294967295 clientoption1=671088672 clientoption2=128056
2008-10-17 18:58:03.38 spid13s executionStack
2008-10-17 18:58:03.38 spid13s frame procname=adhoc line=1 sqlhandle=0x0200000061c9a220c564361e00f44b52a3d489c34a4ace28
2008-10-17 18:58:03.38 spid13s insert bulk [SCHEMA].[TableName] ([Col1] UniqueIdentifier, [Col2] DateTime2(3), [Col3] BigInt, [Col4] BigInt, [Col5] Float, [Col6] NVarChar(256) COLLATE SQL_Latin1_General_CP1_CI_AS, [Col7] DateTime2(3))
2008-10-17 18:58:03.38 spid13s inputbuf
2008-10-17 18:58:03.38 spid13s insert bulk [SCHEMA].[TableName] ([Col1] UniqueIdentifier, [Col2] DateTime2(3), [Col3] BigInt, [Col4] BigInt, [Col5] Float, [Col6] NVarChar(256) COLLATE SQL_Latin1_General_CP1_CI_AS, [Col7] DateTime2(3))
2008-10-17 18:58:03.38 spid13s resource-list
2008-10-17 18:58:03.38 spid13s objectlock lockPartition=0 objid=1749581271 subresource=FULL dbid=5 objectname=Database.SCHEMA.TableName id=lock8722e100 mode=IX associatedObjectId=1749581271
2008-10-17 18:58:03.38 spid13s owner-list
2008-10-17 18:58:03.38 spid13s owner id=process44d3288 mode=IX
2008-10-17 18:58:03.38 spid13s owner id=process44d2bc8 mode=IX
2008-10-17 18:58:03.38 spid13s waiter-list
2008-10-17 18:58:03.38 spid13s waiter id=process44ed708 mode=Sch-M requestType=wait
2008-10-17 18:58:03.38 spid13s objectlock lockPartition=0 objid=1749581271 subresource=FULL dbid=5 objectname=Database.SCHEMA.TableName id=lock8722e100 mode=IX associatedObjectId=1749581271
2008-10-17 18:58:03.38 spid13s owner-list
2008-10-17 18:58:03.38 spid13s owner id=process44ed708 mode=IX
2008-10-17 18:58:03.38 spid13s waiter-list
2008-10-17 18:58:03.38 spid13s waiter id=process44b9048 mode=Sch-M requestType=wait
2008-10-17 18:58:03.38 spid13s objectlock lockPartition=0 objid=1749581271 subresource=FULL dbid=5 objectname=Database.SCHEMA.TableName id=lock8722e100 mode=IX associatedObjectId=1749581271
2008-10-17 18:58:03.38 spid13s owner-list
2008-10-17 18:58:03.38 spid13s owner id=process44ed708 mode=IX
2008-10-17 18:58:03.38 spid13s waiter-list
2008-10-17 18:58:03.38 spid13s waiter id=process44d2bc8 mode=Sch-M requestType=wait
2008-10-17 18:58:03.38 spid13s objectlock lockPartition=0 objid=1749581271 subresource=FULL dbid=5 objectname=Database.SCHEMA.TableName id=lock8722e100 mode=IX associatedObjectId=1749581271
2008-10-17 18:58:03.38 spid13s owner-list
2008-10-17 18:58:03.38 spid13s owner id=process44ed708 mode=IX
2008-10-17 18:58:03.38 spid13s waiter-list
2008-10-17 18:58:03.38 spid13s waiter id=process44d3288 mode=Sch-M requestType=wait
2008-10-17 18:58:03.38 spid13s objectlock lockPartition=0 objid=1749581271 subresource=FULL dbid=5 objectname=Database.SCHEMA.TableName id=lock8722e100 mode=IX associatedObjectId=1749581271
2008-10-17 18:58:03.38 spid13s owner-list
2008-10-17 18:58:03.38 spid13s owner id=process44ed708 mode=IX
2008-10-17 18:58:03.38 spid13s waiter-list
2008-10-17 18:58:03.38 spid13s waiter id=process44b8e08 mode=Sch-M requestType=wait
2008-10-17 18:58:13.74 spid51 Attempting to cycle error log. This is an informational message only; no user action is required.
P.S. : Please don´t be astonished at the database/schema/table/column names - I had to anonymize the log...
Best regards,
Juergen
October 23, 2008 at 3:15 am
Can you do a test changing the isolation level ?
I would change it to read uncommitted , in your case is read committed.
Kr,
R
October 23, 2008 at 3:36 am
Hello,
Thanks for your reply.
I am trying to do so, but I have the problem that within C# IMHO there is no obvious way to change the transaction isolation level of the inner transaction of a SqlBulkCopy object.
I need to choose the option 'UseInternalTransaction' because I have VERY large bulks to insert ( could be considered almost a continous flow of data ) and I cannot span a giant transaction containing millions of recordsets over the whole bulk.
Maybe there is an option to change the transaction isolation level of SqlBulkCopy internal transactions - but I do not know how to do so.
Best regards,
Juergen
October 27, 2008 at 1:26 am
r.dragoi (10/23/2008)
Can you do a test changing the isolation level ?I would change it to read uncommitted , in your case is read committed.
Isolation levels only apply to selects. There's no way to do a data modification without taking locks.
Are there any indexes on the table? Any triggers? Can you post the code C# that you're using?
The wait resources are schema modification locks (Sch-M) and those should only be taken when something in the table's definition is changing.
p.s. traceflag 3605 is not required. 1204 and 1205 or 1222 will do the job just fine.
Gail Shaw
Microsoft Certified Master: SQL Server, MVP, M.Sc (Comp Sci)
SQL In The Wild: Discussions on DB performance with occasional diversions into recoverability
October 27, 2008 at 3:14 am
Isolation levels only apply to selects. There's no way to do a data modification without taking locks.
Are there any indexes on the table? Any triggers? Can you post the code C# that you're using?
The wait resources are schema modification locks (Sch-M) and those should only be taken when something in the table's definition is changing.
Hello Gail,
There are no triggers on this table, but the first 2 columns are a clustered index.
The C# code is quite simple :
SqlBulkCopy bcp = new SqlBulkCopy(_cnStr, SqlBulkCopyOptions.UseInternalTransaction);
bcp.DestinationTableName = "[SCHEMA].[TableName]";
bcp.SqlRowsCopied += _CB_RowsCopied; //callback for progress info
bcp.NotifyAfter =_notifyStep;
bcp.BulkCopyTimeout = Int32.MaxValue;
bcp.BatchSize = _batchSize;
//perform writing :
bcp.WriteToServer(_dataReader);
bcp.Close();
That´s all...
Meanwhile I experimented with the table option 'table lock on bulk load ' - it seems as if this would prevent the deadlocks. I am still testing - but I am wondering if I serialize bulk loads by using this option - or does this mean that multiple bulk loads can concurrently write to a table with the lock type 'BU' ?
Thanks for your help :),
Juergen
October 27, 2008 at 5:34 am
GilaMonster (10/27/2008)
r.dragoi (10/23/2008)
p.s. traceflag 3605 is not required. 1204 and 1205 or 1222 will do the job just fine.
Trace Flag 3605 with -1 will write the output of the other flags being enabled to the SQL Server Error Log for every SPID on the server. I find that this is the easiest method for people to get deadlock graph information, which is why I used those flags together.
Jonathan Kehayias | Principal Consultant | MCM: SQL Server 2008
My Blog | Twitter | MVP Profile
Training | Consulting | Become a SQLskills Insider
Troubleshooting SQL Server: A Guide for Accidental DBAs[/url]
October 27, 2008 at 5:46 am
Jonathan Kehayias (10/27/2008)
Trace Flag 3605 with -1 will write the output of the other flags being enabled to the SQL Server Error Log for every SPID on the server. I find that this is the easiest method for people to get deadlock graph information, which is why I used those flags together.
1204 or 1222 enabled globally will do that alone. There's no need to use 3605 as well.
Gail Shaw
Microsoft Certified Master: SQL Server, MVP, M.Sc (Comp Sci)
SQL In The Wild: Discussions on DB performance with occasional diversions into recoverability
October 27, 2008 at 7:38 am
Thanks Gail,
You are correct, and I learned something I didn't previously know. 1204 and 1222 are the pertinent Trace Flags for the analysis of the deadlocking, and they both log directly to the ErrorLog as you said. 1205 does require the 3605 flag which is the deadlock monitor output, which isn't necessary for troubleshooting a deadlocking scenario. I'll have to go back and look at why I would have been using that flag, and I will definately update the references that I provide to people in the future.
Thanks again for correcting that.
Jonathan Kehayias | Principal Consultant | MCM: SQL Server 2008
My Blog | Twitter | MVP Profile
Training | Consulting | Become a SQLskills Insider
Troubleshooting SQL Server: A Guide for Accidental DBAs[/url]
October 27, 2008 at 8:01 am
Jonathan Kehayias (10/27/2008)
I'll have to go back and look at why I would have been using that flag, and I will definately update the references that I provide to people in the future.
There's a kb article (from the early SQL 2000 days) that says that 3605 is necessary. I need to find it again and then go and log a bug on it.
Gail Shaw
Microsoft Certified Master: SQL Server, MVP, M.Sc (Comp Sci)
SQL In The Wild: Discussions on DB performance with occasional diversions into recoverability
Viewing 11 posts - 1 through 10 (of 10 total)
You must be logged in to reply to this topic. Login to reply