Les Évènements Étendus avec SQL Server 2008

Une interface unique d'audit des instances et des bases de données pour SQL Server

Nicolas Souquet

L'avantage majeur des Évènements Étendus par rapport à tous les outils d'audit de SQL Server mis à disposition par Microsoft, est qu'ils fournissent une interface unique de diagnostic de ce qui affecte SQL Server, aussi bien de façon interne qu'externe à l'instance, tout en ayant un impact négligeable sur les performances générales de l'instance.

Si de prime abord leur organisation semble absconse, nous allons nous attacher dans cet article à comprendre leur architecture, afin d'en connaître les rouages, avant de fournir quelques exemples d'utilisation. --- Commentez

- Titre : Les Évènements Étendus avec SQL Server 2008

- Auteur : Nicolas Souquet

- Parution : 28 avril 2012

- Mise à jour : 10 juin 2020

- Licence : Les sources présentées sur cette page sont libres de droits et vous pouvez les utiliser à votre convenance. Par contre, la page de présentation constitue une œuvre intellectuelle protégée par les droits d'auteur. Copyright ® 2012 Nicolas Souquet. Aucune reproduction, même partielle, ne peut être faite de ce site et de l'ensemble de son contenu : textes, documents, images, etc. sans l'autorisation expresse de l'auteur. Sinon vous encourez selon la loi jusqu'à trois ans de prison et jusqu'à 300 000 € de dommages et intérêts. Droits de diffusion permanents accordés à Developpez LLC.

Sommaire

- I. Introduction

- II. Architecture logique des XE

- II-A. I.1. Les packages

- II-A-1. I.2. Les évènements

- II-A-2. I.3 Les cibles

- II-A-3. I.4 Les actions

- II-A-4. I.5 Les prédicats

- II-A-5. I.6 Les « maps »

- II-A-6. I.7 Les types

- III. Gestion des sessions de XE avec les vues et fonctions de gestion dynamique

- III-A. II.1 Les DMV de description de l'ensemble des caractéristiques possibles d'une session XE

- III-A-1. II.2 Les DMV de description des sessions XE en cours d'exécution

- III-A-2. II.3 Les vues de catalogue de description des sessions XE, qu'elles soient démarrées ou arrêtées

- III-A-3. II.4 La DMV du distributeur de XE

- III-A-4. II.5 La DMF de dépouillement des fichiers binaires produits par une session XE

- IV. Quelques exemples guidés

- IV-A. III.1 Audit des échecs d'authentification : démarche de création d'une session XE pas à pas

- IV-A-1. III.2 Audit des requêtes grandes consommatrices de CPU et/ou d'E/S disque

- IV-A-2. III.3 Audit du nombre d'appels à des modules T-SQL par base de données utilisateur avec l'anneau de mémoire

- V. Le futur avec SQL Server 2012

- VI. Avantages et inconvénients de l'utilisation des XE

- VII. Conclusion

- Remerciements

I - Introduction

Dans la liste des tâches quotidiennes de l'administrateur de bases de données, il y en a une qui ne disparaîtra probablement jamais: la recherche et la résolution de problèmes, très souvent liés aux performances générales d'une base de données.

En effet, au fur et à mesure qu'une base de données vit et évolue suivant les besoins de l'entreprise, il en va de même pour la charge qu'elle subit (en nombre d'utilisateurs, dans l'expression et le nombre des requêtes, dans la configuration physique du serveur hébergeant la base de données et les optimisations précédentes peuvent se révéler insuffisantes, obsolètes ou nécessitant des modifications (optimisation des procédures de maintenance globale).

