Logo Questions Linux Laravel Mysql Ubuntu Git Menu
 

Transaction Deadlocks on SQL Server Insert with EF Core

I'm trying to do a large number of individual inserts containing a large amount of data quickly using Entity Framework Core. I'm inserting data into several related tables and occasionally get a SqlException with the following message;

Transaction (Process ID 120) was deadlocked on lock resources with another process and has been chosen as the deadlock victim. Rerun the transaction.

The only reads I am doing is as part of the insert to retrieve the ID's for the newly created records. You can see the Entity Framework Core logs from the inserts taking place. If it makes a difference, I added a single non-clustered index to the UniqueId column.

How can I avoid deadlocks and get better performance as a result?

2018-06-13 17:11:59 DBG Executing DbCommand [Parameters=["@p0='40515' (Nullable = true), @p1='22a98afd-57c9-4821-8027-db9a7d1098d0' (Nullable = true), @p2='2017-12-13T17:11:41.8202539+01:00' (Nullable = true), @p3='2018-06-13T16:11:57.3627370+00:00', @p4='11' (Nullable = true), @p5='0' (Nullable = true), @p6='Teacher Tech' (Nullable = false) (Size = 1000), @p7='3' (Nullable = true), @p8='True' (Nullable = true), @p9='7f72ce12-7c3a-449e-b456-97db816dd7e6' (Nullable = true), @p10='11.0.40515.3' (Size = 50), @p11='False' (Nullable = true), @p12='False' (Nullable = true), @p13='bridge 2015-12-09_15-29 97f149c' (Size = 200), @p14='Global' (Nullable = false) (Size = 100), @p15='False' (Nullable = true), @p16='Development' (Nullable = false) (Size = 50), @p17='2018-06-13T16:11:57.3627551+00:00', @p18='Onyx' (Size = 200), @p19='Bridge_C67HD_AUDIO' (Size = 200), @p20='195.110.84.182' (Size = 50), @p21='72Mbps' (Size = 100), @p22='02:00:00:00:00:00' (Size = 50), @p23='bridgewifi' (Size = 100), @p24='Android' (Nullable = false) (Size = 1000), @p25='4.2.2' (Nullable = false) (Size = 200), @p26='10' (Nullable = true), @p27='EATT-2322' (Size = 200), @p28='751619276', @p29='1073741824', @p30='322122548', @p31='East African Standard Time' (Size = 50), @p32='536870912' (Nullable = true), @p33='10800' (Nullable = true), @p34='2' (Nullable = true), @p35='2018-06-13T16:11:41.8347079+01:00', @p36='2018-06-13T16:11:57.3627630+00:00', @p37='2018-06-13T16:11:57.3627630+00:00', @p38='0', @p39='2018-06-13T17:11:41.8356696+01:00', @p40='b2c398ca-43dd-49da-a89c-b5319756271d', @p41='1' (Nullable = true), @p42='[email protected]' (Size = 100), @p43='T00001' (Size = 20), @p44='2018-06-13T16:11:57.3627658+00:00', @p45='' (DbType = Int32), @p46='Teacher 1' (Size = 100)"], CommandType='Text', CommandTimeout='30']"
""SET NOCOUNT ON;
INSERT INTO [log].[App] ([BuildVersion], [DatabaseId], [Installed], [LastUpdated], [MajorVersion], [MinorVersion], [Name], [RevisionVersion], [TrainingMode], [UniqueId], [Version])
VALUES (@p0, @p1, @p2, @p3, @p4, @p5, @p6, @p7, @p8, @p9, @p10);
SELECT [AppId]
FROM [log].[App]
WHERE @@ROWCOUNT = 1 AND [AppId] = scope_identity();

INSERT INTO [log].[Device] ([AutoTime], [AutoTimeZone], [BuildNumber], [Country], [DeveloperMode], [Environment], [LastUpdated], [Manufacturer], [Model], [NetworkIpAddress], [NetworkLinkSpeed], [NetworkMacAddress], [NetworkSSID], [Platform], [PlatformVersion], [ScreenTimeout], [Serial], [StorageFree], [StorageTotal], [StorageUsed], [TimeZone], [TotalMemory], [UtcOffsetSeconds], [WifiSleepPolicy])
VALUES (@p11, @p12, @p13, @p14, @p15, @p16, @p17, @p18, @p19, @p20, @p21, @p22, @p23, @p24, @p25, @p26, @p27, @p28, @p29, @p30, @p31, @p32, @p33, @p34);
SELECT [DeviceId]
FROM [log].[Device]
WHERE @@ROWCOUNT = 1 AND [DeviceId] = scope_identity();

INSERT INTO [log].[Message] ([CreatedTimestamp], [LastUpdated], [ReceivedTimestamp], [Retries], [SentTimestamp], [UniqueId])
VALUES (@p35, @p36, @p37, @p38, @p39, @p40);
SELECT [MessageId]
FROM [log].[Message]
WHERE @@ROWCOUNT = 1 AND [MessageId] = scope_identity();

INSERT INTO [log].[User] ([BridgeUserId], [Email], [EmployeeId], [LastUpdated], [LogId], [Name])
VALUES (@p41, @p42, @p43, @p44, @p45, @p46);
SELECT [UserId]
FROM [log].[User]
WHERE @@ROWCOUNT = 1 AND [UserId] = scope_identity();"

