Tunear logs de SQL Server

Hace un par de semanas vengo trabajando en crear logs de SQL Server que valgan la pena para así poder realizar trabajos de revisión y auditoría de lo que sucede en los servidores de base de datos de la empresa. El tema es que, aunque a uno le parezca totalmente simple activar los logs de un sistema tan utilizado y (supuestamente) fácil de administrar, esto no es así.
Por defecto SQL Server no loguea casi nada útil, solamente cuando ocurre un error grave o cuando se hace backup de la base de datos. Si piensan que su motor de base de datos está (como debería) logueando información para poder controlar las acciones... piensen de nuevo!, revisen los logs y diganme si encuentran algo en los logs que les sirva!

Por supuesto que el DBMS en cuestión cuenta con sistema de logueo de eventos, pero hay que activarlo a mano y conocer un poco sobre el funcionamiento de algunos store procedures creados para esto. Una de las primeras cosas que uno se encuentra cuando busca logs de SQL Server, es el modo de auditoría C2, pero existen otra forma más efectiva de loguear, la cual es usando los traces de SQL Server. A continuación explico un poco de estas dos modalidades de logueo.

Cabe destacar que activar sistemas de logueo siempre generan una sobrecarga en el sistema. Dependiendo lo que deseemos loguear, la sobrecarga será mayor o menor, pero es un punto a tener en cuenta.


Modo de auditoría C2

Este modo fue diseñado para poder cumplir con la clase C2 del Criterio de evaluación de confianza de un sistema computacional creado por el Department of Defence yankee (DoD). Cuando se activa esta modalidad de logueo, todos los eventos y todas las columnas pertenecientes a cada evento se loguearan. Como se podrán imaginar, este nivel de logging es extremo y poco útil para la mayoría de los sistemas. Revisar estos logs es para un monje Shaolin drogado, porque por más filtros que pongamos, seguiremos teniendo miles de entradas repetitivas e inútiles.
Para que se den una idea del nivel de logueo C2, lo probamos en una base de datos con relativo poco movimiento de datos y el log creció a más de 1GB en un par de horas! 1GB de texto! se imaginan lo que es??? pues mucho!

Si luego de toda esa introducción al modo audit C2 todavía tienen ganas de probarlo, lo pueden hacer ejecutando las siguientes sentencias T-SQL:

SP_CONFIGURE 'show advanced options', 1;
GO
RECONFIGURE
GO
SP_CONFIGURE 'c2 audit mode', 1;
GO
RECONFIGURE
GO
SP_CONFIGURE 'show advanced options', 1;
GO

Luego de ejecutar las sentencias anteriores, deberán reiniciar el motor de base de datos, así que haganlo en algún momento donde no tengan mucho movimiento de datos.
Para revisar que el modo quedó activado, pueden ejecutar la siguiente sentencia:

SELECT value FROM sys.configurations
WHERE name = 'c2 audit mode';
GO

Los logs se almacenan en el directorio \MSSQL\Data (osea, donde está instalado el SQL Server) y son archivos .trc de 200MB cada uno. Los archivos se van generando a medida que se van llenando, osea, se arranca con un archivo, cuando llega a 200MB, se cierra y se abre uno nuevo.
Recuerden lo que les dije al principio, estos logs son monstruosos, así que si tienen poco espacio en el disco, vigilenlos! Sino les comerá el disco y al almacenarse en la misma partición que la base de datos, puede que les genere un Denial of Service si el disco se llena!


SQL Traces

Para no volvernos locos con los logs generados por el modo C2, podemos customizar lo que deseamos loguear utilizando trazas (traces), las cuales creamos con una serie de store procedures que trae SQL Server. La explicación de cada uno de estos store procedures la pueden encontrar en la página oficial de MS, dependiendo la versión de SQL Server que tengan, puede variar un poco, pero hasta donde vi es bastante similar en todas las versiones. Yo voy a explicar el sistema para SQL Server 2005, pero no debería variar mucho para SQL Server 2008.