Jusqu'à SQL Server 2005, de nombreux outils ont été mis à la disposition des développeurs et des administrateurs de bases de données pour leur permettre d'optimiser les requêtes (SQL Server Profiler, Assistant de paramétrage du moteur de bases de données, plan d'exécution graphique, options de session SET STATISTICS .), et d'auditer les performances internes du moteur de base de données à l'aide des statistiques collectées au fil de l'eau (fonctions et vues de gestion dynamique introduites avec SQL Server 2005, instructions DBCC, notifications d'évènements .).

Leur mise en place et leur utilisation au quotidien (triggers DDL et DML…), parfois en les combinant (Trace SQL Server Profiler en corrélation avec une trace Perfmon), nécessitent une phase de développement, de tests, puis d'analyses qui peuvent se révéler fastidieuses, et qui peuvent également causer une baisse des performances globales de la base de données (même s'il est possible, par exemple, d'utiliser des traces côté serveur de SQL Server Profiler, l'utilisation de ce dernier peut s'avérer gourmande en ressources, notamment lors de l'utilisation de l'interface graphique ou d'un filtrage granuleux de la trace).

Un nouvel outil, en complément des Audits (d'ailleurs supportés par les évènements étendus), eux aussi introduits avec SQL Server 2008, vient compléter cette liste : les ÉvénementsÉtendus, désignés, dans la littérature peu abondante sur le sujet, par ExtendedEvents ou XE.

L'avantage majeur des XE par rapport à tous les outils cités ci-dessus et possiblement omis, est qu'ils fournissent une interface unique de diagnostic de ce qui affecte SQL Server, aussi bien de façon interne qu'externe à l'instance, tout en ayant un impact négligeable sur les performances générales de l'instance.

Si de prime abord leur organisation semble absconse, nous allons nous attacher dans cet article à comprendre leur architecture, afin d'en connaître les rouages, avant de fournir quelques exemples d'utilisation.

II - Architecture logique des XE

Si vous avez déjà interrogé les vues de gestion dynamique qui exposent les XE, vous avez pu vous rendre compte que certaines d'entre elles n'étaient pas simples à comprendre.

Qu'à cela ne tienne, voici une vue d'ensemble et des définitions qui nous permettront par la suite d'utiliser aisément les XE. Nous allons en granularité croissante.

II-A - I.1. Les packages

Un package est un conteneur d'objets d'évènements étendus. Sous SQL Server 2008, il existe quatre packages :

- package0 contient les objets système qui sont nécessaires au bon fonctionnement d'une session d'évènements étendus ;

- sqloscontient tous les objets relatifs au fonctionnement du moteur de bases de données ;

- sqlservercontient tous les objets relatifs à la vie d'une instance (attachement d'une base de données, exécution d'une requête, gestion des fonctionnalités comme FileStream et Service Broker, un split de page…) ;

- SecAuditcontient des objets dont SQL Server se sert pour les audits. Ce package est privé et on ne peut pas l'utiliser directement.

On peut trouver la liste des packages en interrogeant la vue de gestion dynamique sys.dm_xe_packages :

SELECTname AS package_name
, description
, capabilities_desc
FROM sys.dm_xe_packages

Ce qui nous retourne :

package_name

description

capabilities_desc

package0

Default package. Contains all standard types, maps, compare operators, actions and targets

utility

sqlos

Extended events for SQL Operating System

NULL

sqlserver

Extended events for Microsoft SQL Server

NULL

SecAudit

Security Audit Events

private

Chacun de ces packages peut contenir les objets suivants :

- Les évènements, c'est-à-dire ce que l'on cherche à capturer (tout comme lorsqu'on utilise SQL Profiler) ;

- Les cibles, qui consomment les évènements, et permettent de définir le réceptacle de la capture (fichiers, anneau de mémoire, journaux d'évènements…) ;

- Les actions, qui sont des caractéristiques communes aux évènements d'un package qui peuvent être capturées, ou qui permettent d'indiquer ce qui doit être fait lorsque les évènements sont capturés ;

- Les prédicats permettent de filtrer les évènements, tout comme dans SQL Profiler (par exemple on ne cherchera que les requêtes dont le temps d'exécution est supérieur à 5 secondes, dans une base de données particulière), avant que l'évènement soit consommé par la cible ;

- Les « maps » et les types qui sont des types plus ou moins complexes utilisés pour stocker les valeurs dans la structure binaire de capture de l'évènement.

II-A-1 - I.2. Les évènements

Un évènement est une action déclenchée par l'exécution de code (requêtes utilisateur ou système), par exemple :

- une requête commence ou se termine ;

- l'acquisition, de la libération, ou du time-out d'acquisition d'un verrou ;

- un split de page ;

- l'exécution d'un point de contrôle (CHECKPOINT) ;

- la fin de la restauration d'une base de données ;

- la libération de pages par le gestionnaire des tampons.

Pour ceux qui sont familiers de SQL Profiler, on retrouve les évènements fournis par ce dernier, avec en complément ceux fournis exclusivement avec les évènements étendus : le SQL Profiler de SQL Server 2008 expose 180 évènements, tandis que les XE en proposent pas moins de 254 sous SQL Server 2008, et 4 de plus sous SQL Server 2008 R2.

D'ailleurs, tout comme avec SQL Profiler, une session d'évènements étendus peut capturer plusieurs évènements.

On peut récupérer la liste des évènements de tous les packages à l'aide de la requête suivante :

SELECT P.name AS package_name
, P.description
, P.capabilities_desc
, O.name AS event_name
FROM sys.dm_xe_objects AS O
INNER JOIN sys.dm_xe_packages AS P
ON O.package_guid = P.guid
WHERE O.object_type = 'event'

Et voici un extrait du résultat :

package_name

description

event_name

sqlserver

Extended events for Microsoft SQL Server

filestream_file_io_failure

sqlserver

Extended events for Microsoft SQL Server

filestream_file_io_trace

sqlserver

Extended events for Microsoft SQL Server

filestream_file_io_dump

sqlserver

Extended events for Microsoft SQL Server

xml_deadlock_report

sqlserver

Extended events for Microsoft SQL Server

module_start

sqlserver

Extended events for Microsoft SQL Server

module_end

sqlserver

Extended events for Microsoft SQL Server

database_started

sqlserver

Extended events for Microsoft SQL Server

database_stopped

sqlserver

Extended events for Microsoft SQL Server

physical_page_read

sqlserver

Extended events for Microsoft SQL Server

physical_page_write

sqlserver

Extended events for Microsoft SQL Server

lock_deadlock

sqlserver

Extended events for Microsoft SQL Server

sql_statement_starting

sqlserver

Extended events for Microsoft SQL Server

sql_statement_completed

sqlserver

Extended events for Microsoft SQL Server

sp_statement_starting

sqlserver

Extended events for Microsoft SQL Server

sp_statement_completed

sqlserver

Extended events for Microsoft SQL Server

rpc_starting

sqlserver

Extended events for Microsoft SQL Server

rpc_completed

Chaque évènement expose des attributs qui sont valués lorsque celui-ci est capturé (traduit dans la littérature par le terme payload), que l'on peut visualiser à l'aide de la requête suivante :

SELECT P.name AS package_name
, O.name AS event_name
, OC.column_id
, OC.name AS column_name
, OC.column_type
, OC.column_value
, OC.description AS column_description
FROM sys.dm_xe_objects AS O
INNER JOIN sys.dm_xe_object_columns AS OC
ON O.name = OC.object_name
INNER JOIN sys.dm_xe_packages AS P
ON O.package_guid = P.guid
WHERE O.object_type = 'event'

Ce qui donne, pour l'évènement sp_statement_starting :

package_name

event_name

column_id

column_name

column_type

sqlserver

sp_statement_starting

0

ID

readonly

sqlserver

sp_statement_starting

1

UUID

readonly

sqlserver

sp_statement_starting

2

VERSION

readonly

sqlserver

sp_statement_starting

3

CHANNEL

readonly

sqlserver

sp_statement_starting

4

KEYWORD

readonly

sqlserver

sp_statement_starting

0

source_database_id

data

sqlserver

sp_statement_starting

1

object_id

data

sqlserver

sp_statement_starting

2

object_type

data

sqlserver

sp_statement_starting

3

state

data

sqlserver

sp_statement_starting

4

offset

data

sqlserver

sp_statement_starting

5

offset_end

data

sqlserver

sp_statement_starting

6

nest_level

data

Il est très simple de voir que chaque évènement possède ses propres attributs : dans la requête suivante, la colonne event_attributes_count retourne le nombre d'attributs de chaque évènement :

SELECT P.name AS package_name
, O.name AS event_name
, COUNT(*) AS event_attributes_count
FROM sys.dm_xe_objects AS O
INNER JOIN sys.dm_xe_object_columns AS OC
ON O.name = OC.object_name
INNER JOIN sys.dm_xe_packages AS P
ON O.package_guid = P.guid
WHERE O.object_type = 'event'
GROUP BY P.name, O.name
ORDER BY P.name, O.name

II-A-2 - I.3 Les cibles

Les cibles consomment un évènement et permettent d'indiquer quel objet sera leur réceptacle. Les évènements capturés peuvent ainsi être extraits de plusieurs manières :

- depuis un fichier binaire, spécifique aux évènements étendus ;

- directement dans la mémoire en anneau (« ring buffer ») de SQL Server ;

- depuis le journal d'évènements de Windows (Event Tracing for Windows) ;

- en comptant le nombre d'évènements capturés par une session, pour caractériser une charge de travail par exemple ;

- chercher une correspondance entre deux évènements d'une même session.

De la même manière que les évènements, on peut utiliser plusieurs cibles dans une même session.

On peut donc exposer les évènements capturés à la fois :

- dans le journal d'évènements et dans un fichier binaire ;

- mais aussi chercher les correspondances entre évènements et les exposer dans un fichier binaire ;

- …

On peut connaître la liste de toutes les cibles et de leurs caractéristiques par la requête suivante :

SELECT P.name AS package_name
, O.name AS target_name
, OC.column_id
, OC.name AS column_name
, OC.column_type
, OC.capabilities_desc
, OC.column_value
, OC.description AS column_description
FROM sys.dm_xe_objects AS O
INNER JOIN sys.dm_xe_object_columns AS OC
ON O.name = OC.object_name
INNER JOIN sys.dm_xe_packages AS P
ON O.package_guid = P.guid
WHERE O.object_type = 'target'

Voici donc les caractéristiques de la cible asynchronous_file_target :

package_name

target_name

column_id

column_name

column_type

capabilities_desc

column_value

column_description

package0

asynchronous_file_target

0

filename

customizable

mandatory

NULL

Specifies the location and file name of the log

package0

asynchronous_file_target

1

max_file_size

customizable

1024

Maximum file size in MB

package0

asynchronous_file_target

2

max_rollover_files

customizable

5

Maximum number of files to retain

package0

asynchronous_file_target

3

increment

customizable

0

Size in MB to grow the file

package0

asynchronous_file_target

4

metadatafile

customizable

NULL

Specifies location and file name of metadata file

On notera que la colonne capabilities_desc précise si l'attribut de la cible doit être obligatoirement spécifié (valeur mandatory) lors de l'utilisation de la cible dans la spécification d'une session.

De la même façon que pour les évènements, on peut récupérer la liste de toutes les cibles possibles :

SELECT P.name AS package_name
, O.name AS target_name
, O.capabilities_desc AS target_capabilities
, O.description AS target_description
FROM sys.dm_xe_objects AS O
INNER JOIN sys.dm_xe_packages AS P
ON O.package_guid = P.guid
WHERE O.object_type = 'target'
ORDER BY package_name, target_name

package_name

target_name

target_capabilities

target_description

package0

asynchronous_bucketizer

NULL

Asynchronous bucketizing target

package0

asynchronous_file_target

process_whole_buffers

Asynchronous file target

package0

etw_classic_sync_target

singleton synchronous

Event Tracing for Windows (ETW) Synchronous Target

package0

pair_matching

process_whole_buffers

Pairing target

package0

ring_buffer

process_whole_buffers

Asynchronous ring buffer target.

package0

synchronous_bucketizer

synchronous

Synchronous bucketizing target

package0

synchronous_event_counter

synchronous

Synchronous Counter target

SecAudit

asynchronous_security_audit_event_log_target

private

Asynchronous security audit NT event log target

SecAudit

asynchronous_security_audit_file_target

private process_whole_buffers

Asynchronous security audit file target

SecAudit

asynchronous_security_audit_security_log_target

private

Asynchronous security audit NT security log target

SecAudit

synchronous_security_audit_event_log_target

private synchronous

Synchronous security audit NT event log target

SecAudit

synchronous_security_audit_file_target

private synchronous

Synchronous security audit file target

SecAudit

synchronous_security_audit_security_log_target

private synchronous

Synchronous security audit NT security log target

Et l'on s'aperçoit ici que seuls deux packages exposent des cibles : package0 et SecAudit. Étant donné que l'on ne peut pas utiliser le package SecAudit puisqu'il est privé, on peut utiliser toutes les cibles du package0.

II-A-3 - I.4 Les actions

Les actions définissent les caractéristiques d'un évènement. Ces actions peuvent être soit communes à tous les évènements d'un package, soit spécifiques à un évènement particulier. On trouve la liste de ces actions ainsi qu'une brève description avec la requête suivante :

SELECT P.name AS package_name
, O.name AS action_name
, O.capabilities_desc AS action_capabilities
, O.description AS action_description
FROM sys.dm_xe_objects AS O
INNER JOIN sys.dm_xe_packages AS P
ON O.package_guid = P.guid
WHERE O.object_type = 'action'
ORDER BY package_name, action_name

Dont le résultat pour le package SQL Server est :

package_name

action_name

action_description

package0

attach_activity_id

Attach an activity ID to an event

package0

attach_activity_id_xfer

Attach an activity ID transfer to an event

package0

collect_cpu_cycle_time

Collect the current CPU's cycle count

sqlos

cpu_id

Collect current CPU ID

sqlos

node_affinity

Collect current NUMA node affinity

sqlos

scheduler_id

Collect current scheduler ID

sqlos

task_resource_group_id

Collect current task resource group ID

sqlos

task_resource_pool_id

Collect current task resource pool ID

sqlos

task_time

Collect current task execution time

sqlserver

client_app_name

Collect client application name

sqlserver

client_hostname

Collect client hostname

sqlserver

client_pid

Collect client process ID

sqlserver

create_dump_all_threads

Create mini dump including all threads

sqlserver

create_dump_single_thread

Create mini dump for the current thread

sqlserver

database_context

Collect useful infomation related to the current database

sqlserver

database_id

Collect database ID

sqlserver

is_system

Collect whether current session is system

sqlserver

plan_handle

Collect plan handle

sqlserver

session_nt_username

Collect session's NT username

sqlserver

session_resource_group_id

Collect current session resource group ID

sqlserver

session_resource_pool_id

Collect current session resource pool ID

sqlserver

sql_text

Collect SQL text

Le résultat de cette requête montre que l'on peut collecter le CPU sur lequel s'est exécutée la requête, le nom de la machine cliente et de l'application qui a exécuté la requête, la base de données sur laquelle s'est exécutée la requête, le texte de la requête.

Ce sont tout autant de caractéristiques dont on peut se servir pour restreindre ce que l'on souhaite auditer, comme par exemple capturer les requêtes exécutées sur une base de données particulière (sqlserver.database_id), ou par un nom d'utilisateur donné (sqlserver.session_nt_user_name).

On remarquera que le package SecAudit n'apparaît pas dans la liste des packages retournés par cette requête. Ce n'est pas une surprise, puisque ce package est privé et supporte la fonctionnalité d'Audit introduite avec SQL Server 2008.

II-A-4 - I.5 Les prédicats

Les prédicats ont vocation à filtrer de manière plus fine qu'avec SQL Profiler une session d'évènements. Par exemple il est possible de :

- ne pas collecter les évènements en dessous ou au-dessus d'une valeur seuil ;

- restreindre la capture à un certain nombre d'occurrences d'un évènement (package0.counter = <uneValeur>) ;

- ne capturer qu'un échantillon (package0.divides_by_uint64(package0.counter,4)) ;

- limiter la consommation de ressources de certaines actions, comme un dump mémoire ou la capture de la pile d'appel ;

- …

Il existe deux types de prédicats :

- les prédicats « source », c'est-à-dire ceux pour lesquels on peut utiliser la syntaxe de comparaison habituelle, comme on spécifierait un filtre dans la clause WHERE d'une requête, sans se soucier du type de la donnée du prédicat.

C'est ce que l'on a vu précédemment lorsqu'on souhaite filtrer sur une session pour une base de données particulière ou un utilisateur particulier (WHERE sqlserver.database_id = 12) ;

- les prédicats de « comparaison »mettent en œuvre une comparaison qui respecte le type de données de la colonne de l'objet filtré. Donc, si l'on souhaite capturer les évènements d'une session seulement lorsque l'espérance de vie des pages de données en RAM passe en dessous de 5000, on écrira :

ADD EVENT sqlserver.buffer_manager_page_life_expectancy
WHERE (package0.less_than_equal_uint64(package0.count, 5000))

On trouve la liste des prédicats similairement aux évènements :

SELECT P.name AS package_name
, P.capabilities_desc AS package_capabilities
, O.name AS pred_source_name
, O.object_type
FROM sys.dm_xe_objects AS O
INNER JOIN sys.dm_xe_packages AS P
ON O.package_guid = P.guid
WHERE O.object_type = 'pred_source'
OR O.object_type = 'pred_compare'

Dont un extrait du résultat est :

package_name

package_capabilities

pred_source_name

object_type

sqlserver

NULL

database_id

pred_source

sqlserver

NULL

session_id

pred_source

sqlserver

NULL

client_app_name

pred_source

package0

utility

equal_uint64

pred_compare

package0

utility

not_equal_uint64

pred_compare

package0

utility

less_than_uint64

pred_compare

package0

utility

less_than_equal_uint64

pred_compare

II-A-5 - I.6 Les « maps »

Les « maps » sont en fait des tables de correspondance pour les valeurs internes au moteur de base de données, de sorte qu'elles soient intelligibles. Elles sont similaires à une entité d'un modèle de données de base de données relationnelle SQL qui représente les divers états possibles d'une autre entité. Dans le cas présent, elles font correspondre, par exemple, le type d'attente 3 à LCK_M_S (attente d'acquisition de verrou de modification de schéma).

Voyons d'abord comment trouver les « maps » : c'est assez identique à ce que nous avons déjà vu :

SELECT P.name
, O.name AS event_name
, O.object_type
FROM sys.dm_xe_objects AS O
INNER JOIN sys.dm_xe_packages AS P
ON O.package_guid = P.guid
WHERE O.object_type = 'map'

Voici le résultat abrégé :

name

event_name

object_type

sqlserver

lock_resource_type

map

sqlserver

lock_owner_type

map

sqlserver

lock_mode

map

sqlserver

latch_mode

map

sqlserver

latch_class

map

Une autre vue de gestion dynamique expose les valeurs et leur sens : sys.dm_xe_map_values :

SELECT P.name AS package_name
, O.name AS map_name
, MV.map_key
, MV.map_value
FROM sys.dm_xe_objects AS O
INNER JOIN sys.dm_xe_packages AS P
ON O.package_guid = P.guid
INNER JOIN sys.dm_xe_map_values AS MV
ON MV.object_package_guid = O.package_guid
AND MV.name = O.name
WHERE O.object_type = 'map'

Voici un court extrait du résultat :

package_name

map_name

map_key

map_value

sqlos

wait_types

0

UNKNOWN

sqlos

wait_types

1

LCK_M_SCH_S

sqlos

wait_types

2

LCK_M_SCH_M

sqlos

wait_types

3

LCK_M_S

sqlos

wait_types

4

LCK_M_U

sqlos

wait_types

5

LCK_M_X

sqlos

wait_types

6

LCK_M_IS

sqlos

wait_types

7

LCK_M_IU

sqlos

wait_types

8

LCK_M_IX

sqlserver

lock_resource_type

2

DATABASE

sqlserver

lock_resource_type

3

FILE

sqlserver

lock_resource_type

4

UNUSED1

sqlserver

lock_resource_type

5

OBJECT

sqlserver

lock_resource_type

6

PAGE

sqlserver

lock_resource_type

7

KEY

sqlserver

lock_mode

1

SCH_S

sqlserver

lock_mode

2

SCH_M

sqlserver

lock_mode

3

S

sqlserver

lock_mode

4

U

sqlserver

lock_mode

5

X

sqlserver

lock_mode

6

IS

sqlserver

lock_mode

7

IU

sqlserver

lock_mode

8

IX

sqlserver

lock_mode

9

SIU

sqlserver

lock_mode

10

SIX

II-A-6 - I.7 Les types

Les types représentent tous les types de données utilisés par l'ensemble des évènements qu'il est possible de capturer avec les XE. On notera que tout champ exposé par un évènement est typé. Les types prennent tout leur sens lors de la spécification des prédicats.

On en obtient la liste avec la requête suivante :

SELECT P.name AS package_name
, O.name AS type_name
, O.type_size
FROM sys.dm_xe_objects AS O
INNER JOIN sys.dm_xe_packages AS P
ON O.package_guid = P.guid
WHERE O.object_type = 'type'

Dont une partie du résultat est la suivante :

package_name

type_name

type_size

package0

null

0

package0

int8

1

package0

int16

2

package0

int32

4

package0

int64

8

package0

uint8

1

package0

boolean

1

package0

guid

0

package0

binary_data

0

package0

callstack

0

package0

char

1

package0

uint16

2

package0

uint32

4

package0

uint64

8

package0

float32

4

package0

float64

8

package0

cpu_cycle

8

sqlos

sos_context

0

sqlserver

database_context

0

III - Gestion des sessions de XE avec les vues et fonctions de gestion dynamique

Avant de rentrer dans le vif du sujet avec des exemples, voyons comment, à l'aide des vues de gestion dynamique dédiées aux évènements étendus, on peut gérer les sessions.

Comme nous l'avons à travers les sections précédentes, les XE et leurs propriétés sont exposés par les fonctions et vues de gestion dynamique commençant par sys.dm_xe_.

Néanmoins il en existe plusieurs autres, et on peut toutes les classer en quatre catégories :

- les DMV de description de l'ensemble des caractéristiques possibles d'une session XE ;

- les DMV de description des sessions XE en cours d'exécution ;

- les vues de catalogue de description des sessions XE, qu'elles soient démarrées ou arrêtées ;

- la DMV du distributeur de XE ;

- la DMF de dépouillement des fichiers binaires produits par une session XE.

III-A - II.1 Les DMV de description de l'ensemble des caractéristiques possibles d'une session XE

Je vous renvoie vers la documentation de toutes ces vues, qui se trouve ici, puisque nous les avons déjà abordées en détail dans les sections précédentes. La table suivante donne une description rapide de celles-ci ainsi qu' un lien direct vers la documentation en ligne.

dm_xe_view

Rôle

sys.dm_xe_map_values

Décrit les valeurs internes utilisées par SQL Server pour les valeurs utilisées en interne par le moteur de bases de données

sys.dm_xe_object_columns

Retourne toutes les caractéristiques des packages, évènements, cibles, actions, prédicats, maps et types

sys.dm_xe_objects

Retourne tous les packages, évènements, cibles, actions, prédicats, maps et types

sys.dm_xe_packages

Retourne la liste de tous les packages permettant l'utilisation des évènements étendus

III-A-1 - II.2 Les DMV de description des sessions XE en cours d'exécution

Il existe cinq DMV qui permettent de connaître les caractéristiques (évènements, actions et cibles) de toutes les sessions XE en cours d'audit. Leur nom commence par sys.dm_xe_sessions_.

De la même façon, je vous renvoie vers la documentation sur Internet :

dm_xe_view

Rôle

sys.dm_xe_session_event_actions

Retourne la liste des caractéristiques actions des évènements capturés par une session d'évènements étendus en cours d'exécution

sys.dm_xe_session_events

Retourne la liste d'évènements étendus, d'actions et de cibles qu'une session en cours d'exécution utilise

sys.dm_xe_session_object_columns

Retourne la liste des caractéristiques des évènements capturés par une session en cours d'exécution

sys.dm_xe_session_targets

Retourne les caractéristiques des cibles d'une session d'évènements étendus en cours d'exécution

sys.dm_xe_sessions

Retourne les caractéristiques des sessions d'évènements étendus en cours d'exécution

Voici une requête qui retourne toutes les caractéristiques de la session nommée system_health :

SELECT DISTINCT S.name AS session_name
, SEAM.event_name
, A.action_list
FROM sys.dm_xe_sessions AS S
INNER JOIN sys.dm_xe_session_event_actions AS SEAM
ON S.address = SEAM.event_session_address
CROSS APPLY(
SELECT PA.name + '.' + SEA.action_name + ', '
FROM sys.dm_xe_session_event_actions AS SEA
INNER JOIN sys.dm_xe_packages AS PA
ON SEA.action_package_guid = PA.guid
WHERE S.address = SEA.event_session_address
AND SEAM.event_name = SEA.event_name
FOR XML PATH ('')
) AS A(action_list)
WHERE S.name = 'system_health'
ORDER BY SEAM.event_name

En fait, la session nommée system_health est une session système activée par défaut sur SQL Server 2008 et qui collecte les évènements dans un anneau de mémoire (ring buffer en Anglais), en capturant par exemple les caractéristiques des 256 derniers deadlocks, ce qui permet de les retrouver de façon rétrospective.

Voyons comment trouver ses cibles :

SELECT S.name AS session_name
, PT.name + '.' + ST.target_name AS target_name
, CAST(ST.target_data AS xml) AS target_data
FROM sys.dm_xe_session_targets AS ST
INNER JOIN sys.dm_xe_sessions AS S
ON ST.event_session_address = S.address
INNER JOIN sys.dm_xe_packages AS PT
ON ST.target_package_guid = PT.guid

La colonne target_data de la DMV sys.dm_xe_session_targets retourne un document XML dans tous les cas, mais avec un contenu différent en fonction de la cible utilisée par la session concernée.

III-A-2 - II.3 Les vues de catalogue de description des sessions XE, qu'elles soient démarrées ou arrêtées

Il existe là aussi 5 vues qui permettent de gérer les sessions d'évènements étendus, qu'elles soient arrêtées ou démarrées (nous verrons plus tard qu'on l'on peut créer une session sans la démarrer, la démarrer par la suite, l'arrêter et la démarrer de nouveau).

Leurs noms commencent par sys.server_event_session. Je vous renvoie de nouveau vers la documentation disponible sur Internet :

sys,server_event_session_view

Rôle

sys.server_event_sessions

Retourne la liste de toutes les sessions XE enregistrées dans l'instance, qu'elles soient démarrées ou non

sys.server_event_session_actions

Retourne toutes les actions associées aux évènements capturés par toutes les sessions enregistrées dans l'instance

sys.server_event_session_events

Retourne tous les évènements capturés par une session enregistrée dans l'instance, avec éventuellement ses prédicats de filtrage

sys.server_event_session_fields

Retourne les caractéristiques d'une session enregistrée dans l'instance, comme les fichiers de la cible, ou la mémoire maximale configurée lors de la spécification de la session

sys.server_event_session_targets

Retourne la liste des cibles de toutes les sessions enregistrées dans l'instance

La requête suivante retourne la liste de toutes les sessions d'évènements étendus enregistrées dans l'instance SQL Server :

SELECT name AS session_name
, event_retention_mode_desc
, max_dispatch_latency
, max_event_size
, max_memory
, memory_partition_mode_desc
, CASE startup_state
WHEN 1 THEN 'Démarre automatiquement avec l''instance'
ELSE 'Démarrée par action de l''utilisateur'
END AS startup_state
, track_causality
FROM sys.server_event_sessions

Voici comment trouver la liste des évènements et leurs actions :

SELECT S.name AS session_name
, SE.package + '.' + SE.name AS event_name
, REPLACE(REPLACE(SE.predicate, '[', ''), ']', '') AS event_predicate
, A.action_list
FROM sys.server_event_sessions AS S
INNER JOIN sys.server_event_session_events AS SE
ON S.event_session_id = SE.event_session_id
CROSS APPLY(
SELECT package + '.' + name + ', '
FROM sys.server_event_session_actions AS SEA
WHERE SEA.event_session_id = S.event_session_id
AND SEA.event_id = SE.event_id
FOR XML PATH ('')
) AS A(action_list)

C'est assez similaire avec les DMV pour les sessions en cours d'exécution ; néanmoins les jointures ne se font pas sur une adresse, mais sur un identifiant.

Le détail des options de session s'obtient comme suit :

SELECT S.name AS session_name
, SF.name AS session_option_name
, SF.value AS option_value
FROM sys.server_event_session_fields AS SF
INNER JOIN sys.server_event_sessions AS S
ON SF.event_session_id = S.event_session_id

Et voici pour les cibles :

SELECT S.name AS session_name
, ST.package + '.' + ST.name AS target_name
FROM sys.server_event_session_targets AS ST
INNER JOIN sys.server_event_sessions AS S
ON ST.event_session_id = S.event_session_id

III-A-3 - II.4 La DMV du distributeur de XE

La DMV sys.dm_os_dispatcher_pools retourne les caractéristiques du distributeur d'évènements étendus pour les sessions en cours d'exécution.

En effet, les XE ont été conçus pour avoir un impact minimal sur les performances de l'instance auditée. Donc, lorsqu'un même évènement est audité par plusieurs sessions, il n'est en fait capturé qu'une seule fois et distribué à toutes ces sessions, suivant que les filtres de celles-ci vérifient les caractéristiques de l'évènement capturé. C'est un comportement différent de SQL Profiler, où les évènements sont capturés, autant de fois qu'ils se produisent, par toutes les traces en cours d'exécution.

Il n'y a donc qu'un distributeur d'évènements par instance de SQL Server, donc pour en connaître le statut, la requête est très simple :

SELECT *
FROM sys.dm_os_dispatcher_pools

III-A-4 - II.5 La DMF de dépouillement des fichiers binaires produits par une session XE

La fonction sys.fn_xe_file_target_read_file est le seul outil à disposition qui permet de retourner les caractéristiques des évènements qui ont été capturés par une session XE dont la cible est un fichier binaire. Elle s'utilise comme suit :

SELECT CAST(event_data AS xml) AS data
FROM sys.fn_xe_file_target_read_file
(
'D:\dossier\uneSessionXE*.xel' -- fichier de capture des évènements XE
, 'D:\dossier\uneSessionXE*.xem' -- fichier de métadonnées de la session
, NULL
, NULL
)

On notera que cette fonction retourne une liste de documents XML sous la forme d'une chaîne de caractères, ce qui facilite l'extraction des données via les requêtes de type XML de SQL Server, comme nous le verrons dans les exemples.

Le premier paramètre est le chemin du fichier dans lequel on a capturé tous les évènements de la session. On peut utiliser les jokers si l'on ne souhaite pas spécifier le nom du fichier à lire, sachant qu'il peut y en avoir plusieurs par session (un à chaque démarrage de la session).

Le second paramètre est le chemin du fichier de métadonnées qui décrit les caractéristiques de la session. De la même façon, il peut y en avoir plusieurs par session.

On a plusieurs fichiers par session si l'on arrête puis redémarre une session, ou si l'on supprime une session et qu'on la recrée avec le même nom.

On notera que ces deux fichiers sont indissociables : c'est-à-dire que si l'on transfère seulement le fichier de capture des évènements à une autre personne sans le fichier de métadonnées, cette personne sera dans l'impossibilité de le lire.

Les deux précédents paramètres sont obligatoires, mais les deux suivants ne le sont pas. En revanche si l'on spécifie l'un d'entre eux, il faut que l'autre soit également valué :

- Le troisième paramètre est le premier fichier de la série que l'on souhaite lire. On peut le passer à NULL si l'on souhaite tous les lire.

- Le quatrième paramètre est l'offset à partir duquel on souhaite commencer la lecture.

On peut trouver la liste des fichiers et de leurs offsets à l'aide de la requête suivante :

SELECT DISTINCT file_name
, file_offset
FROM sys.fn_xe_file_target_read_file
(
'D:\dossier\uneSessionXE*.xel' -- fichier de capture des évènements XE
, 'D:\dossier\uneSessionXE*.xem' -- fichier de métadonnées de la session
, NULL
, NULL
)

IV - Quelques exemples guidés

Nous entrons enfin dans le vif du sujet : je vais donner quelques exemples de sessions que j'ai utilisés en production pour faire de simples audits à plus ou moins court terme.

J'ai constaté que les sessions XE permettent de rechercher un problème à plus ou moins grande échelle : on peut « ratisser » large pour trouver un problème, puis raffiner par filtrage de la session, en ajoutant plus de détails.

Je n'écris pas de section sur la structure des instructions de création des sessions, parce que ce n'est pas très compliqué, et que les exemples sont beaucoup plus parlants.

IV-A - III.1 Audit des échecs d'authentification : démarche de création d'une session XE pas à pas

Ayant trouvé dans les journaux d'erreurs de SQL Server de nombreuses erreurs comme celle-ci :

Cannot open database « ELSUKET » requested by the login. The login failed .

Le problème, c'est que le nom de login utilisé n'est pas précisé, ni la machine depuis laquelle la tentative a été faite, ni même le nom de la base de données à laquelle l'utilisateur a tenté de se connecter.

Voyons si un évènement permettant de capturer les erreurs existe :

SELECT name, description
FROM sys.dm_xe_objects
WHERE object_type = 'event'
AND name LIKE '%error%'

Le résultat est le suivant :

name

description

error_ring_buffer_recorded

Error ring buffer recorded

errorlog_written

Errorlog written

error_reported

Error has been reported

cdc_error

CDC Error Information

Voyons maintenant quels sont les champs que l'évènement error_reported audite :

SELECT name
, type_name
, column_type
FROM sys.dm_xe_object_columns
WHERE object_name = 'error_reported'

Le résultat est le suivant :

name

type_name

column_type

ID

uint16

readonly

UUID

guid_ptr

readonly

VERSION

uint8

readonly

CHANNEL

etw_channel

readonly

KEYWORD

keyword_map

readonly

error

int32

data

severity

int32

data

state

int32

data

user_defined

data

message

unicode_string

data

Les lignes pour lesquelles la colonne column_type est valuée à data représentent ce qui est exposé à l'utilisateur lorsqu'on lit ce que la session a capturé. Cela correspond tout à fait à n'importe quel message d'erreur classique que l'on obtient sous SQL Server.

Nous allons donc choisir l'évènement error_reported, et interroger la vue système sys.messages, qui contient tous les messages d'erreur dans toutes les langues dans lequel le moteur de base de données est disponible.

SELECT *
FROM sys.messages
WHERE language_id = 1033 -- Anglais
AND text LIKE '%login%'
AND text LIKE '%fail%'

Après un tri des messages, on peut spécifier la session XE suivante :

CREATE EVENT SESSION login_failure_audit ON SERVER
ADD EVENT sqlserver.error_reported
(
ACTION
(
sqlserver.sql_text
, sqlserver.client_app_name
, sqlserver.client_hostname
, sqlserver.database_id
, sqlserver.session_nt_username
)
WHERE error = 4060
OR error = 4064
OR error = 15113
OR error = 17197
OR error = 17892
OR error = 18056
OR error = 18311
OR error = 18315
OR error = 18321
OR error = 18322
OR error = 18323
OR error = 18324
OR error = 18325
OR error = 18326
OR error = 18327
OR error = 18331
OR error = 18332
OR error = 18333
OR error = 18339
OR error = 18343
OR error = 18345
OR error = 18346
OR error = 18347
OR error = 18348
OR error = 18350
OR error = 18357
OR error = 18401
OR error = 18451
OR error = 18452
OR error = 18456
OR error = 18458
OR error = 18459
OR error = 18460
OR error = 18461
OR error = 18462
OR error = 18463
OR error = 18464
OR error = 18465
OR error = 18466
OR error = 18467
OR error = 18468
OR error = 18470
OR error = 18471
OR error = 18486
OR error = 18487
OR error = 18488
)
ADD TARGET package0.asynchronous_file_target
(
SET FILENAME = 'C:\XE\login_failure_audit.xel'
, METADATAFILE = 'C:\XE\login_failure_audit.xem'
)
GO

Ici on va donc filtrer les erreurs rencontrées par le moteur de base de données seulement pour celles que l'on souhaite auditer, et qu'on a pu trouver dans sys.messages , et enregistrer chacune d'entre-elles dans le fichier de chemin 'C:\XE \ login_failure_audit.xel ' , dont la structure est décrite par le fichier dont le chemin est 'C:\XE \ login_failure_audit.xem ' .

La liste des données que nous capturerons est décrire par la clause ACTION :

- sqlserver.sql_text  : le texte de la requête ;

- sqlserver.client_app_name  : le nom de l'application qui a tenté la connexion ;

- sqlserver.client_hostname  : le nom de la machine qui héberge l'application ;

- sqlserver.database_id  : l'identifiant de la base de données à laquelle l'application a tenté de se connecter. On la trouvera dans la vue système sys.databases ;

- sqlserver.session_nt_username  : le nom d'utilisateur qui a été utilisé lors de la tentative de connexion.

Exécutons donc la requête : pour l'instant seule sa définition est enregistrée dans l'instance, mais elle n'audite rien. En effet, si nous interrogeons la DMV sys.dm_xe_sessions  :

SELECT name
, create_timeFROM sys.dm_xe_sessions

Nous obtenons:

name

create_time

system_health

2012-02-19 17:41:10.417

Comme nous l'avons vu dans les , la session system_health collecte quelques évènements qui permettent de savoir rétrospectivement ce qui s'est passé.

En revanche, en interrogeant la DMV sys.server_event_sessions, on obtient :

SELECT name
FROM sys.server_event_sessions

name

system_health

login_failure_audit

La définition est bien enregistrée. Voyons ce qui existe dans le dossier C:\XE\ :

Le dossier est vide pour le moment. Démarrons la session :

ALTER EVENT SESSION login_failure_audit ON SERVER
STATE = START
GO

Puis réexécutons :

SELECT name
, create_time
FROM sys.dm_xe_sessions

name

create_time

system_health

2012-02-19 17:41:10.417

login_failure_audit

2012-02-19 18:41:51.070

Voyons le contenu du dossier C:\XE\ :

Voilà nos deux fichiers. Nous pouvons utiliser SQLQueryStress pour tester avec un login qui n'existe pas. Voyons dans ce cas si la session audite quelque chose :

SELECT CAST(event_data AS xml) AS data
FROM sys.fn_xe_file_target_read_file
(
'C:\XE\login_failure_audit*.xel'
, 'C:\XE\login_failure_audit*.xem'
, NULL
, NULL
)

Voici donc quelques documents XML. La partie compliquée dans la collecte de données avec les XE est l'interrogation de documents XML, qui est possible avec SQLXML. C'est un peu comme avec l'eau froide d'une piscine : c'est un peu dur au début, mais on s'en accommode assez facilement. Je ne rentre pas dans les détails que SQLXML, car cela pourrait faire l'objet d'un article complet, et dépasse le cadre de cet article.

Voici donc la requête qui permet de retourner un jeu de données SQL classique :

;WITH
CTE(event_data_xml) AS
(
SELECT CAST(event_data AS xml) AS data
FROM sys.fn_xe_file_target_read_file
(
'C:\XE\login_failure_audit*.xel'
, 'C:\XE\login_failure_audit*.xem'
, NULL
, NULL
)
)
SELECT DATEADD (Hour, DATEDIFF(hour, GETUTCDATE(), GETDATE()), event_data_xml.value('(/event/@timestamp)[1]', 'datetime')) AS time_stamp
, event_data_xml.value('(/event/data/value)[1]', 'int') AS message_id
, event_data_xml.value('(/event/data/value)[2]', 'tinyint') AS severity
, event_data_xml.value('(/event/data/value)[3]', 'tinyint') AS state
, event_data_xml.value('(/event/data/value)[5]', 'varchar(max)') AS message_label
, event_data_xml.value('(/event/action/value)[1]', 'nvarchar(max)') AS sql_text
, event_data_xml.value('(/event/action/value)[2]', 'sysname') AS application_name
, event_data_xml.value('(/event/action/value)[5]', 'sysname') AS requesting_login
, event_data_xml.value('(/event/action/value)[3]', 'sysname') AS client_host_name
FROM CTE
ORDER BY time_stamp

Ce qui donne:

time_stamp

message_id

severity

state

message_label

sql_text

application_name

requesting_login

client_host_name

2012-02-19 19:04:29.477

18456

14

5

Login failed for user ' toto '. Raison : impossible de trouver une connexion correspondant au nom fourni. [CLIENT : <local machine>]

Unable to retrieve SQL text

.Net SqlClient Data Provider

ELSUKET-SQL2008

On obtient donc le message complet retourné à l'application, la machine depuis laquelle a été exécutée l'application, le nom de cette dernière, et dans le cas présent, nous n'avons pas la requête. Dans d'autres cas, on obtient un jeu plus complet de données, qui permettent de signaler l'erreur à un collègue avec plus de précision. Ici on a une piste, qui est meilleure que celle donnée par le journal d'erreurs de SQL Server.

IV-A-1 - III.2 Audit des requêtes grandes consommatrices de CPU et/ou d'E/S disque

On cherche ici à collecter sur le long terme les requêtes contre-performantes. Ce sont typiquement les requêtes qui sont longues à s'exécuter, consomment beaucoup de CPU, et/ou les requêtes qui lisent beaucoup de pages. Ce n'est pas exhaustif, mais cela couvre assez largement les requêtes qui méritent d'être revues et optimisées.

Bien sûr on peut auditer la même chose avec SQL Profiler, mais il est clair que les Évènements Étendus ont un impact bien plus léger une instance SQL Server que SQL Profiler, surtout lorsque la charge de travail est de type OLTP (de très nombreuses requêtes, majoritairement simples).

Avec la même démarche que dans la section précédente, voyons s'il existe des évènements permettant de capturer les requêtes exécutées, que ce soit par des procédures stockées, ou avec sp_executesql, ou encore par un job.

SELECT name, description
FROM sys.dm_xe_objects
WHERE object_type = 'event'
AND name LIKE '%statement%'

Ce qui retourne:

name

description

sql_statement_starting

SQL statement starting

sql_statement_completed

SQL statement completed

sp_statement_starting

Stored procedure statement starting

sp_statement_completed

Stored procedure statement completed

Voyons maintenant quelles sont les données capturées par ces évènements :

SELECT O.name AS event_name
, C.name AS column_name
, C.type_name AS column_data_type
, C.column_type AS column_usage
FROM sys.dm_xe_object_columns AS C
INNER JOIN sys.dm_xe_objects AS O
ON C.object_name = O.name
WHERE O.name LIKE '%statement%'
AND C.column_type <> 'readonly'

event_name

column_name

column_data_type

column_usage

sql_statement_starting

source_database_id

uint16

data

sql_statement_starting

object_id

uint32

data

sql_statement_starting

object_type

uint16

data

sql_statement_starting

state

statement_state

data

sql_statement_starting

offset

int32

data

sql_statement_starting

offset_end

int32

data

sql_statement_starting

nest_level

int32

data

sql_statement_completed

source_database_id

uint16

data

sql_statement_completed

object_id

uint32

data

sql_statement_completed

object_type

uint16

data

sql_statement_completed

cpu

uint32

data

sql_statement_completed

duration

int64

data

sql_statement_completed

reads

uint64

data

sql_statement_completed

writes

uint64

data

sp_statement_starting

source_database_id

uint16

data

sp_statement_starting

object_id

uint32

data

sp_statement_starting

object_type

uint16

data

sp_statement_starting

state

statement_state

data

sp_statement_starting

offset

int32

data

sp_statement_starting

offset_end

int32

data

sp_statement_starting

nest_level

int32

data

sp_statement_completed

source_database_id

uint16

data

sp_statement_completed

object_id

uint32

data

sp_statement_completed

object_type

uint16

data

sp_statement_completed

cpu

uint32

data

sp_statement_completed

duration

int64

data

sp_statement_completed

reads

uint64

data

sp_statement_completed

writes

uint64

data

On voit clairement que les évènements sql_statement_completed et sp_statement_completed collectent les caractéristiques des requêtes dès que celles-ci ont terminé leur exécution :

- sp_statement_completed auditera les requêtes exécutées lors de l'appel d'un module T-SQL (procédure stockée, trigger, fonction) ;

- à l'inverse, sql_statement_completed auditera toutes les requêtes qui sont soumises au moteur de base de données en dehors d'un module T-SQL, par exemple lors de l'utilisation de sp_executesql, EXEC(@sql), ou par un job de l'Agent SQL Server.

Ces deux évènements nous permettent d'appliquer des filtres sur les caractéristiques des requêtes que l'on souhaite capturer : nombre de lecture s et d' écritures de pages , temps CPU consommé, durée de la requête, contexte de base de données .

Malheureusement le niveau d'imbrication (ex. : une procédure stockée qui en appelle une autre, qui qui appelle à son tour un trigger, qui lui-même appelle une procédure stockée qui exécute du code T-SQL dynamique à l'aide de sp_executesql ) n'est pas exposé par les deux évènements ci-dessus , mais il l'est par les évènements sql_statement_starting et sp_statement_star ted .

Avec ces deux évènements, on peut créer la session suivante :

CREATE EVENT SESSION long_running_queries ON SERVER
ADD EVENT sqlserver.sp_statement_completed
(
ACTION (sqlserver.sql_text)
WHERE(
reads >= 100000 -- en nombre de pages
OR duration >= 10000000 -- 10 secondes en microsecondes
)
AND sqlserver.database_id = 7 -- voircolonnesys.databases.database_id
)
, ADD EVENT sqlserver.sql_statement_completed
(
ACTION (sqlserver.sql_text)
WHERE(
reads >= 100000 -- en nombre de pages
OR duration >= 10000000 -- 10 secondes en microsecondes
)
AND sqlserver.database_id = 7 -- voircolonnesys.databases.database_id
)
ADD TARGET package0.asynchronous_file_target
(
SET FILENAME = N'C:\XE\long_running_queries.xel'
, METADATAFILE = N'C:\XE\long_running_queries.xem'
)
-- si le service est redémarré, la session démarre
-- avant que l'instance soit disponible aux connexions
WITH
(STARTUP_STATE = ON)
GO

ALTER EVENT SESSION long_running_queries ON SERVER
STATE = START;

Ici on souhaite auditer :

- toutes les requêtes ;

- dont le nombre de lectures est supérieur ou égal à 100 000 ;

- et dont la durée dépasse 10 secondes ;

- et qui s'exécutent dans la base de données dont le database_id égale 7 : (qui correspond à l'id de la base de données ELSUKET sur mon instance SQL Server ici).

Voyons donc ce que l'on capture à l'exécution de la requête suivante :

SELECT *
FROM master.dbo.spt_values AS A
CROSS JOIN master.dbo.spt_values AS B

La machine virtuelle sur laquelle j'ai réalisé l'article est paramétrée avec 1 GB de mémoire vive. La table dbo. spt_values contenant 2506 lignes, la requête retournera donc 6.280. 036 lignes , ce qui devrait prendre relativement longtemps à calculer compte tenu des caractéristiques physiques de la machine virtuelle.

La requête qui permet de dépouiller ce qui est collecté par cette session est la suivante :

;WITH
CTE(event_data_xml) AS
(
SELECT CAST(event_data AS xml) AS data
FROM sys.fn_xe_file_target_read_file
(
N'C:\XE\long_running_queries*.xel'
, N'C:\XE\long_running_queries*.xem'
, NULL
, NULL
)
)
, DATA AS
(
SELECT DATEADD
(
hour
, DATEDIFF(hour, GETUTCDATE(), GETDATE()), event_data_xml.value('(/event/@timestamp)[1]', 'datetime')) AS time_stamp
, event_data_xml.value('(/event/data/value)[1]', 'int') AS database_id
, event_data_xml.value('(/event/action/value)[1]', 'nvarchar(max)') AS query
, event_data_xml.value('(/event/data/value)[4]', 'bigint') AS CPU
, event_data_xml.value('(/event/data/value)[5]', 'bigint') AS duration
, event_data_xml.value('(/event/data/value)[6]', 'bigint') AS reads
, event_data_xml.value('(/event/data/value)[7]', 'bigint') AS writes
FROM CTE
)
SELECT DB.name AS database_name
, D.time_stamp
, D.query
, D.CPU
, D.duration
, D.reads
, D.writes
FROM DATA AS D
INNER JOIN sys.databases AS DB ON D.database_id = DB.database_id
ORDER BY time_stamp

Durant l'exécution de la requête avec CROSS JOIN, bien que le temps total d'exécution soit supérieur à 2 minutes, l'exécution de la requête ci-dessus ne retourne rien : cela correspond tout à fait au nom des évènements que nous avons utilisés pour définir la session : ils contiennent tout le mot completed .

En revanche, dès la fin de la session, on obtient :

Le nombre de lectures (colonne reads ) n'a pas excédé le seuil de capture que nous avions fixé (100 000), mais il a amplement dépassé celui de la durée : la requête a duré 123 721 646 µs , et le seuil est à 10 000 000 µs. Nous avons toutes les autres données que nous voulons pour cet audit, en particulier la base de données dans laquelle s'est exécutée la requête, et à quelle heure.

Il est nécessaire d'utiliser DATEDIFF(hour, GETUTCDATE(), GETDATE()), puisque l'heure d'un évènement est toujours enregistrée en UTC.

Mais il serait bien utile aussi de savoir quelle application, sur quelle machine, et par quel utilisateur cette requête a été exécutée. Il suffit donc de modifier la session en ajoutant les actions sqlserver.client_app_name , sqlserver.client_hostname et sqlserver.session_nt_username , que l'on trouve avec la requête qui liste toutes les actions à la section I.4 :

-- Créons une toute nouvelle session

DROP EVENT SESSION long_running_queries ON SERVERGO

-- Supprimer les fichiers relatifs à cette session

-- Création de la nouvelle session

CREATE EVENT SESSION long_running_queries ON SERVER
ADD EVENT sqlserver.sp_statement_completed
(
ACTION
(
sqlserver.sql_text
, sqlserver.client_app_name
, sqlserver.client_hostname
, sqlserver.session_nt_username
)
WHERE(
reads >= 100000 -- en nombre de pages
OR duration >= 10000000 -- 10 secondes en microsecondes
)
AND sqlserver.database_id = 7 -- voircolonnesys.databases.database_id
)
, ADD EVENT sqlserver.sql_statement_completed
(
ACTION
(
sqlserver.sql_text
, sqlserver.client_app_name
, sqlserver.client_hostname
, sqlserver.session_nt_username
)
WHERE(
reads >= 100000 -- en nombre de pages
OR duration >= 10000000 -- 10 secondes en microsecondes
)
AND sqlserver.database_id = 7 -- voircolonnesys.databases.database_id
)
ADD TARGET package0.asynchronous_file_target
(
SET FILENAME = N'C:\XE\long_running_queries.xel'
, METADATAFILE = N'C:\XE\long_running_queries.xem'
)
-- si le service est redémarré, la session démarre
-- avant que l'instance soit disponible aux connexions
WITH
(STARTUP_STATE = ON)
GO

ALTER EVENT SESSION long_running_queries ON SERVER
STATE = START;

Après avoir réexécuté la requête avec le CROSS JOIN, voyons ce que retourne la fonction  sys . fn_xe_file_target_read_file :

SELECT CAST(event_data AS xml) AS data
FROM sys.fn_xe_file_target_read_file
(
N'C:\XE\long_running_queries*.xel'
, N'C:\XE\long_running_queries*.xem'
, NULL
, NULL
)

<eventname=« sql_statement_completed »package=« sqlserver »id=« 60 »version=« 1 »timestamp=« 2012-04-14T11:58:57.224Z »>
<dataname=« source_database_id »>
<value>7</value>
<text />
</data>
<dataname=« object_id »>
<value>908208103</value>
<text />
</data>
<dataname=« object_type »>
<value>20801</value>
<text />
</data>
<dataname=« cpu »>
<value>5868</value>
<text />
</data>
<dataname=« duration »>
<value>79657089</value>
<text />
</data>
<dataname=« reads »>
<value>42736</value>
<text />
</data>
<dataname=« writes »>
<value>7</value>
<text />
</data>
<actionname=« sql_text »package=« sqlserver »>
<value>SELECT * FROM master.dbo.spt_values AS A CROSS JOIN master.dbo.spt_values AS B</value>
<text />
</action>
<actionname=« client_app_name »package=« sqlserver »>
<value>Microsoft SQL Server Management Studio - Requête</value>
<text />
</action>
<actionname=« client_hostname »package=« sqlserver »>
<value>ELSUKET-SQL2008</value>
<text />
</action>
<actionname=« session_nt_username »package=« sqlserver »>
<value>ELSUKET-SQL2008\Nicolas SOUQUET</value>
<text />
</action>
</event>

On peut donc changer la requête de dépouillement des documents XML retournés par la fonction :

;WITH
CTE(event_data_xml) AS
(
SELECT CAST(event_data AS xml) AS data
FROM sys.fn_xe_file_target_read_file
(
N'C:\XE\long_running_queries*.xel'
, N'C:\XE\long_running_queries*.xem'
, NULL
, NULL
)
)
, DATA AS
(
SELECT DATEADD(hour, DATEDIFF(hour, GETUTCDATE(), GETDATE()), event_data_xml.value('(/event/@timestamp)[1]', 'datetime')) AS time_stamp
, event_data_xml.value('(/event/data/value)[1]', 'int') AS database_id
, event_data_xml.value('(/event/action/value)[1]', 'nvarchar(max)') AS query
, event_data_xml.value('(/event/action/value)[2]', 'varchar(256)') AS appname
, event_data_xml.value('(/event/action/value)[3]', 'varchar(128)') AS hostname
, event_data_xml.value('(/event/action/value)[4]', 'varchar(256)') ASusername
, event_data_xml.value('(/event/data/value)[4]', 'bigint') AS CPU
, event_data_xml.value('(/event/data/value)[5]', 'bigint') AS duration
, event_data_xml.value('(/event/data/value)[6]', 'bigint') AS reads
, event_data_xml.value('(/event/data/value)[7]', 'bigint') AS writes
FROM CTE
)
SELECT DB.name AS database_name
, D.time_stamp
, D.appname
, D.hostname
, D.username
, D.query
, D.CPU
, D.duration
, D.reads
, D.writes
FROM DATA AS D
INNER JOIN sys.databases AS DB ON D.database_id = DB.database_id
ORDER BY time_stamp

Ce qui donne :

Changeons maintenant cette requête en procédure stockée  :

CREATE PROCEDURE usp_spt_values_play_around
AS
BEGIN
SET NOCOUNT ON

SELECT *
FROM master.dbo.spt_values AS A
CROSS JOIN master.dbo.spt_values AS B
END
GO

EXEC dbo.usp_spt_values_play_around

En réexécutant la seconde requête de dépouillement, nous obtenons :

On voit donc qu'on a bien capturé deux évènements : un pour l'exécution de la requête dans la procédure stockée, et un pour l'exécution de la procédure stockée. Malheureusement, nous obtenons deux fois le même texte, et assez curieusement, des consommations de ressources différentes.

IV-A-2 - III.3 Audit du nombre d'appels à des modules T-SQL par base de données utilisateur avec l'anneau de mémoire

J'ai créé cette session afin de chercher les bases de données qui ne sont jamais utilisées, sur une instance de SQL Server dédiée au développement, et qui hébergeait une centaine de base de données.

Comme le standard de l'entreprise est d'utiliser exclusivement des procédures stockées, mais qu'il existe aussi quelques triggers et fonctions, on peut donc chercher s'il existe un évènement qui capture l'exécution d'un module T-SQL :

SELECT P.name AS package_name
, O.name AS event_name
, O.description
FROM sys.dm_xe_objects AS O
INNER JOIN sys.dm_xe_packages AS P
ON O.package_guid = P.guid
WHERE O.object_type = 'event'
AND O.name LIKE '%module%'

Ce qui retourne :

Voyons en détail s les caractéristiques de l'anneau de mémoire asynchrone (il en existe un synchrone, comme le montre le résultat de la requête pages 8 et 9 de la section I.3 ) :

SELECT O.name AS target_name
, OC.column_id
, OC.name AS column_name
, OC.column_type
, OC.column_value
, OC.description AS column_description
FROM sys.dm_xe_objects AS O
INNER JOIN sys.dm_xe_object_columns AS OC
ON O.name = OC.object_name
INNER JOIN sys.dm_xe_packages AS P
ON O.package_guid = P.guid
WHERE O.object_type = 'target'
AND O.name = 'asynchronous_bucketizer'

Dont le résultat est le suivant :

On peut donc définir la session comme suit :

CREATE EVENT SESSION database_usage ON SERVER
ADD EVENT sqlserver.module_start
(
ACTION (sqlserver.database_id)
WHERE (
sqlserver.database_id > 4 - La base de données n'est pas une base de données système
AND sqlserver.database_id <> 32767 - La base de données n'est pas Resource
)
)
ADD TARGET package0.asynchronous_bucketizer
(
SET filtering_event_name = 'sqlserver.module_start'
, source_type = 1 -- The source type: 0: filtering event name, 1: action name
, source = 'sqlserver.database_id'
, slots = 128 -- Number of buckets in the histogram
)
WITH
(
MAX_DISPATCH_LATENCY = 5 SECONDS)
GO

-- Starting the session

ALTER EVENT SESSION database_usage ON SERVER
STATE = START
GO

Sur un serveur en cours d'activité, il suffit d'attendre quelques secondes (un peu plus de 5 avec la session ci-dessus ) pour voir ce qui est capturé :

SELECT CAST(T.target_data AS xml) AS target_data
FROM sys.dm_xe_sessions AS S
INNER JOIN sys.dm_xe_session_targets AS T
ON S.address = T.event_session_address
WHERE S.name = 'database_usage'
AND T.target_name = 'asynchronous_bucketizer'

Étant donné qu'on peut avoir plusieurs sessions utilisant un anneau de mémoire, il est nécessaire de filtrer par le nom de la session. Le résultat de la requête est le suivant :

<BucketizerTargettruncated=« 0 »buckets=« 128 »>
<Slotcount=« 8 »trunc=« 0 »>
<value>7</value>
</Slot>
</BucketizerTarget>

Ce que l'on transforme en données directement interprétables avec la requête suivante :

;WITH
CTE AS
(
SELECT CAST(T.target_data AS xml) AS target_data
FROM sys.dm_xe_sessions AS S
INNER JOIN sys.dm_xe_session_targets AS T
ON S.address = T.event_session_address
WHERE S.name = 'database_usage'
AND T.target_name = 'asynchronous_bucketizer'
)
, DATA AS
(
SELECT BZ.bucket.value('./value[1]', 'int') AS database_id
, BZ.bucket.value('./@count', 'int') AS calls_count
FROM CTE
CROSS APPLY target_data.nodes('BucketizerTarget/Slot') AS BZ(bucket)
)
SELECT DB.name AS database_name
, D.calls_count
FROM sys.databases AS DB
INNER JOIN DATA AS D
ON DB.database_id = D.database_id

Qui, dans mon cas, donne à l'exécution :

Voyons combien de mémoire consomme l'anneau :

SELECT name
, create_time
, total_buffer_size / 1024 AS total_buffer_size_KB
FROM sys.dm_xe_sessions
WHERE name = 'module_call'

Ce qui donne 4223 dans la colonne total_buffer_size_KB , soit 4MB . C'est négligeable sur un serveur.

V - Le futur avec SQL Server 2012

Microsoft continue d'investir dans cet outil qui, nous l'avons vu, permet de collecter des données sur tout ce qui se passe dans une instance SQL Server.

S QL Server 2008 (R1) propose 255 évènements ; SQL Server 2012 en propose 618 !

On notera les ajouts suivants :

- blocked_process_report ;

- sql_batch_starting / completed ;

- missing_column_statistics et missing_join_predicate , ou encore les évènements do n t le nom commence par sp_cache _ ;

- window_spool_ondisk_warning ;

- les évènements concernant les nouvelles fonctionnalités de SQL Server 2012

- la haute disponibilité (81, commençant par hadr _ ) et AlwaysOn (5, commençant par availability _ et alwayson _ ),

- les index ColumnStore (5, commençant par column_store _ ),

- la méthode de stockage FileTable (13, commençant par filetable _ ),

- les évènements concernant Unified Communications Stack(+22, contenant ou commençant par ucs_) ;

- les index de texte intégral (+ 10 , commençant soit par full_ , full_text _ , ou fulltext _ ) ;

- le fichier du journal des transactions (+ 17, commençant par log_ ) ;

- login et logout ;

- la possibilité de capturer les plans de requête (+3, se terminant par _ showplan , attention à l'impact sur les performances !) ;

- les appels de procédures stockées distants (+56, commençant par query_rpc _ ) ;

- les phases de récupération (+14, commençant par recovery _ et redo _ ) ;

- plus de colonnes exposées par de nombreux évènements : certaines des colonnes que j'ai utilisées dans cet article ne sont plus disponibles ; par exemple reads a été remplacée par logical_reads et physical_reads a été ajouté.

Pour ceux qui utilisent cette requête pour obtenir rétrospectivement la liste des deadlocks sous SQL Server 2008, elle produit un document XML qui, lorsqu'il est ouvert avec SQLProfiler, produit une erreur sous SQL Server 2008. Cela a été corrigé avec SQL Server 2012.

Enfin, Microsoft a ajouté une interface graphique :

En effectuant un clic droit sur le nœud sessions, on se voit proposer un assistant de création de sessions, ou bien une interface permettant de créer directement une session pour les utilisateurs un peu plus avancés.

Nul doute que cela facilitera également la création manuelle de sessions, puisque comme avec la plupart des interfaces graphiques de SQL Server Management Studio, on a la possibilité de scripter ce que l'on vient de spécifier.

VI - Avantages et inconvénients de l'utilisation des XE

Voici quelques éléments en faveur de l'utilisation des évènements étendus :

- ils fournissent une interface unique de diagnostic du moteur de base de données ;

- la spécification et le contrôle des sessions d'évènements étendus se font entièrement en T-SQL : il suffit donc de sauver le script pour le réutiliser sur d'autres serveurs, ou encore tester la session sur un serveur de développement, puis faire un déploiement de la session sur un groupe de serveurs Central Mangement Servers ;

- les évènements sont exécutés de manière synchrone, et peuvent ensuite être traités de la même façon, ou bien en asynchrone

- l'architecture interne des évènements éte ;ndus repose à un niveau très bas dans l'architecture globale du moteur de base de données  confère aux XE un très faible impact sur les performances globales de la base de données, tout en leur permettant d'interagir avec n'importe quel composant du moteur de bases de données ;

- il est possible de faire démarrer une session XE avant que l'instance soit disponible aux utilisateurs, à l'aide de l'option STARTUP_STATE.

Le seul inconvénient que je vois sous SQL Server 2008 est qu'il ne propose pas d'interface graphique pour la création de sessions, ce qui aurait facilité l'appropriation de cette fonctionnalité majeure pour les DBA.

On peut aussi considérer que l'écriture de requêtes SQL, SQLXML et XQuery n'est pas des plus simples, et que cela peut être un frein à l'utilisation des XE. Mais comme je l'ai déjà écrit en section II.5, avec un peu de pratique, l'écriture de telles requêtes devient (presque ?) aisée.

VII - Conclusion

On l'a vu donc, Microsoft a su, avec la fonctionnalité XE, proposer une interface unique de diagnostic d'un grand nombre d'évènements qui peuvent se produire aussi bien au niveau d'une instance de SQL Server qu'au niveau base de données.

Le XE remplacement allègrement le jeu d'outils proposé jusqu'avant l'introduction de SQL Server 2008, qu'il était nécessaire de combiner par un développement parfois complexe et peu souple.

Il ne fait nul doute que pour les DBAS, cette fonctionnalité est des plus utiles si ce n'est pas leur favorite. Si l'on peut voir l'absence d'interface graphique et le dépouillement d'un document XML en T-SQL comme un frein à son adoption, Microsoft a comblé le vide créé par le premier.

Pour ma part j'utilise les XE de façon régulière pour les besoins en base de données de mon employeur, et cela m'a permis de tracer des évènements jusqu'alors inaccessibles, ou difficilement accessibles avec les outils proposés avec les précédentes versions et de connaître la source de plusieurs problèmes de façon relativement simple.

J'espère que cet article vous a éclairé sous les XE, et qu'il vous aura donné envie de faire le saut pendant que votre entreprise envisage de passer à SQL Server 2012 (si ce n'est déjà fait), dans lequel vous serez probablement à l'aise pour auditer les nouvelles fonctionnalités à l'aide de XE.

Bon XE-Monitoring à tous !

Remerciements

Je remercie Mikedavem pour la relecture de l'article