2018-06-13 17:12:00 DBG Executing DbCommand [Parameters=["@p47='2' (Nullable = true), @p48='3454', @p49='3454', @p50='T90282' (Size = 20), @p51='3454', @p52='900' (Nullable = true), @p53='232' (Nullable = true), @p54='8', @p55='3454' (Nullable = true), @p56='2' (Nullable = true), @p57='3454', @p58='3454', @p59='T90282' (Size = 20), @p60='3454', @p61='900' (Nullable = true), @p62='232' (Nullable = true), @p63='8', @p64='3454' (Nullable = true), @p65='2' (Nullable = true), @p66='3454', @p67='3454', @p68='T90282' (Size = 20), @p69='3454', @p70='900' (Nullable = true), @p71='232' (Nullable = true), @p72='8', @p73='3454' (Nullable = true), @p74='2' (Nullable = true), @p75='3454', @p76='3454', @p77='T90282' (Size = 20), @p78='3454', @p79='900' (Nullable = true), @p80='232' (Nullable = true), @p81='8', @p82='3454' (Nullable = true), @p83='2' (Nullable = true), @p84='3454', @p85='3454', @p86='T90282' (Size = 20), @p87='3454', @p88='900' (Nullable = true), @p89='232' (Nullable = true), @p90='8', @p91='3454' (Nullable = true), @p92='2' (Nullable = true), @p93='3454', @p94='3454', @p95='T90282' (Size = 20), @p96='3454', @p97='900' (Nullable = true), @p98='232' (Nullable = true), @p99='8', @p100='3454' (Nullable = true), @p101='2' (Nullable = true), @p102='3454', @p103='3454', @p104='T90282' (Size = 20), @p105='3454', @p106='900' (Nullable = true), @p107='232' (Nullable = true), @p108='8', @p109='3454' (Nullable = true), @p110='2' (Nullable = true), @p111='3454', @p112='3454', @p113='T90282' (Size = 20), @p114='3454', @p115='900' (Nullable = true), @p116='232' (Nullable = true), @p117='8', @p118='3454' (Nullable = true), @p119='2' (Nullable = true), @p120='3454', @p121='3454', @p122='T90282' (Size = 20), @p123='3454', @p124='900' (Nullable = true), @p125='232' (Nullable = true), @p126='8', @p127='3454' (Nullable = true), @p128='2' (Nullable = true), @p129='3454', @p130='3454', @p131='T90282' (Size = 20), @p132='3454', @p133='900' (Nullable = true), @p134='232' (Nullable = true), @p135='8', @p136='3454' (Nullable = true), @p137='2' (Nullable = true), @p138='3454', @p139='3454', @p140='T90282' (Size = 20), @p141='3454', @p142='900' (Nullable = true), @p143='232' (Nullable = true), @p144='8', @p145='3454' (Nullable = true), @p146='2' (Nullable = true), @p147='3454', @p148='3454', @p149='T90282' (Size = 20), @p150='3454', @p151='900' (Nullable = true), @p152='232' (Nullable = true), @p153='8', @p154='3454' (Nullable = true), @p155='2' (Nullable = true), @p156='3454', @p157='3454', @p158='T90282' (Size = 20), @p159='3454', @p160='900' (Nullable = true), @p161='232' (Nullable = true), @p162='8', @p163='3454' (Nullable = true), @p164='2' (Nullable = true), @p165='3454', @p166='3454', @p167='T90282' (Size = 20), @p168='3454', @p169='900' (Nullable = true), @p170='232' (Nullable = true), @p171='8', @p172='3454' (Nullable = true), @p173='2' (Nullable = true), @p174='3454', @p175='3454', @p176='T90282' (Size = 20), @p177='3454', @p178='900' (Nullable = true), @p179='232' (Nullable = true), @p180='8', @p181='3454' (Nullable = true), @p182='2' (Nullable = true), @p183='3454', @p184='3454', @p185='T90282' (Size = 20), @p186='3454', @p187='900' (Nullable = true), @p188='232' (Nullable = true), @p189='8', @p190='3454' (Nullable = true), @p191='2' (Nullable = true), @p192='3454', @p193='3454', @p194='T90282' (Size = 20), @p195='3454', @p196='900' (Nullable = true), @p197='232' (Nullable = true), @p198='8', @p199='3454' (Nullable = true), @p200='2' (Nullable = true), @p201='3454', @p202='3454', @p203='T90282' (Size = 20), @p204='3454', @p205='900' (Nullable = true), @p206='232' (Nullable = true), @p207='8', @p208='3454' (Nullable = true), @p209='2' (Nullable = true), @p210='3454', @p211='3454', @p212='T90282' (Size = 20), @p213='3454', @p214='900' (Nullable = true), @p215='232' (Nullable = true), @p216='8', @p217='3454' (Nullable = true), @p218='2' (Nullable = true), @p219='3454', @p220='3454', @p221='T90282' (Size = 20), @p222='3454', @p223='900' (Nullable = true), @p224='232' (Nullable = true), @p225='8', @p226='3454' (Nullable = true), @p227='2' (Nullable = true), @p228='3454', @p229='3454', @p230='T90282' (Size = 20), @p231='3454', @p232='900' (Nullable = true), @p233='232' (Nullable = true), @p234='8', @p235='3454' (Nullable = true), @p236='2' (Nullable = true), @p237='3454', @p238='3454', @p239='T90282' (Size = 20), @p240='3454', @p241='900' (Nullable = true), @p242='232' (Nullable = true), @p243='8', @p244='3454' (Nullable = true), @p245='2' (Nullable = true), @p246='3454', @p247='3454', @p248='T90282' (Size = 20), @p249='3454', @p250='900' (Nullable = true), @p251='232' (Nullable = true), @p252='8', @p253='3454' (Nullable = true), @p254='2' (Nullable = true), @p255='3454', @p256='3454', @p257='T90282' (Size = 20), @p258='3454', @p259='900' (Nullable = true), @p260='232' (Nullable = true), @p261='8', @p262='3454' (Nullable = true), @p263='2' (Nullable = true), @p264='3454', @p265='3454', @p266='T90282' (Size = 20), @p267='3454', @p268='900' (Nullable = true), @p269='232' (Nullable = true), @p270='8', @p271='3454' (Nullable = true), @p272='2' (Nullable = true), @p273='3454', @p274='3454', @p275='T90282' (Size = 20), @p276='3454', @p277='900' (Nullable = true), @p278='232' (Nullable = true), @p279='8', @p280='3454' (Nullable = true)"], CommandType='Text', CommandTimeout='30']"
""SET NOCOUNT ON;
DECLARE @inserted0 TABLE ([LogId] int, [_Position] [int]);
MERGE [log].[Log] USING (
VALUES (@p47, @p48, @p49, @p50, @p51, @p52, @p53, @p54, @p55, 0),
(@p56, @p57, @p58, @p59, @p60, @p61, @p62, @p63, @p64, 1),
(@p65, @p66, @p67, @p68, @p69, @p70, @p71, @p72, @p73, 2),
(@p74, @p75, @p76, @p77, @p78, @p79, @p80, @p81, @p82, 3),
(@p83, @p84, @p85, @p86, @p87, @p88, @p89, @p90, @p91, 4),
(@p92, @p93, @p94, @p95, @p96, @p97, @p98, @p99, @p100, 5),
(@p101, @p102, @p103, @p104, @p105, @p106, @p107, @p108, @p109, 6),
(@p110, @p111, @p112, @p113, @p114, @p115, @p116, @p117, @p118, 7),
(@p119, @p120, @p121, @p122, @p123, @p124, @p125, @p126, @p127, 8),
(@p128, @p129, @p130, @p131, @p132, @p133, @p134, @p135, @p136, 9),
(@p137, @p138, @p139, @p140, @p141, @p142, @p143, @p144, @p145, 10),
(@p146, @p147, @p148, @p149, @p150, @p151, @p152, @p153, @p154, 11),
(@p155, @p156, @p157, @p158, @p159, @p160, @p161, @p162, @p163, 12),
(@p164, @p165, @p166, @p167, @p168, @p169, @p170, @p171, @p172, 13),
(@p173, @p174, @p175, @p176, @p177, @p178, @p179, @p180, @p181, 14),
(@p182, @p183, @p184, @p185, @p186, @p187, @p188, @p189, @p190, 15),
(@p191, @p192, @p193, @p194, @p195, @p196, @p197, @p198, @p199, 16),
(@p200, @p201, @p202, @p203, @p204, @p205, @p206, @p207, @p208, 17),
(@p209, @p210, @p211, @p212, @p213, @p214, @p215, @p216, @p217, 18),
(@p218, @p219, @p220, @p221, @p222, @p223, @p224, @p225, @p226, 19),
(@p227, @p228, @p229, @p230, @p231, @p232, @p233, @p234, @p235, 20),
(@p236, @p237, @p238, @p239, @p240, @p241, @p242, @p243, @p244, 21),
(@p245, @p246, @p247, @p248, @p249, @p250, @p251, @p252, @p253, 22),
(@p254, @p255, @p256, @p257, @p258, @p259, @p260, @p261, @p262, 23),
(@p263, @p264, @p265, @p266, @p267, @p268, @p269, @p270, @p271, 24),
(@p272, @p273, @p274, @p275, @p276, @p277, @p278, @p279, @p280, 25)) AS i ([AcademyId], [AppId], [DeviceId], [EmployeeId], [MessageId], [OriginalId], [SequentialId], [TenantId], [UserId], _Position) ON 1=0
WHEN NOT MATCHED THEN
INSERT ([AcademyId], [AppId], [DeviceId], [EmployeeId], [MessageId], [OriginalId], [SequentialId], [TenantId], [UserId])
VALUES (i.[AcademyId], i.[AppId], i.[DeviceId], i.[EmployeeId], i.[MessageId], i.[OriginalId], i.[SequentialId], i.[TenantId], i.[UserId])
OUTPUT INSERTED.[LogId], i._Position
INTO @inserted0;

