Πώς συλλέγουμε deadlocked queries μέσω Extended Event και πως διαβάζουμε τα δεδομένα του

Σχετικά με
τελευταίες δημοσιεύσεις

Το ταξίδι άρχισε το 2008 όπου ξεκίνησα να εργάζομαι επίσημα στον τομέα της τεχνολογίας πληροφορικής (IT). Ξεκινώντας το πρώτο εξάμηνο της σχολής κατάλαβα μια ιδιαίτερη έλξη προς τις βάσεις δεδομένων και τους αυτοματισμούς.Έχω ασχοληθεί με βάσεις δεδομένων όπως Microsoft SQL Server / Oracle Database, ανάλυση δεδομένων και αυτοματισμούς με τη χρήση γραμμής εντολών (CLI), Visual Basic for Applications και Python. Μέσα από τα χρόνια εμπειρίας εξέλιξα αυτές τις δυνατότητες ώστε να μπορώ να κάνω τη ζωή μου πιο εύκολη. Για μένα ο σκοπός του κάθε IT guy αλλά και κάθε υπαλλήλου γραφείου είναι το να έχει τις γνώσεις ώστε μέσω εργαλείων να μπορεί να δουλεύει λίγο αλλά να παράγει πολύ. Μέσα από αυτό τον ιστότοπο του DataPlatform.gr προσπαθώ να προσφέρω γνώσεις και να προτείνω λύσεις σε καθημερινά προβλήματα.

Πιστοποιήσεις:

certs

Τελευταίες δημοσιεύσεις από Stratos Matzouranis (Προβολή όλων)

Πώς μπορούμε να συνδέσουμε Oracle Database με SQL Server με χρήση Oracle Gateway σε Windows - 5 Απρίλιος 2024
Πώς μπορούμε να λαμβάνουμε email κάθε φορά που ξεπερνάει ένα όριο η μνήμη PGA σε βάση δεδομένων της Oracle - 1 Μάρτιος 2024
Πώς κάνουμε μαζικά detach / attach βάσεις δεδομένων στον SQL Server - 2 Φεβρουάριος 2024

Σε παλαιότερο άρθρο είχαμε δει πως δημιουργούμε Extended Event για να δούμε τα queries με μεγάλη διάρκεια. Σε αυτό το άρθρο θα φτιάξουμε Extended Event που καταγράφει τα deadlocks.

Το μόνο που χρειάζεται να κάνουμε είναι να το δημιουργήσουμε με ένα T-SQL command. Αφού δημιουργηθεί θα καταγράφει στο path που του έχουμε δηλώσει σε ένα αρχείο XML όσα queries είχανε διάρκεια πάνω από 1 δευτερόλεπτο.

Για την δημιουργία του Extended Event

Δεν πρέπει να ξεχάσουμε να αλλάξουμε το path σε αυτό που θα θέλουμε να αποθηκεύονται τα δεδομένα.

Έπειτα το εκτελούμε σε ένα απλό query window.

CREATE EVENT SESSION [deadLock] ON SERVER 
ADD EVENT sqlserver.xml_deadlock_report(
ACTION(package0.callstack,package0.collect_cpu_cycle_time,package0.collect_current_thread_id,package0.collect_system_time,package0.event_sequence,package0.last_error,package0.process_id,sqlos.cpu_id,sqlos.scheduler_id,sqlserver.client_app_name,sqlserver.client_connection_id,sqlserver.client_hostname,sqlserver.client_pid,sqlserver.context_info,sqlserver.database_id,sqlserver.database_name,sqlserver.is_system,sqlserver.query_plan_hash,sqlserver.server_instance_name,sqlserver.server_principal_name,sqlserver.server_principal_sid,sqlserver.session_id,sqlserver.session_nt_username,sqlserver.session_server_principal_name,sqlserver.sql_text,sqlserver.transaction_id,sqlserver.tsql_frame,sqlserver.username)) 
ADD TARGET package0.event_file(SET filename=N'D:\xevents\deadlock.xel',max_file_size=(5))
WITH (MAX_MEMORY=4096 KB,EVENT_RETENTION_MODE=ALLOW_SINGLE_EVENT_LOSS,MAX_DISPATCH_LATENCY=30 SECONDS,MAX_EVENT_SIZE=0 KB,MEMORY_PARTITION_MODE=NONE,TRACK_CAUSALITY=OFF,STARTUP_STATE=ON)
GO