SQL Server basa su funcionamiento en eventos y por ello, los logs se arman en base a los eventos que queremos loguear. Por cada evento tenemos una serie de atributos que podemos loguear. Muchos atributos son comunes para todas los eventos, pero algunos son específicos para cierta clase de eventos. Nuestro trabajo trata sobre ver que eventos queremos loguear y qué atributo de cada evento deseamos... no es un trabajo fácil, porque existen como 200 eventos a loguear, y contamos con 64 atributos posibles, encontrar lo que realmente necesitamos llevará un tiempo de pruebas.

Para comenzar les puedo dar el formato de como crear una traza básica:

-- declaramos las variables necesarias
DECLARE @traceID int
DECLARE @maxFileSize bigint
DECLARE @traceFile nvarchar(245)
DECLARE @on bit
DECLARE @date nvarchar(25)

-- seteamos el tamanio para los archivos donde se almacenan los logs
set @maxfilesize = 200
-- seteamos la localización de los logs
set @date = convert(nvarchar(25), GETDATE())
set @date = REPLACE(@date,':','.')
set @date = REPLACE(@date,' ','_')
set @traceFile = N'D:\SQL_Traces\trace_'+@date+'.trc'


-- creamos la traza, obtienendo un id que se almacenara en @traceID. Indicamos que cuando se alcance el maximo del archivo, se cree otro archivo nuevo.
EXEC sp_trace_create @traceID OUTPUT, 2, @traceFile, @maxFileSize, NULL

-- decimos que queremos activar el evento
set @on = 1

-- activamos el evento 109 (auditar cuando se agrega un login a la base de datos) y queremos guardar las columnas 1 (el texto generado por el evento) y 11 (el nombre de login).
EXEC sp_trace_setevent @traceID, 109, 1, @on
EXEC sp_trace_setevent @traceID, 109, 11, @on

-- activamos el evento 110 (agregar un miembro a un rol) con las mismas columnas que antes.
EXEC sp_trace_setevent @traceID, 110, 1, @on
EXEC sp_trace_setevent @traceID, 110, 11, @on

-- iniciamos la traza
EXEC sp_trace_setstatus @traceID, 1
GO

Traté de comentar todo lo relevante en el código, pero es interesante destacar el significado de algunas líneas. Por un lado al principio decimos el tamaño máximo que debe alcanzar cada archivo de log (se utiliza el formato propietario .trc). Luego creamos un nombre para estos archivos. Como no deseamos pisar trazas anteriores, le agregué la fecha al nombre de archivo.
Una vez seteadas las variables, creamos la traza con el store procedure sp_trace_create, al cual debemos pasarle una variable donde nos retornará el id de la traza creada. Con el siguiente valor le podemos especificar opciones, yo coloqué 2 para indicar que una vez que se llena el archivo de log (osea, alcanzamos los 200MB), que se cree un nuevo archivo... es decir, vamos creando archivos de 200MB. Como se imaginarán, el siguiente parámetro especifica el nombre del archivo donde guardar las trazas, y el que se encuentra al lado es el tamaño de los archivos. Por último, como no nos interesan los valores stoptime y filecount, colocamos un NULL.
Ahora pasamos a setear los eventos que queremos loguear. Primero utilizamos una variable del tipo bit que nos servirá para decir que queremos poner en on el evento... esa variable la utilizaremos en el store procedure sp_trace_setevent. Las siguientes líneas simplemente activan los eventos agregar un login y agregar usuario a un rol utilizando la citada sp_trace_setevent. Para ambos casos logueamos las columnas 1 y 11, las cuales nos dicen el texto del evento (osea, lo que pasó) y el nombre del usuario de login que causó el evento. La lista completa de eventos que pueden loguear y las columnas que se pueden loguear, vean el mismo manual de sp_trace_setevent... armense de paciencia porque son muchos...
Por último, iniciamos la traza utilizando el store procedure sp_trace_setstatus, donde le damos el id de la traza que queremos activar, y le pasamos un 1 para indicar que iniciamos, si pusiéramos un 0 estaríamos deteniendo y con un 2 la eliminamos del sistema.