SELECT [t].[LogId] FROM [log].[Log] t
INNER JOIN @inserted0 i ON ([t].[LogId] = [i].[LogId])
ORDER BY [i].[_Position];"

2018-06-13 17:12:01 DBG Executing DbCommand [Parameters=["@p281='418532', @p282='2018-06-13T16:11:57.3074235+00:00', @p283='0.4', @p284='Good' (Size = 50), @p285='20.3' (Nullable = true), @p286='2018-06-13T16:56:41.8231036+01:00', @p287='418555', @p288='2018-06-13T16:11:57.3405259+00:00', @p289='0.5', @p290='Good' (Size = 50), @p291='22.4' (Nullable = true), @p292='2018-06-13T16:51:41.8233120+01:00', @p293='418554', @p294='2018-06-13T16:11:57.3406167+00:00', @p295='0.6', @p296='Overheat' (Size = 50), @p297='32.4' (Nullable = true), @p298='2018-06-13T16:41:41.8233144+01:00', @p299='418553', @p300='2018-06-13T16:11:57.3422995+00:00', @p301='1', @p302='Good' (Size = 50), @p303='20.3' (Nullable = true), @p304='2018-06-13T05:11:41.8238020+01:00', @p305='418552', @p306='2018-06-13T16:11:57.3423548+00:00', @p307='0.75', @p308='Overheat' (Size = 50), @p309='30.4' (Nullable = true), @p310='2018-06-13T11:11:41.8240006+01:00', @p311='418551', @p312='2018-06-13T16:11:57.3424910+00:00', @p313='0.5', @p314='Over Voltage' (Size = 50), @p315='40.5' (Nullable = true), @p316='2018-06-13T16:11:41.8240025+01:00', @p317='418550', @p318='1' (Nullable = true), @p319='2018-06-13T16:11:41.8242812+01:00', @p320='2018-06-13T15:11:41.8243830+01:00', @p321='1' (Nullable = true), @p322='' (DbType = Int32), @p323='2018-06-13T15:41:41.8244762+01:00', @p324='2018-06-13T14:41:41.8245662+01:00', @p325='10' (Nullable = true), @p326='ss' (Size = 100), @p327='2018-06-13T16:11:57.3489556+00:00', @p328='\\Bridge\\Scripts\\sds' (Nullable = false) (Size = 1000), @p329='0', @p330='False' (Nullable = true), @p331='10' (Nullable = true), @p332='0', @p333='418549', @p334='1' (Nullable = true), @p335='2018-06-13T16:11:41.8253668+01:00', @p336='2018-06-13T15:11:41.8253691+01:00', @p337='2' (Nullable = true), @p338='5' (Nullable = true), @p339='2018-06-13T15:41:41.8253695+01:00', @p340='2018-06-13T14:41:41.8253703+01:00', @p341='10' (Nullable = true), @p342='sfjdsofjdsf[dsfdsfodhsfdsfoidsjfdssfds' (Size = 100), @p343='2018-06-13T16:11:57.3523276+00:00', @p344='\\Bridge\\Scripts\\Path\\To\\Guide1.zip' (Nullable = false) (Size = 1000), @p345='1', @p346='False' (Nullable = true), @p347='5' (Nullable = true), @p348='0', @p349='418545', @p350='2018-06-13T16:11:57.3689908+00:00', @p351='Device On' (Nullable = false) (Size = 200), @p352='2018-06-13T14:11:41.8307572+01:00', @p353='418546', @p354='2018-06-13T16:11:57.3689833+00:00', @p355='User Depart' (Nullable = false) (Size = 200), @p356='2018-06-13T16:11:41.8307560+01:00', @p357='418544', @p358='2018-06-13T16:11:57.3689951+00:00', @p359='Device Off' (Nullable = false) (Size = 200), @p360='2018-06-13T16:11:41.8307584+01:00', @p361='418548', @p362='2018-06-13T16:11:57.3642126+00:00', @p363='User Arrive' (Nullable = false) (Size = 200), @p364='2018-06-13T13:11:41.8301114+01:00', @p365='418547', @p366='2018-06-13T16:11:57.3653672+00:00', @p367='User Login' (Nullable = false) (Size = 200), @p368='2018-06-13T14:11:41.8307524+01:00', @p369='418543', @p370='1' (Nullable = true), @p371='123', @p372='23b70c30d1194fbdb23be4dfcd3eb256' (Size = 100), @p373='2018-06-13T16:11:57.3710762+00:00', @p374='\\Bridge\\Scripts\\Path\\To\\Guide1.zip' (Nullable = false) (Size = 1000), @p375='0', @p376='2018-06-13T13:11:41.8329773+01:00', @p377='418542', @p378='2' (Nullable = true), @p379='456', @p380='fbc76c18df2f421681359d844ac330bc' (Size = 100), @p381='2018-06-13T16:11:57.3721495+00:00', @p382='\\Bridge\\Scripts\\Path\\To\\Guide2.zip' (Nullable = false) (Size = 1000), @p383='1', @p384='2018-06-13T13:11:41.8329809+01:00', @p385='418541', @p386='1' (Nullable = true), @p387='123', @p388='23b70c30d1194fbdb23be4dfcd3eb256' (Size = 100), @p389='2018-06-13T16:11:57.3721795+00:00', @p390='\\Bridge\\Scripts\\Path\\To\\Guide1.zip' (Nullable = false) (Size = 1000), @p391='0', @p392='2018-06-13T13:11:41.8318409+01:00', @p393='418540', @p394='1', @p395='2018-06-13T00:00:00' (DbType = Date), @p396='100', @p397='2018-06-13T16:11:57.3738415+00:00', @p398='2018-06-13T17:11:41.8324776+01:00' (Nullable = true), @p399='418539', @p400='127374182', @p401='2018-06-13T16:11:57.3777203+00:00', @p402='2018-06-13T14:11:41.8334423+01:00', @p403='536870912' (Nullable = true), @p404='409496730', @p405='418538', @p406='117374182', @p407='2018-06-13T16:11:57.3787673+00:00', @p408='2018-06-13T15:11:41.8338427+01:00', @p409='536870912' (Nullable = true), @p410='419496730', @p411='418537', @p412='107374182', @p413='2018-06-13T16:11:57.3787925+00:00', @p414='2018-06-13T16:11:41.8338478+01:00', @p415='536870912' (Nullable = true), @p416='429496730', @p417='418556', @p418='0.1' (Nullable = true), @p419='1', @p420='-0.1', @p421='2018-06-13T16:11:57.3910273+00:00', @p422='2018-06-13T17:11:41.8424721+01:00', @p423='418536', @p424='0' (Nullable = true), @p425='0.231242343', @p426='32.34234323', @p427='2018-06-13T16:11:57.3807241+00:00', @p428='2018-06-13T16:11:41.8367110+01:00', @p429='418535', @p430='0' (Nullable = true), @p431='0.231242303', @p432='32.34234023', @p433='2018-06-13T16:11:57.3811927+00:00', @p434='2018-06-13T16:41:41.8368740+01:00', @p435='418534', @p436='0.1' (Nullable = true), @p437='1', @p438='-0.1', @p439='2018-06-13T16:11:57.3903925+00:00', @p440='2018-06-13T17:11:41.8376319+01:00', @p441='418533', @p442='0.1' (Nullable = true), @p443='1', @p444='-0.1', @p445='2018-06-13T16:11:57.3910123+00:00', @p446='2018-06-13T17:11:41.8424571+01:00', @p447='418557', @p448='0.1' (Nullable = true), @p449='1', @p450='-0.1', @p451='2018-06-13T16:11:57.3910332+00:00', @p452='2018-06-13T17:11:41.8424784+01:00'"], CommandType='Text', CommandTimeout='30']"
""SET NOCOUNT ON;
INSERT INTO [log].[BatteryLevel] ([LogId], [LastUpdated], [Level], [Status], [Temperature], [Timestamp])
VALUES (@p281, @p282, @p283, @p284, @p285, @p286),
(@p287, @p288, @p289, @p290, @p291, @p292),
(@p293, @p294, @p295, @p296, @p297, @p298),
(@p299, @p300, @p301, @p302, @p303, @p304),
(@p305, @p306, @p307, @p308, @p309, @p310),
(@p311, @p312, @p313, @p314, @p315, @p316);
INSERT INTO [log].[CompletedGuide] ([LogId], [ActivityId], [ActualEnd], [ActualStart], [ClassroomId], [CompletedPages], [ExpectedEnd], [ExpectedStart], [GuideId], [Hash], [LastUpdated], [Path], [PercentageCompleted], [RenderedSuccessfully], [TotalPages], [Type])
VALUES (@p317, @p318, @p319, @p320, @p321, @p322, @p323, @p324, @p325, @p326, @p327, @p328, @p329, @p330, @p331, @p332),
(@p333, @p334, @p335, @p336, @p337, @p338, @p339, @p340, @p341, @p342, @p343, @p344, @p345, @p346, @p347, @p348);
INSERT INTO [log].[Event] ([LogId], [LastUpdated], [Name], [Timestamp])
VALUES (@p349, @p350, @p351, @p352),
(@p353, @p354, @p355, @p356),
(@p357, @p358, @p359, @p360),
(@p361, @p362, @p363, @p364),
(@p365, @p366, @p367, @p368);
INSERT INTO [log].[Guide] ([LogId], [ActivityId], [GuideId], [Hash], [LastUpdated], [Path], [Status], [Timestamp])
VALUES (@p369, @p370, @p371, @p372, @p373, @p374, @p375, @p376),
(@p377, @p378, @p379, @p380, @p381, @p382, @p383, @p384),
(@p385, @p386, @p387, @p388, @p389, @p390, @p391, @p392);
INSERT INTO [log].[GuideCount] ([LogId], [Actual], [Date], [Expected], [LastUpdated], [Timestamp])
VALUES (@p393, @p394, @p395, @p396, @p397, @p398);
INSERT INTO [log].[MemoryLevel] ([LogId], [Free], [LastUpdated], [Timestamp], [Total], [Used])
VALUES (@p399, @p400, @p401, @p402, @p403, @p404),
(@p405, @p406, @p407, @p408, @p409, @p410),
(@p411, @p412, @p413, @p414, @p415, @p416);
INSERT INTO [log].[Position] ([LogId], [Accuracy], [CoordinatesLatitude], [CoordinatesLongitude], [LastUpdated], [Timestamp])
VALUES (@p417, @p418, @p419, @p420, @p421, @p422),
(@p423, @p424, @p425, @p426, @p427, @p428),
(@p429, @p430, @p431, @p432, @p433, @p434),
(@p435, @p436, @p437, @p438, @p439, @p440),
(@p441, @p442, @p443, @p444, @p445, @p446),
(@p447, @p448, @p449, @p450, @p451, @p452);"

