SQL Server: Como examinar el registro de transacciones

En un momento dado, alguien puede modificar los datos de una tabla sensible. En otra ocasión, algún despistado puede borrar una tabla o incluso unos registros de otra tabla que no debería. Si ese "alguien" se da cuenta y honestamente nos lo comenta no pasa nada, como dba seguro que tenemos alguna copia de respaldo para poder recuperar esos datos: ya sea desde el backup nocturno, al combinado del backup con alguna copia del registro de transacciones si es una tabla que cambia continuamente (intentamos hacer un restore a una hora concreta). El problema lo podemos tener con tablas que no se usan apenas o que alguien ha borrado y no ha confesado. Para poder empezar nuestra búsqueda necesitamos habilitado el seguimiento de cambios para la base de datos en cuestión. En este post veremos como examinar el contenido del log con una base de datos de prueba.

Es cierto que existen algunas herramientas que ya permiten explorar de forma más automatizada el registro de transacciones. Por ejemplo, si hablamos de Oracle, Toad ya tiene el LogMiner, una opción de menú que nos permite ver el detalle de cada archivelog (fichero del registro de transacciones). Para MS SQL Server tenemos por ejemplo ApexSql Discovery and Recovery Tool. Estas aplicaciones lo hacen más fácil, más bonito y más rápido pero tienen un coste de licencia y en los tiempos que corren ya se sabe... Volviendo al tema, estas dos como muchas otras herramientas, no hacen magia y lo que acaban haciendo podemos encontrar la manera de hacerlo nosotros directamente (aunque nos cueste más tiempo y esfuerzo). En MS SQL Server, el caso que nos ocupar, para desgranar el contenido del registro de transacciones usaremos la función no documentada fn_dblog. Como parámetros solo requiere un Log Sequence Number (LSN) inicial y un LSN final. Como parámetro por defecto tiene el valor NULL y nos devolverá el contenido de todo el registro de transacciones. Vamos a probar con una base de datos limpia del entorno de desarrollo:

-- Script creación de la base de datos

USE [master];
GO

CREATE DATABASE [Testdb];
GO

-- Creación de una tabla

USE [Testdb];
GO

CREATE TABLE [Articulos] (
  [IdArticulo] INT IDENTITY,
  [FechaCreacion] DATETIME DEFAULT GETDATE (),
  [Codigo] CHAR (5) NOT NULL,
  [Descripcion] CHAR(20) NULL);

Aquí ya es momento de probar. Ejecutamos la consulta con la función fn_dblog para explorar que tenemos hasta ahora (solo con la creación de la base de datos y una tabla).

-- Primero vemos la cantidad

USE [Testdb]
GO
SELECT COUNT(*) 
FROM fn_dblog(NULL, NULL)

-- Vemos el detalle

SELECT [Current LSN],
  [Operation],
  [Transaction Name],
  [Transaction ID],
  [Transaction SID],
  [SPID],
  [Begin Time]
FROM fn_dblog(null,null)

Cuando observamos el resultado de la consulta para ver el detalle, podemos empezar por identificar los diferentes TransactionName. Ahora encontraremos "TestDb" para cuando empieza la creación de la base de datos y "CREATE TABLE" cuando empieza con la tabla. A partir de estos registros, si nos seguimos desplazando y comparando el Transaction ID vemos las operaciones internas que se incluyen en cada operación. En la foto inferior está el resultado. Si nos fijamos cada "transacción" empieza con un Operation del tipo LOP_BEGIN_XACT y se cierra con LOP_COMMIT_XACT (unos registros más abajo).

Lo siguiente será seguir investigando y ver que pasa con otro tipo de consultas DML como inserciones o actualizaciones.

-- Script con un INSERTy UPDATE

USE [Testdb];
GO

INSERT INTO [Articulos] (Codigo, Descripcion) VALUES ('00001','Scott Spark MTB')
GO

UPDATE [Articulos]
SET [Descripcion] = 'MTB Scott Spark 226'
WHERE [Codigo] = '00001'
GO