alter event session deadLock on server state=start;
go

Πως διαβάζουμε τα αποτελέσματα

Στο path που είχαμε ορίσει κατά την δημιουργία του XEvent δημιουργήθηκε ένα .xel και ένα .xem αρχείο. Μέσω του dynamic view sys.fn_xe_file_target_read_file με παραμέτρους αυτά τα αρχεία έχουμε ως αποτέλεσμα όλο το XML αρχείο με την πληροφορία.

Όμως επειδή δεν είναι πρακτικό να διαβάζεις με το μάτι ένα XML πρέπει κάπως να φιλτραριστεί το αρχείο σε μια πιο ευανάγνωστη μορφή.

Οπότε έκατσα και έφτιαξα ένα query που κάνει αυτή τη δουλειά

Για αρχή μέσω του ονόματος που φτιάξαμε το Xevent βρίσκει το path που βρίσκεται δυναμικά και το ορίζει σαν παράμετρο στο query.

Έπειτα ορίζουμε το XML σαν ένα Common Table Expression. Κάνοντας το SELECT μπορούμε να φέρουμε την τιμή από την κάθε ιδιότητα που χρειαζόμαστε.

Στο where statement μπορούμε να φιλτράρουμε συγκεκριμένες βάσεις, την διάρκεια και το χρονικό διάστημα που εκτελέστηκε.