2018-06-13 17:12:02 DBG Executing DbCommand [Parameters=["@p453='418532', @p454='418532', @p455='2018-06-13T16:11:57.3074235+00:00', @p456='2', @p457='AC' (Size = 100), @p458='418555', @p459='418555', @p460='2018-06-13T16:11:57.3405259+00:00', @p461='3', @p462='AC' (Size = 100), @p463='418554', @p464='418554', @p465='2018-06-13T16:11:57.3406167+00:00', @p466='2', @p467='AC' (Size = 100), @p468='418549', @p469='360', @p470='2018-06-13T16:11:57.3542619+00:00', @p471='1' (Nullable = true), @p472='False' (Nullable = true), @p473='0.2' (Nullable = true), @p474='2018-06-13T15:11:41.8257299+01:00', @p475='418549', @p476='360', @p477='2018-06-13T16:11:57.3555808+00:00', @p478='2' (Nullable = true), @p479='False' (Nullable = true), @p480='0.4' (Nullable = true), @p481='2018-06-13T15:17:41.8258184+01:00', @p482='418549', @p483='360', @p484='2018-06-13T16:11:57.3555831+00:00', @p485='3' (Nullable = true), @p486='False' (Nullable = true), @p487='0.6' (Nullable = true), @p488='2018-06-13T15:23:41.8258203+01:00', @p489='418549', @p490='360', @p491='2018-06-13T16:11:57.3555835+00:00', @p492='4' (Nullable = true), @p493='True' (Nullable = true), @p494='0.8' (Nullable = true), @p495='2018-06-13T15:29:41.8258211+01:00', @p496='418549', @p497='2159', @p498='2018-06-13T16:11:57.3555839+00:00', @p499='5' (Nullable = true), @p500='False' (Nullable = true), @p501='1' (Nullable = true), @p502='2018-06-13T15:35:41.8258219+01:00', @p503='', @p504='' (DbType = DateTimeOffset), @p505='', @p506='418547', @p507='' (DbType = Guid), @p508='123' (Nullable = true), @p509='2018-06-13T16:11:57.3667066+00:00', @p510='UserId' (Nullable = false) (Size = 100), @p511='' (DbType = Int32), @p512='2', @p513='123' (Size = 1000), @p514='', @p515='' (DbType = DateTimeOffset), @p516='', @p517='418547', @p518='' (DbType = Guid), @p519='' (DbType = Int64), @p520='2018-06-13T16:11:57.3687926+00:00', @p521='EmployeeId' (Nullable = false) (Size = 100), @p522='' (DbType = Int32), @p523='0', @p524='T90282' (Size = 1000), @p525='418534', @p526='59' (Nullable = true), @p527='2018-06-13T17:12:41.8371381+01:00' (Nullable = true), @p528='2018-06-13T16:11:57.3894396+00:00', @p529='418534' (Nullable = true), @p530='2018-06-13T17:11:41.8372700+01:00', @p531='0', @p532='418533', @p533='59' (Nullable = true), @p534='2018-06-13T18:12:41.8424476+01:00' (Nullable = true), @p535='2018-06-13T16:11:57.3910111+00:00', @p536='418533' (Nullable = true), @p537='2018-06-13T18:11:41.8424551+01:00', @p538='1', @p539='418556', @p540='59' (Nullable = true), @p541='2018-06-13T19:12:41.8424693+01:00' (Nullable = true), @p542='2018-06-13T16:11:57.3910269+00:00', @p543='418556' (Nullable = true), @p544='2018-06-13T19:11:41.8424709+01:00', @p545='2', @p546='418557', @p547='59' (Nullable = true), @p548='2018-06-13T20:12:41.8424760+01:00' (Nullable = true), @p549='2018-06-13T16:11:57.3910328+00:00', @p550='418557' (Nullable = true), @p551='2018-06-13T20:11:41.8424772+01:00', @p552='0'"], CommandType='Text', CommandTimeout='30']"
""SET NOCOUNT ON;
INSERT INTO [log].[BatteryEvent] ([LogId], [BatteryLevelLogId], [LastUpdated], [Status], [Type])
VALUES (@p453, @p454, @p455, @p456, @p457),
(@p458, @p459, @p460, @p461, @p462),
(@p463, @p464, @p465, @p466, @p467);
DECLARE @inserted3 TABLE ([PageId] int, [_Position] [int]);
MERGE [log].[Page] USING (
VALUES (@p468, @p469, @p470, @p471, @p472, @p473, @p474, 0),
(@p475, @p476, @p477, @p478, @p479, @p480, @p481, 1),
(@p482, @p483, @p484, @p485, @p486, @p487, @p488, 2),
(@p489, @p490, @p491, @p492, @p493, @p494, @p495, 3),
(@p496, @p497, @p498, @p499, @p500, @p501, @p502, 4)) AS i ([CompletedGuideId], [DurationSeconds], [LastUpdated], [PageNumber], [Pause], [PercentageCompleted], [Timestamp], _Position) ON 1=0
WHEN NOT MATCHED THEN
INSERT ([CompletedGuideId], [DurationSeconds], [LastUpdated], [PageNumber], [Pause], [PercentageCompleted], [Timestamp])
VALUES (i.[CompletedGuideId], i.[DurationSeconds], i.[LastUpdated], i.[PageNumber], i.[Pause], i.[PercentageCompleted], i.[Timestamp])
OUTPUT INSERTED.[PageId], i._Position
INTO @inserted3;