-- Vemos el detalle de nuevo

SELECT [Current LSN],
  [Operation],
  [Transaction Name],
  [Transaction ID],
  [Transaction SID],
  [SPID],
[Begin Time]
FROM fn_dblog(null,null)

Ahora miraremos de nuevo el resultado de la consulta y buscaremos el Transaction Name del tipo INSERT o UPDATE. Esta vez, miraremos en el resultado pero nos fijaremos los registros donde el SPID sea el mismo y no es nulo (en la imagen es 53). Si nos desplazamos veremos en que se traduce internamente el INSERT: primero el registro, la obtención de una página de datos donde insertar y la actualización de estadísticas (TransactionName=AutoCreateQPStats) de la tabla. El caso del update ya es más simple y se traduce solo en una Operation Name UPDATE y a nivel más bajo en vemos el BEGIN_XACT, LOP_MODIFY_ROW y LOP_COMMIT_XACT.

A continuació algunas consultas útiles sobre el resultado de la ejecución de fn_dblog:

• Consulta filtrada para ver a un nivel más alto las operaciones que tienen lugar, incluidas las de sistema:

SELECT [Current LSN],
  [Operation],
  [Transaction Name],
  [Transaction ID],
  [Transaction SID],
  [SPID],
  [Begin Time]
FROM fn_dblog(null,null)
WHERE [Transaction Name] IS NOT NULL

• Consulta para ver los principales tipos de consulta DML (INSERT, UPDATE, DELETE). Destacar el campo AllocUnitName que permite ver la tabla afectada y BeginTime con la fecha inicio:

SELECT
  [Current LSN],
  [Transaction ID],
  [Operation],
  [Transaction Name],
  [CONTEXT],
  [AllocUnitName],
  [Page ID],
  [Slot ID],
  [Begin Time],
  [End Time],
  [Number of Locks],
  [Lock Information]
FROM sys.fn_dblog(NULL,NULL)
WHERE Operation IN
('LOP_INSERT_ROWS','LOP_MODIFY_ROW', 'LOP_DELETE_ROWS','LOP_BEGIN_XACT','LOP_COMMIT_XACT')

• Consulta para ver la frecuencia con la que ocurren los "Page Splits". Estos ocurren cuando los cambios de la fila no caben en la página de datos que tocaría y se mueven a una nueva (que tengan lugar son malos si hablamos en términos de rendimiento!):

SELECT
  [Current LSN],
  [Transaction ID],
  [Operation],
  [Transaction Name],
  [CONTEXT],
  [AllocUnitName],
  [Page ID],
  [Slot ID],
  [Begin Time],
  [End Time],
  [Number of Locks],
  [Lock Information]
FROM sys.fn_dblog(NULL,NULL)
WHERE [Transaction Name]='SplitPage'
GO

En conclusión... 

..., saber que podemos explorar los cambios realizados recientemente y que mantenemos en el registro de transacciones puede ser útil en determinadas circunstancias, como algunas que comentamos arriba. Va bien incluso saber que se guarda el SPID ya que si mantenemos algún registro de las conexiones a la base de datos (mediante triggers de servidor por ejemplo) podemos enlazar una cosa con la otra: saber que cambio y quién lo hizo. En otro post ya comentaré el caso de los registros eliminados y como restablecerlos. Por cierto, si llegamos a probar esto en el entorno de producción porque podemos consumir bastantes recursos en la operación.

Libros de SQL Server

¿Quieres profundizar más en Transact-SQL o en administración de bases de datos SQL? Puedes hacerlo consultando alguno de estos libros de SQL Server.

Mejor revisa la lista completa de los últimos libros de SQL Server publicados en Amazon según lo que te interese aprender, pero estos son los que a mi me parecen más interesantes, teniendo en cuenta precio y temática:

• eBooks de SQL Server gratuítos para la versión Kindle, o muy baratos (menos de 4€):

• Libros recomendados de SQL Server