Σε αυτό το κομμάτι θέλει προσοχή, καθώς το default xml timestamp είναι σε UTC timezone οπότε για να βάζουμε την πραγματική ώρα που έχει ο server προσθέτουμε την διαφορά ώρας που έχει ο server με το UTC timezone (DATEADD(HOUR,DATEDIFF(hour, SYSUTCDATETIME(),SYSDATETIME() )).

declare

@xel as varchar(max),
@xem as varchar(max) 

set @xel=(select 
--n.name as XeventName,
SUBSTRING(cast(f.value as varchar(max)),1,len(cast(f.value as varchar(max)))-4)+'*.xel' as xel
--,SUBSTRING(cast(f.value as varchar(max)),1,len(cast(f.value as varchar(max)))-4)+'*.xem' as xem
from sys.server_event_session_fields f
inner join sys.server_event_sessions n on f.event_session_id = n.event_session_id
WHERE f.NAME = 'filename' 
and n.name like '%deadLock%') --Set xevent Name


set @xem=(select 
--n.name as XeventName,
--SUBSTRING(cast(f.value as varchar(max)),1,len(cast(f.value as varchar(max)))-4)+'*.xel' as xel
SUBSTRING(cast(f.value as varchar(max)),1,len(cast(f.value as varchar(max)))-4)+'*.xem' as xem
from sys.server_event_session_fields f
inner join sys.server_event_sessions n on f.event_session_id = n.event_session_id
WHERE f.NAME = 'filename' 
and n.name like '%deadLock%')  --Set xevent Name

;WITH XEvents AS
(
select object_name, CAST(event_data AS XML) AS A FROM sys.fn_xe_file_target_read_file(
@xel
,@xem
, NULL, NULL)
)
SELECT 
A.value ('(/event/action[@name=''database_name'']/value)[1]', 'VARCHAR(MAX)') AS DB_Name,
DATEADD(HOUR,DATEDIFF(hour,  SYSUTCDATETIME(),SYSDATETIME() ),A.value ('(/event/@timestamp)[1]', 'DATETIME')) AS [Time],
d.name as DB_Name,

A.value ('(/event/data/value/deadlock/resource-list/objectlock/@objectname)[1]',  'VARCHAR(MAX)') AS locked_objectname,
A.value ('(/event/data[@name=''xml_report'']/value)[1]',  'VARCHAR(MAX)') AS All_Queries,
A.value ('(/event/data/value/deadlock/victim-list/victimProcess/@id)[1]',  'VARCHAR(MAX)') AS VictimProcess1,
A.value ('(/event/data/value/deadlock/victim-list/victimProcess/@id)[2]',  'VARCHAR(MAX)') AS VictimProcess2,
A.value ('(/event/data/value/deadlock/victim-list/victimProcess/@id)[3]',  'VARCHAR(MAX)') AS VictimProcess3,
A.value ('(/event/data/value/deadlock/victim-list/victimProcess/@id)[4]',  'VARCHAR(MAX)') AS VictimProcess4,
A.value ('(/event/data/value/deadlock/victim-list/victimProcess/@id)[5]',  'VARCHAR(MAX)') AS VictimProcess5,
A.value ('(/event/data/value/deadlock/process-list/process/@id)[1]',  'VARCHAR(MAX)') AS ListProcess1,
A.value ('(/event/data/value/deadlock/process-list/process/inputbuf)[1]',  'VARCHAR(MAX)') AS ListQuery1,
A.value ('(/event/data/value/deadlock/process-list/process/@hostname)[1]',  'VARCHAR(MAX)') AS hostname1,
A.value ('(/event/data/value/deadlock/process-list/process/@lockMode)[1]',  'VARCHAR(MAX)') AS lockMode1,
A.value ('(/event/data/value/deadlock/process-list/process/@isolationlevel)[1]',  'VARCHAR(MAX)') AS isolationlevel1,

A.value ('(/event/data/value/deadlock/process-list/process/executionStack/frame/@sqlhandle)[1]',  'VARCHAR(MAX)') AS sql_handle1,
sf1.text as full_text1,
qp1.query_plan as query_plan1,

A.value ('(/event/data/value/deadlock/process-list/process/@id)[2]',  'VARCHAR(MAX)') AS ListProcess2,
A.value ('(/event/data/value/deadlock/process-list/process/inputbuf)[2]',  'VARCHAR(MAX)') AS ListQuery2,
A.value ('(/event/data/value/deadlock/process-list/process/@hostname)[2]',  'VARCHAR(MAX)') AS hostname2,
A.value ('(/event/data/value/deadlock/process-list/process/@isolationlevel)[2]',  'VARCHAR(MAX)') AS isolationlevel12,
A.value ('(/event/data/value/deadlock/process-list/process/@lockMode)[2]',  'VARCHAR(MAX)') AS lockMode2,
A.value ('(/event/data/value/deadlock/process-list/process[2]/executionStack/frame/@sqlhandle)[1]',  'VARCHAR(MAX)') AS sql_handle2,
sf2.text as full_text2,
qp2.query_plan as query_plan2,
A.value ('(/event/data/value/deadlock/process-list/process/@id)[3]',  'VARCHAR(MAX)') AS ListProcess3,
A.value ('(/event/data/value/deadlock/process-list/process/inputbuf)[3]',  'VARCHAR(MAX)') AS ListQuery3,
A.value ('(/event/data/value/deadlock/process-list/process/@lockMode)[3]',  'VARCHAR(MAX)') AS lockMode3,
A.value ('(/event/data/value/deadlock/process-list/process/@hostname)[3]',  'VARCHAR(MAX)') AS hostname3,
A.value ('(/event/data/value/deadlock/process-list/process/@isolationlevel)[3]',  'VARCHAR(MAX)') AS isolationlevel3,
A.value ('(/event/data/value/deadlock/process-list/process[3]/executionStack/frame/@sqlhandle)[1]',  'VARCHAR(MAX)') AS sql_handle3,
sf3.text as full_text3,
qp3.query_plan as query_plan3,
A.value ('(/event/data/value/deadlock/process-list/process/@id)[4]',  'VARCHAR(MAX)') AS ListProcess4,
A.value ('(/event/data/value/deadlock/process-list/process/inputbuf)[4]',  'VARCHAR(MAX)') AS ListQuery4,
A.value ('(/event/data/value/deadlock/process-list/process/@lockMode)[4]',  'VARCHAR(MAX)') AS lockMode4,
A.value ('(/event/data/value/deadlock/process-list/process/@hostname)[4]',  'VARCHAR(MAX)') AS hostname4,
A.value ('(/event/data/value/deadlock/process-list/process/@isolationlevel)[4]',  'VARCHAR(MAX)') AS isolationlevel4,
A.value ('(/event/data/value/deadlock/process-list/process[4]/executionStack/frame/@sqlhandle)[1]',  'VARCHAR(MAX)') AS sql_handle4,
sf4.text as full_text4,
qp4.query_plan as query_plan4,
A.value ('(/event/data/value/deadlock/process-list/process/@id)[5]',  'VARCHAR(MAX)') AS ListProcess5,
A.value ('(/event/data/value/deadlock/process-list/process/inputbuf)[5]',  'VARCHAR(MAX)') AS ListQuery5,
A.value ('(/event/data/value/deadlock/process-list/process/@lockMode)[5]',  'VARCHAR(MAX)') AS lockMode5,
A.value ('(/event/data/value/deadlock/process-list/process/@hostname)[5]',  'VARCHAR(MAX)') AS hostname5,
A.value ('(/event/data/value/deadlock/process-list/process/@isolationlevel)[5]',  'VARCHAR(MAX)') AS isolationlevel5,
A.value ('(/event/data/value/deadlock/process-list/process[5]/executionStack/frame/@sqlhandle)[1]',  'VARCHAR(MAX)') AS sql_handle5,
sf5.text as full_text5,
qp5.query_plan as query_plan5,
A.value ('(/event/data/value/deadlock/process-list/process/@id)[6]',  'VARCHAR(MAX)') AS ListProcess6,
A.value ('(/event/data/value/deadlock/process-list/process/inputbuf)[6]',  'VARCHAR(MAX)') AS ListQuery6,
A.value ('(/event/data/value/deadlock/process-list/process/@lockMode)[6]',  'VARCHAR(MAX)') AS lockMode6,
A.value ('(/event/data/value/deadlock/process-list/process/@hostname)[6]',  'VARCHAR(MAX)') AS hostname6,
A.value ('(/event/data/value/deadlock/process-list/process/@isolationlevel)[6]',  'VARCHAR(MAX)') AS isolationlevel6,
A.value ('(/event/data/value/deadlock/process-list/process[6]/executionStack/frame/@sqlhandle)[1]',  'VARCHAR(MAX)') AS sql_handle6,
sf6.text as full_text6,
qp6.query_plan as query_plan6,
A.value ('(/event/data/value/deadlock/process-list/process/@id)[7]',  'VARCHAR(MAX)') AS ListProcess7,
A.value ('(/event/data/value/deadlock/process-list/process/inputbuf)[7]',  'VARCHAR(MAX)') AS ListQuery7,
A.value ('(/event/data/value/deadlock/process-list/process/@lockMode)[7]',  'VARCHAR(MAX)') AS lockMode7,
A.value ('(/event/data/value/deadlock/process-list/process/@hostname)[7]',  'VARCHAR(MAX)') AS hostname7,
A.value ('(/event/data/value/deadlock/process-list/process/@isolationlevel)[7]',  'VARCHAR(MAX)') AS isolationlevel7,
A.value ('(/event/data/value/deadlock/process-list/process[7]/executionStack/frame/@sqlhandle)[1]',  'VARCHAR(MAX)') AS sql_handle7,
sf7.text as full_text7,
qp7.query_plan as query_plan7,
A   AS xml_report
--,SUBSTRING(CAST(A as varchar(max)), CHARINDEX('<inputbuf>', CAST(A as varchar(max))), CHARINDEX('</inputbuf>',CAST(A as varchar(max))) - CHARINDEX('<inputbuf>', CAST(A as varchar(max))) + Len('</inputbuf>')) as VictimQuery,
--SUBSTRING(CAST(A as varchar(max)), CHARINDEX('<inputbuf>',CAST(A as varchar(max)),CHARINDEX('<inputbuf>',CAST(A as varchar(max)))+10), CHARINDEX('</inputbuf>',CAST(A as varchar(max)),CHARINDEX('</inputbuf>',CAST(A as varchar(max)))+10) - CHARINDEX('<inputbuf>',CAST(A as varchar(max)),CHARINDEX('<inputbuf>',CAST(A as varchar(max)))+1) + Len('</inputbuf>')) as TheOtherQuery
From XEvents x
left join sys.databases d on x.A.value ('(/event/data/value/deadlock/resource-list/objectlock/@dbid)[1]',  'VARCHAR(MAX)') =d.database_id
--left join  sys.dm_exec_query_stats qs1 on  qs1.sql_handle = CONVERT(VARBINARY(MAX), x.A.value ('(/event/data/value/deadlock/process-list/process/executionStack/frame/@sqlhandle)[1]',  'varchar(max)'), 1) 
outer apply sys.dm_exec_sql_text (CONVERT(VARBINARY(MAX), x.A.value ('(/event/data/value/deadlock/process-list/process/executionStack/frame/@sqlhandle)[1]',  'varchar(max)'), 1)) as sf1
outer apply sys.dm_exec_query_plan((select top 1 plan_handle from sys.dm_exec_query_stats where sql_handle = CONVERT(VARBINARY(MAX), x.A.value ('(/event/data/value/deadlock/process-list/process/executionStack/frame/@sqlhandle)[1]',  'varchar(max)'), 1)order by last_execution_time desc))as qp1

outer apply sys.dm_exec_sql_text (CONVERT(VARBINARY(MAX), x.A.value ('(/event/data/value/deadlock/process-list/process[2]/executionStack/frame/@sqlhandle)[1]',  'varchar(max)'), 1)) as sf2
outer apply sys.dm_exec_query_plan((select top 1 plan_handle from sys.dm_exec_query_stats where sql_handle = CONVERT(VARBINARY(MAX), x.A.value ('(/event/data/value/deadlock/process-list/process[2]/executionStack/frame/@sqlhandle)[1]',  'varchar(max)'), 1)order by last_execution_time desc))as qp2

outer apply sys.dm_exec_sql_text (CONVERT(VARBINARY(MAX), x.A.value ('(/event/data/value/deadlock/process-list/process[3]/executionStack/frame/@sqlhandle)[1]',  'varchar(max)'), 1)) as sf3
outer apply sys.dm_exec_query_plan((select top 1 plan_handle from sys.dm_exec_query_stats where sql_handle = CONVERT(VARBINARY(MAX), x.A.value ('(/event/data/value/deadlock/process-list/process[3]/executionStack/frame/@sqlhandle)[1]',  'varchar(max)'), 1)order by last_execution_time desc))as qp3

outer apply sys.dm_exec_sql_text (CONVERT(VARBINARY(MAX), x.A.value ('(/event/data/value/deadlock/process-list/process[4]/executionStack/frame/@sqlhandle)[1]',  'varchar(max)'), 1)) as sf4
outer apply sys.dm_exec_query_plan((select top 1 plan_handle from sys.dm_exec_query_stats where sql_handle = CONVERT(VARBINARY(MAX), x.A.value ('(/event/data/value/deadlock/process-list/process[4]/executionStack/frame/@sqlhandle)[1]',  'varchar(max)'), 1)order by last_execution_time desc))as qp4

outer apply sys.dm_exec_sql_text (CONVERT(VARBINARY(MAX), x.A.value ('(/event/data/value/deadlock/process-list/process[5]/executionStack/frame/@sqlhandle)[1]',  'varchar(max)'), 1)) as sf5
outer apply sys.dm_exec_query_plan((select top 1 plan_handle from sys.dm_exec_query_stats where sql_handle = CONVERT(VARBINARY(MAX), x.A.value ('(/event/data/value/deadlock/process-list/process[5]/executionStack/frame/@sqlhandle)[1]',  'varchar(max)'), 1)order by last_execution_time desc))as qp5

outer apply sys.dm_exec_sql_text (CONVERT(VARBINARY(MAX), x.A.value ('(/event/data/value/deadlock/process-list/process[6]/executionStack/frame/@sqlhandle)[1]',  'varchar(max)'), 1)) as sf6
outer apply sys.dm_exec_query_plan((select top 1 plan_handle from sys.dm_exec_query_stats where sql_handle = CONVERT(VARBINARY(MAX), x.A.value ('(/event/data/value/deadlock/process-list/process[6]/executionStack/frame/@sqlhandle)[1]',  'varchar(max)'), 1)order by last_execution_time desc))as qp6

outer apply sys.dm_exec_sql_text (CONVERT(VARBINARY(MAX), x.A.value ('(/event/data/value/deadlock/process-list/process[7]/executionStack/frame/@sqlhandle)[1]',  'varchar(max)'), 1)) as sf7
outer apply sys.dm_exec_query_plan((select top 1 plan_handle from sys.dm_exec_query_stats where sql_handle = CONVERT(VARBINARY(MAX), x.A.value ('(/event/data/value/deadlock/process-list/process[7]/executionStack/frame/@sqlhandle)[1]',  'varchar(max)'), 1)order by last_execution_time desc))as qp7

where  1=1
and DATEADD(HOUR,DATEDIFF(hour,  SYSUTCDATETIME(),SYSDATETIME() ),A.value ('(/event/@timestamp)[1]', 'DATETIME'))  between '2018-01-26 10:26:00.000' and '2018-12-26 10:28:00.000'
--and d.name ='DB_1'

Το αποτέλεσμα

Το αποτέλεσμα του query μας έφερε για αυτό το χρονικό διάστημα στη βάση που του ζητήσαμε τα queries που ήτανε deadlocked, την λίστα με τα query μαζί με το process id, το locking mode, το isolation level που έτρεχε το καθένα και τέλος ποια ήταν τα Victim δηλαδή ποια έγιναν kill για να συνεχίσουν τα υπόλοιπα.

Πώς συλλέγουμε deadlocked queries μέσω Extended Event και πως διαβάζουμε τα δεδομένα του

Πηγές:

Quickstart: Extended Events in SQL Server

Μοιράσου το

Κουλουράκι	Διάρκεια	Περιγραφή
cookielawinfo-checkbox-advertisement	1 year	The cookie is set by GDPR cookie consent to record the user consent for the cookies in the category "Advertisement".
cookielawinfo-checkbox-analytics	11 months	This cookie is set by GDPR Cookie Consent plugin. The cookie is used to store the user consent for the cookies in the category "Analytics".
cookielawinfo-checkbox-functional	11 months	The cookie is set by GDPR cookie consent to record the user consent for the cookies in the category "Functional".
cookielawinfo-checkbox-necessary	11 months	This cookie is set by GDPR Cookie Consent plugin. The cookies is used to store the user consent for the cookies in the category "Necessary".
cookielawinfo-checkbox-others	11 months	This cookie is set by GDPR Cookie Consent plugin. The cookie is used to store the user consent for the cookies in the category "Other.
cookielawinfo-checkbox-performance	11 months	This cookie is set by GDPR Cookie Consent plugin. The cookie is used to store the user consent for the cookies in the category "Performance".
viewed_cookie_policy	11 months	The cookie is set by the GDPR Cookie Consent plugin and is used to store whether or not user has consented to the use of cookies. It does not store any personal data.

Κουλουράκι	Διάρκεια	Περιγραφή
__gads	1 year 24 days	This cookie is set by Google and stored under the name dounleclick.com. This cookie is used to track how many times users see a particular advert which helps in measuring the success of the campaign and calculate the revenue generated by the campaign. These cookies can only be read from the domain that it is set on so it will not track any data while browsing through another sites.
_ga	2 years	This cookie is installed by Google Analytics. The cookie is used to calculate visitor, session, campaign data and keep track of site usage for the site's analytics report. The cookies store information anonymously and assign a randomly generated number to identify unique visitors.
_gid	1 day	This cookie is installed by Google Analytics. The cookie is used to store information of how visitors use a website and helps in creating an analytics report of how the website is doing. The data collected including the number visitors, the source where they have come from, and the pages visted in an anonymous form.

Κουλουράκι	Διάρκεια	Περιγραφή
IDE	1 year 24 days	Used by Google DoubleClick and stores information about how the user uses the website and any other advertisement before visiting the website. This is used to present users with ads that are relevant to them according to the user profile.
test_cookie	15 minutes	This cookie is set by doubleclick.net. The purpose of the cookie is to determine if the user's browser supports cookies.

Για την δημιουργία του Extended Event

Πως διαβάζουμε τα αποτελέσματα

Το αποτέλεσμα

Πηγές:

Αφήστε μία απάντηση Ακύρωση απάντησης