SELECT [t].[PageId] FROM [log].[Page] t
INNER JOIN @inserted3 i ON ([t].[PageId] = [i].[PageId])
ORDER BY [i].[_Position];

DECLARE @inserted8 TABLE ([PropertyId] int, [_Position] [int]);
MERGE [log].[Property] USING (
VALUES (@p503, @p504, @p505, @p506, @p507, @p508, @p509, @p510, @p511, @p512, @p513, 0),
(@p514, @p515, @p516, @p517, @p518, @p519, @p520, @p521, @p522, @p523, @p524, 1)) AS i ([BoolValue], [DateTimeValue], [DoubleValue], [EventId], [GuidValue], [IntegerValue], [LastUpdated], [Name], [TimeSpanSecondsValue], [Type], [Value], _Position) ON 1=0
WHEN NOT MATCHED THEN
INSERT ([BoolValue], [DateTimeValue], [DoubleValue], [EventId], [GuidValue], [IntegerValue], [LastUpdated], [Name], [TimeSpanSecondsValue], [Type], [Value])
VALUES (i.[BoolValue], i.[DateTimeValue], i.[DoubleValue], i.[EventId], i.[GuidValue], i.[IntegerValue], i.[LastUpdated], i.[Name], i.[TimeSpanSecondsValue], i.[Type], i.[Value])
OUTPUT INSERTED.[PropertyId], i._Position
INTO @inserted8;

