Bueno, en esta oportunidad quiero comentarles una técnica que me ha dado excelentes resultados con muy poco trabajo. Se trata de dedicar algunos minutos, máximo alguna hora a la creación de un esquema de logueo de comandos de base de datos ejecutados por dbexpress que puede ser de suma utilidad en desarrollo e incluso en producción.
El Problema
Muchas veces en el día a día del desarrollo nos encontramos con alguna error de base de datos, o una operación que no se realizo como esperábamos, en definitiva una situación desconocida y no tenemos muchas herramientas para hacer un diagnostico rápido. De nada valen breakpoints porque no es un error de programa sino propiamente SQL.
La solución
La solución que quiero presentar es muy simple de implementar gracias el componente TsqlMonitor de DBExpress, no cuesta mucho trabajo y siempre es útil tener a mano algo mas de información para un rápido diagnostico. El Componente TsqlMonitor nos dispara una evento con cada interacción entre nuestra conexión y la base de datos, este evento viene acompañado de una buena cantidad de información sobre el comando que se acaba de ejecutar, existen una forma rapida mediante el componente de guardar esta información en archivo pero yo quiero ir un poco mas allá.
La implementación
Lo que propongo es guardar también esta información en la base de datos, esto nos permite rastrear y encontrar mejor lo que buscamos, permite una persistencia mas seria de la historia. Un diseño de tabla mas o menos completo seria el siguiente:
CREATE TABLE [dbo].[SqlLog](
[IdSqlLog] [int] IDENTITY(1,1) NOT FOR REPLICATION NOT NULL,--Clave principal autoincremental
[Module] [varchar](50) NULL,--Modulo que ejecuto el comando, muy util en DataSnap
[FechaHora] [datetime] NOT NULL,--FechaHora de ejecucion
[Message] [text] NOT NULL,--Mensaje, DDL DML correspondiente
[TraceFlag] [int] NOT NULL,--Informacion adicion DBExpress
[TraceLevel] [int] NOT NULL, --Informacion adicion DBExpress
[CustomCategory] [varchar](256) NOT NULL, --Informacion adicion DBExpress
[Login] [varchar](50) NULL, --Usuario logueado
[InTransaction] [varchar](50) NOT NULL, --¿El comando se ejecuto dentro de una transaccion?
CONSTRAINT [PK_idSqlLog] PRIMARY KEY CLUSTERED
(
[IdSqlLog] ASC
) )Etc....
Esto esta extraido de un sqlserver 2008 pero es mas o menos lo mismo en cualquier motor. Comento en cada linea cual es la idea del campo.
Campo mas campo menos la información esta, abajo un ejemplo real de mis aplicaciones
TSqlMonitor
Lo primero que hay que hacer luego de crear la tabla es drag and drop de un TsqlMonitor a nuestro DataModule o donde tengamos acceso a nuestro componente de conexión, mediante la propiedad SqlConnection enlazamos el Monitor a la conexión.
Si tenemos una datamodule o servermodule abstracto del cual heredamos mucho mejor, mas información sobre esto aquí
Ahora hay que tener mucho cuidado, no podemos usar la misma conexión para loguear lo que sucede, seria como verse entre dos espejos, la situación se extendería hasta el infinito en el caso de dbexpress hasta el access violation :)
La razón es simple, si usamos la misma conexión al tener que llevar una operación al log estaríamos generando otro trace (El insert al log) que también generaría otro comando para un nuevo trace de este comando y así hasta el desastre.
De esto se desprende que necesitamos otra conexión para cumplir con el objetivo, podemos usar directamente le componente de conexión o ayudarnos con un TsqlQuery con la siguiente inserción:
INSERT INTO SqlLog
(Module, Message, TraceFlag, TraceLevel, CustomCategory, Login, InTransaction)
VALUES (:Module,:Message,:TraceFlag,:TraceLevel,:CustomCategory,:Login,:InTransaction)
(Las fechas las pone la base), y un metodo que hago uso del comando mas o menos así:
function TDMGlobalConnection.eLogTrace(AModule:String; Msg:String; TraceFlag:Integer; TraceLevel:Integer; CustomCategory:String; UserName:String; InTransaction:boolean):boolean;
begin
Result := false;
//OLEDB - Commit
//OLEDB - StartTransaction
//256=Consulta
//512=Parametros
if ((TraceFlag=256) or (TraceFlag=512) and ((TraceFlag=32))) and
(
(Msg<>'OLEDB - Release')and
(Msg<>'OLEDB - ReleaseAccessor')and
(Msg<>'OLEDB - GetNextRows')and
(Msg<>'OLEDB - ReleaseRows')and
(Msg<>'OLEDB - GetData')and
(Msg<>'OLEDB - Execute')and
(Msg<>'OLEDB - GetResult')and
(Msg<>'OLEDB - CreateAccessor')and
(Msg<>'OLEDB - IAccessor')and
(Msg<>'OLEDB - GetColumnsInfo')and
(Msg<>'OLEDB - GetColumnInfo')and
(Msg<>'OLEDB - IColumnsInfo')and
(Msg<>'OLEDB - ICommandText')and
(Msg<>'OLEDB - SetCommandText')and
(Msg<>'OLEDB - GetResult')and
(Msg<>'OLEDB - ReleaseAccessor')and
(Pos('SELECT DISTINCT DB_NAME(), SCHEMA_NAME(O.uid)', Msg)=0)and
(AModule<>'TDSInterface')
) then begin
InsertLog.ParamByName('Module').Value := AModule;
InsertLog.ParamByName('Message').Value := Msg;
InsertLog.ParamByName('TraceFlag').Value := TraceFlag;
InsertLog.ParamByName('TraceLevel').Value := TraceLevel;
InsertLog.ParamByName('CustomCategory').Value := CustomCategory;
InsertLog.ParamByName('Login').Value := UserName;
InsertLog.ParamByName('InTransaction').Value := BoolToStr(InTransaction, true);
InsertLog.ExecSQL();
Result := true;
end;
end;
Se puede observar que no se esta logueando todo, se esta haciendo un filtro y esto es muy dependiente del motor, el lector puede loguear todo y luego ir quitando mediante filtros elementos que no lo interesan o no aportan a la causa.
¿Y con aplicaciones multithread?¿Y con DataSnap?
Bueno es básicamente lo mismo pero añadimos un complejidad mas, podemos tener las dos conexiones en cada servermodule, una para su uso regular y otra para log.
Sin embargo la cantidad de conexiones puede ser demasiada si operamos asi, la solucion tener un DataModule global, a este dataModule lo van a usar todos los server modules que necesite loguear. ¡Pero cuidado con la concurrencia! Debemos utilizar seccion criticas para asegurarnos que lo hagan de a uno a la vez, véase
Finalmente el evento quedaria así
procedure TAbstractDSServerModule.SQLMonitorTrace(Sender: TObject;
TraceInfo: TDBXTraceInfo; var LogTrace: Boolean);
begin
//Puede poner flag para desactivar log en producción o cuando no se desee
CSConnection.Enter;
try
DMGlobalConnection.eLogTrace(Self.ClassName, TraceInfo.Message, TraceInfo.TraceFlag, TraceInfo.TraceLevel, TraceInfo.CustomCategory, 'Proxima entrada', TSqlMonitor(Sender).SQLConnection.InTransaction);
finally
CSConnection.Leave;
end;
end;
end;
Prometo subir el código de todas las entradas en breve.