Muy bien, con todo lo anterior ya tenemos la traza en ejecución y logueando eventos. Qué pasa si queremos detenerla? utilizamos el citado sp_trace_setstatus. Como habrán visto, sp_trace_setstatus necesita dos parámetros, el id de la traza y el indicador de qué hacer con la traza (comenzar, detener, eliminar). Pues cómo obtenemos el id de la traza que deseamos? acuerdense que antes utilizábamos la variable @traceID, pero esa variable la perdemos una vez q termina la ejecución de las sentencias anteriores. No desesperen, hay una forma de hacer esto.
Dado que pueden haber varias trazas en ejecución al mismo tiempo, primero tenemos que buscar la que deseamos. Para esto podemos usar la sentencia:

select * from fn_trace_getinfo(0)

Esta sentencia nos devuelve todos los ids de las trazas existentes. Busquen la que desean detener mirando los atributos de cada una (pueden buscar el nombre del archivo donde se guardan los logs por ejemplo). Una vez que obtenemos el id de la traza simplemente ejecutamos:

EXEC sp_trace_setstatus elID, 0

si queremos solamente detenerla, o bien:

EXEC sp_trace_setstatus elID, 0
EXEC sp_trace_setstatus elID, 2

si queremos detenerla y eliminarla del sistema.

Lo último que me queda por decir acerca de las trazas es que estas se detienen cada vez que reiniciamos el motor de base de datos y no se arrancan solas. Si queremos que nuestra traza se inicie cada vez que iniciamos el motor de base de datos, podemos meter todo el código anterior en un store procedure de la base de datos master:

USE [MASTER]
GO

CREATE PROCEDURE usp_trace
AS

... TODO EL CODIGO ANTERIOR ...

Una vez creado el store procedure, debemos configurarlo para que se ejecute al inicio. Para esto, necesitamos oooootro store procedure llamado sp_procoption. Por suerte esto SP es muy simple, debemos pasarle el nombre del SP que queremos ejecutar, un valor indicando lo que queremos hacer (en nuestro caso que se ejecute al inicio del sistema) y el valor de la opción (true para activarlo). Asumiento el nombre del store procedure que utilice en el ejemplo (usp_trace), deberíamos ejecutar lo siguiente:

EXEC sp_procoption ups_trace, StartUp, True

Cómo leemos los archivos .trc?

Para variar, nuestros amigos de MS nos entregan un formato propietario el cual no se puede abrir con otra cosa que no sea el SQL Profiler, osea, un programa provisto por ellos...
El SQL Profiler es bastante completo y permite realizar distintos niveles de filtrado para poder visualizar la información que nos interesa, pero igualmente preferiría un formato de archivo visible con cualquier editor, o desde una base de datos.

Cabe destacar que es posible volcar los valores del log a una base de datos para que sean más fáciles de administrar, aunque ahora no recuerdo exactamente en donde estaba explicado, si lo encuentro en estos días, actualizo el artículo =)

También es interesante saber que las trazas se pueden crear desde el SQL Profiler, desde una GUI bien bonita... aunque siempre es mejor hacerlo a mano y estar seguro de qué se está activando. Además el SQL Profiler incurre en un overhead extra en el sistema para ejecutar las trazas...


Referencias

El gran artículo que me ayudó muchísimo a entender todo este sistema de log de eventos fue Get Compliant with SQL Server 2005 Audit, muchas gracias Larry Clark por tan buen artículo.
Por supuesto que el resto lo tuve que hacer solo mirando los manuales de MS que pueden encontrar en SQL Server Profiler Stored Procedures (Transact-SQL).