SELECT [t].[PropertyId] FROM [log].[Property] t
INNER JOIN @inserted8 i ON ([t].[PropertyId] = [i].[PropertyId])
ORDER BY [i].[_Position];

INSERT INTO [log].[Synchronization] ([LogId], [DurationSeconds], [End], [LastUpdated], [PositionLogId], [Start], [Type])
VALUES (@p525, @p526, @p527, @p528, @p529, @p530, @p531),
(@p532, @p533, @p534, @p535, @p536, @p537, @p538),
(@p539, @p540, @p541, @p542, @p543, @p544, @p545),
(@p546, @p547, @p548, @p549, @p550, @p551, @p552);"

2018-06-13 17:12:02 DBG Executing DbCommand [Parameters=["@p0='1024' (Nullable = true), @p1='899' (Nullable = true), @p2='2018-06-13T17:11:42.7379462+01:00' (Nullable = true), @p3='1.1' (Size = 10), @p4='2018-06-13T16:11:57.3857573+00:00', @p5='10' (Nullable = true), @p6='Guide' (Nullable = false) (Size = 1000), @p7='dce6d641-a766-457a-b3f1-ece8e0d8948f' (Nullable = true), @p8='1' (Nullable = true), @p9='2018-06-13T17:11:41.8386010+01:00', @p10='0', @p11='204' (Nullable = true), @p12='418534', @p13='512' (Nullable = true), @p14='http://example.com' (Size = 4000), @p15='GET' (Size = 7)"], CommandType='Text', CommandTimeout='30']"
""SET NOCOUNT ON;
INSERT INTO [log].[SynchronizationItem] ([DownloadSize], [DurationMilliseconds], [End], [Http], [LastUpdated], [LatencyMilliseconds], [Name], [RequestId], [RetryCount], [Start], [Status], [StatusCode], [SynchronizationId], [UploadSize], [Url], [Verb])
VALUES (@p0, @p1, @p2, @p3, @p4, @p5, @p6, @p7, @p8, @p9, @p10, @p11, @p12, @p13, @p14, @p15);
SELECT [SynchronizationItemId]
FROM [log].[SynchronizationItem]
WHERE @@ROWCOUNT = 1 AND [SynchronizationItemId] = scope_identity();"

