¿Y cuanto duran tus transacciones?

Mientras miraba de reojo un servidor de aplicación funcionando observo el mensaje "Begin transaction module bla bla..", le presto un poco de atención y me pongo en espera  del "Commit transaction.....". (Este servidor de aplicación va logueando en pantalla algunas de las tareas que va realizando).
Sucede entonces que los segundos pasan y nada....y pasan y nada, y de repente "Commit transaction". ¿Que paso acá? La base de datos no esta sobrecargada, yo la monitoreo, ¿Como puede tardar tanto una transacción ? Nos han enseñado una y otra vez que las transacciones deben ser cortas, tan cortas como sea posible. Cuando profundizo en el tema veo con horror los siguiente, esta transacción abarca entre 6 y 10 tablas y ante una situación anormal (Bastante improbable por suerte) la aplicación comienza a preguntar al usuario si quiere resolverlo de tal o cual manera, y mientras tanto la transacción abierta. Problema encontrado, problema solucionado y ahora acá viene el tema ¿Esta esto pasando en varios lugares o fue esta la única "patinada" de toda la aplicación? ¿Como saberlo?

En la entrada
http://pablosoligo.blogspot.com/2011/06/dbexpress-trace.html
se explico como llevar a una tabla de log las operaciones que realiza DBExpress con la base de datos, entre esas operaciones están los begin transaction/commit/rollback entre otras muchas cosas. ¿Y si sacamos la diferencia de tiempo entre un begin transaction y su correspondiente commit/rollback? podriamos ver si hay irregularidades, incluso podemos ordenar la cosa y saber cuales son las que mas demoran.
Desgraciadamente quien les escribe no sabe ni investigo como pedirle al DBExpress o al sqlserver el numero de transaction si es que existiera, tampoco tenemos en la tabla un campo que una un begin transaction con su commit/rollback, por tanto tendremos que usar las neuronas un poco mas.
La siguiente consulta es la base sql que podría resolver el misterio,



select DateDiff(millisecond, s1.FechaHora, s2.FechaHora) as 'Demora', *
from SqlLog as s1 inner join SqlLog as s2
On s1.Module=s2.Module and s1.Login=s2.Login
Where (s1.Message like 'OLEDB - StartTransaction') and
  (s2.Message like 'OLEDB - Abort' or s2.Message like 'OLEDB - Commit')and
  (s2.IdSqlLog>s1.IdSqlLog) and
  (s2.IdSqlLog<(
   Select top 1 IdSqlLog
   from SqlLog as i
   Where i.Login=s1.Login and
     i.Module=s1.Module and
     i.IdSqlLog>s1.IdSqlLog and
     i.Message like 'OLEDB - StartTransaction'
   Order by i.IdSqlLog))


Traducido lo que hace es un join de la tabla de log con sigo misma juntando por Module y login, esto es porque es una aplicación multicapa, en una aplicación Cliente/Servidor una campo hostname en la tabla de log soluciona el problema del join.
Hecho el join busca un begin transaction y para ese busca o un commit o un rollback cuidando de que el idLog sea mayor y que no exista ningún otro begin transaction en el medio (Begin transaction del mismo Login/Module o hostname según corresponda).
Mañana estaré probando esto en un entorno de producción, con datos reales
WARNING
No hace falta pedir el plan de consulta para ver que esta consulta es explosiva especialmente en una tabla que crece sin descanso y que se puede volver gigante en un par de días

Así que mucho cuidado, ejecutarla sobre un set de datos pequeño o en un servidor de testing.