2018-06-13 17:12:02 DBG Executing DbCommand [Parameters=["@p0='386' (Nullable = true), @p1='699' (Nullable = true), @p2='2018-06-13T17:11:43.4390400+01:00' (Nullable = true), @p3='2.0' (Size = 10), @p4='2018-06-13T16:11:57.3878380+00:00', @p5='20' (Nullable = true), @p6='Guide' (Nullable = false) (Size = 1000), @p7='9fe1356a-23b4-41dc-9ef3-001a60f0bf7a' (Nullable = true), @p8='1' (Nullable = true), @p9='2018-06-13T17:11:42.7390436+01:00', @p10='2', @p11='-1' (Nullable = true), @p12='418534', @p13='256' (Nullable = true), @p14='http://example.com' (Size = 4000), @p15='GET' (Size = 7)"], CommandType='Text', CommandTimeout='30']"
""SET NOCOUNT ON;
INSERT INTO [log].[SynchronizationItem] ([DownloadSize], [DurationMilliseconds], [End], [Http], [LastUpdated], [LatencyMilliseconds], [Name], [RequestId], [RetryCount], [Start], [Status], [StatusCode], [SynchronizationId], [UploadSize], [Url], [Verb])
VALUES (@p0, @p1, @p2, @p3, @p4, @p5, @p6, @p7, @p8, @p9, @p10, @p11, @p12, @p13, @p14, @p15);
SELECT [SynchronizationItemId]
FROM [log].[SynchronizationItem]
WHERE @@ROWCOUNT = 1 AND [SynchronizationItemId] = scope_identity();"
like image 704
Muhammad Rehan Saeed Avatar asked Jun 13 '18 16:06

Muhammad Rehan Saeed


People also ask

What to do with deadlock 120 transaction?

Transaction (Process ID 120) was deadlocked on lock resources with another process and has been chosen as the deadlock victim. Rerun the transaction. The only reads I am doing is as part of the insert to retrieve the ID's for the newly created records. You can see the Entity Framework Core logs from the inserts taking place.

Does EF Core send sqlcommands?

At the end of the day, EF Core is just sending SqlCommands here - can you please turn on EF logging and compare what it sends to your own SqlCommand attempt? My "complete repro sample" above does this (it's very close to your original code).

Are inserts and updates the source of deadlock?

So if you're ever baffled about why simple, seemingly non-conflicting INSERTs and UPDATEs are suddenly the apparent source of deadlocks and severe blocking issues, be sure and check if they are involved in any indexed view. Thanks for contributing an answer to Database Administrators Stack Exchange!

What causes a deadlock between two transactions?

It may be possible that when the read operation (SELECT..) from the second transaction is locked by the write operation (INSERT...) from the first transaction, at the same time, the read operation from the first transaction is locked by the write operation from the second transaction. That would cause the deadlock.


1 Answers

I think you should check the Isolation Level of the transactions executed by your application. Usually the default Isolation Level of MSSQL databases is READ COMMITED and transactions executed through EF would respect that configuration.

If that is so, though you haven't shared your code, it seems that these two transactions are executing at almost the same time and that would cause the error you are getting:

2018-06-13 17:12:02 DBG Executing DbCommand [Parameters=["@p0='1024' (Nullable = 
true), @p1='899' (Nullable = true), @p2='2018-06-13T17:11:42.7379462+01:00' (Nullable = true), @p3='1.1' (Size = 10), @p4='2018-06-13T16:11:57.3857573+00:00', @p5='10' (Nullable = true), @p6='Guide' (Nullable = false) (Size = 1000), @p7='dce6d641-a766-457a-b3f1-ece8e0d8948f' (Nullable = true), @p8='1' (Nullable = true), @p9='2018-06-13T17:11:41.8386010+01:00', @p10='0', @p11='204' (Nullable = true), @p12='418534', @p13='512' (Nullable = true), @p14='http://example.com' (Size = 4000), @p15='GET' (Size = 7)"], CommandType='Text', CommandTimeout='30']"
""SET NOCOUNT ON;
INSERT INTO [log].[SynchronizationItem] ([DownloadSize], [DurationMilliseconds], [End], [Http], [LastUpdated], [LatencyMilliseconds], [Name], [RequestId], [RetryCount], [Start], [Status], [StatusCode], [SynchronizationId], [UploadSize], [Url], [Verb])
VALUES (@p0, @p1, @p2, @p3, @p4, @p5, @p6, @p7, @p8, @p9, @p10, @p11, @p12, @p13, @p14, @p15);
SELECT [SynchronizationItemId]
FROM [log].[SynchronizationItem]
WHERE @@ROWCOUNT = 1 AND [SynchronizationItemId] = scope_identity();"

2018-06-13 17:12:02 DBG Executing DbCommand [Parameters=["@p0='386' (Nullable = true), @p1='699' (Nullable = true), @p2='2018-06-13T17:11:43.4390400+01:00' (Nullable = true), @p3='2.0' (Size = 10), @p4='2018-06-13T16:11:57.3878380+00:00', @p5='20' (Nullable = true), @p6='Guide' (Nullable = false) (Size = 1000), @p7='9fe1356a-23b4-41dc-9ef3-001a60f0bf7a' (Nullable = true), @p8='1' (Nullable = true), @p9='2018-06-13T17:11:42.7390436+01:00', @p10='2', @p11='-1' (Nullable = true), @p12='418534', @p13='256' (Nullable = true), @p14='http://example.com' (Size = 4000), @p15='GET' (Size = 7)"], CommandType='Text', CommandTimeout='30']"
""SET NOCOUNT ON;
INSERT INTO [log].[SynchronizationItem] ([DownloadSize], [DurationMilliseconds], [End], [Http], [LastUpdated], [LatencyMilliseconds], [Name], [RequestId], [RetryCount], [Start], [Status], [StatusCode], [SynchronizationId], [UploadSize], [Url], [Verb])
VALUES (@p0, @p1, @p2, @p3, @p4, @p5, @p6, @p7, @p8, @p9, @p10, @p11, @p12, @p13, @p14, @p15);
SELECT [SynchronizationItemId]
FROM [log].[SynchronizationItem]
WHERE @@ROWCOUNT = 1 AND [SynchronizationItemId] = scope_identity();"

It may be possible that when the read operation (SELECT..) from the second transaction is locked by the write operation (INSERT...) from the first transaction, at the same time, the read operation from the first transaction is locked by the write operation from the second transaction. That would cause the deadlock.

like image 199
Emilio Lucas Ceroleni Avatar answered Oct 23 '22 08:10

Emilio Lucas Ceroleni