Surviving the Night

Roar: Inserciones Masivas en MongoDB vs SQL Server (IV)

Pablo Alvarez — Tue, 22 Nov 2011 15:24:24 GMT

Me alegra comprobar que, al parecer, el pequeño reto que nos traemos Unai y yo está provocando cierto interés; más allá de haber conseguido que el de Monforte y yo nos hayamos tenido que rascar el bolsillo e invitarnos el uno al otro a varias cenas, algo de debate si que se ha generado en twitter, llegando a contar incluso con alguna prueba similar en otra plataforma!(*)

Para quien no haya leído la entrada anterior, o la respuesta de Unai, os recuerdo brevemente las reglas de nuestra improvisada apuesta:

El ganador será aquel de nosotros dos que sea capaz de insertar 500.000 filas (documentos, en su dialecto) compuestas por un GUID y una cadena de 20 caracteres (no unicode). Recordaros que la solución bcp ha sido declarada ilegal, para que Unai siga manteniendo alguna opción de victoria ;)

Lo cierto es que no tenía pensado publicar nada mas avanzada la semana. Sin embargo, me ha surgido un imprevisto viaje a la pérfida Albión este fin de semana para participar en una taskforce de rendimiento (yeah!), y he tenido bastantes ratos libres entre viajes y transbordos. No se me ocurrían muchas maneras mejores de ocupar este tiempo que compartiendo mi siguiente solución al reto, así que ahí vamos!

Descargo de Responsabilidad: Al igual que hice en la entrada anterior, voy a tratar de volver a cubrirme las espaldas frente a conversaciones que deriven en fanatismos. Siempre que escribo acerca de una tecnología ajena al ecosistema de Microsoft acabo con problemas de fanatismos y guerras de religión. Por ello, dejadme que deje muy claro que este post solo pretende contar la historia de un pique interesante con un compañero, así como tratar de aprovechar la ocasión para comentaros un par de técnicas no triviales para realizar cargas rápidas de datos en SQL Server. Vaya por delante que MongoDB me resulta un producto más que interesante y con escenarios para los que es más idóneo que una base de datos relacional.

NOTA: Si alguien esta leyendo mi blog de modo secuencial y nota la ausencia de una entrada llamada ‘Inserciones Masivas en MongoDB vs SQL Server (II)’, esto es porque esta entrada la ha realizado Unai en su blog, y podéis acceder a ella aquí. De hecho, os recomiendo encarecidamente que la leáis incluso en el caso de que no estéis particularmente interesados en MongoDB o bases de datos NoSQL.

(*): El amigo Javier Torrecilla hizo la prueba en Oracle, aunque me niego a dar los resultados! ;) Por otra parte, aun esperamos la versión en WP7 de Yeray!!! En el factor rendimiento no creo que nos gane ni a SQL Server ni a MongoDB, pero lo que es en cool factor nos va a dar una paliza.

¿Por dónde íbamos?

Si recordáis la entrada anterior, mis esfuerzos de inserción ya no eran capaces de aprovechar mejor los procesadores, a pesar de que no se encontraban aún al máximo; mi cuello de botella se había desplazado a otros lugares, y se materializaba en el lado de SQL Server mediante esperas por dos tipos de eventos concretos (WRITELOG y PAGELATCH_EX) como muestra la siguiente captura:

El tener casi un 50% de las esperas globales en WRITELOG evidencia el uso masivo del log de transacciones por las inserciones. Recordemos que, al contrario que con la escritura de los datos, esta operación es síncrona. A priori poco más podemos hacer de este lado, a no ser que recurriéramos a un escenario de BULK INSERT mínimamente logado, pero lamentablemente esta opción viola las reglas del concurso. Doh… estúpidas reglas!

¡Vamos a ver si la otra espera nos da alguna pista! La espera es por el tipo PAGELATCH_EX, que se trata de una vieja amiga mía. De todos modos, en caso de que os encontréis con alguna espera que no conozcáis, las tenéis casi todas listadas en la entrada relacionada a sys.dm_os_wait_stats de los Books Online… o en vuestro buscador favorito! ;) La respuesta de la documentación para esta espera es la siguiente:

PAGELATCH_EX : Occurs when a task is waiting on a latch for a buffer that is not in an I/O request. The latch request is in Exclusive mode.

Lo que sucede es que al hacer tantas inserciones de modo concurrente, la ultima pagina del heap sufre de contención, lo que limita seriamente nuestra capacidad para hacer inserciones.

¿Que podemos hacer para reducir la contención de esperas PAGELATCH_EX? Aquí viene el momento genial, pero absolutamente contraintuitivo, de esta entrada del blog:

<drum roll>

Vamos a particionar la tabla sobre la que vamos a hacer las inserciones.

</drum roll>

¡¿Particionar la tabla para las inserts?! Se te pira…

Eso es lo que pensé la primera vez que escuché esta técnica; todos estamos más que habituados al particionado de tablas pensando en las mejoras administrativas que nos proporcionan y, como no, de rendimiento a la hora de realizar búsquedas debido a la eliminación de particiones, la menor altura de los índices, etc…. ¿Pero, mejoras en inserciones?

Os podéis imaginar como me quede cuando leí por primera vez acerca de la idea de particionar una tabla para optimizar la carga de datos en un artículo de Thomas Kejser; sin embargo, tiene sentido. Ahora os estoy escuchando a algunos pensar…

¿¡pero que hardware tiene tu portátil?! Si vas a hacer tantas particiones como procesadores (cuatro), ¿no deberías seguir las buenas recomendaciones y poner cada archivo en un disco independiente?

¡Buena pregunta! (y tanto… ¡como que me la he hecho yo a mi mismo! ;)) Pero daros cuenta de un detalle: la contención NO está en el disco, sino en las estructuras internas de SQL Server de la tabla. Lo que pretendo con esto no es optimizar el acceso a disco, sino la sobrecarga que tiene SQL Server cuando tiene varios hilos tratando de insertar en la misma tabla. Al particionarla, estas esperas se reducen, y ese es nuestro objetivo (PAGELATCH_EX).

De cara a realizar este particionado, vamos a realizar un pequeño cambio a mi tabla que, evidentemente, consensué con Unai previamente. De hecho, a priori, este cambio me pone en una situación mas comprometida, ya que implica agregar un campo nuevo (de tipo TINYINT y al que llamaré Hash aunque realmente no es tal…), así como un índice clustered sobre el ID y este nuevo campo.

La siguiente pregunta es: ¿cuantas particiones crear sobre la tabla? En este punto no he sido muy profesional, para ser sinceros: solo he hecho una prueba por el momento, con 8 particiones. Escogí este valor un poco por intuición; mi maquina tiene 4 núcleos reales, y consideré que 8 particiones deberían ser un numero apropiado para poder jugar un poco con la ociosidad de las tareas y minimizar el signal_wait_time. De todos modos, si encuentro algo más de tiempo, trataré de hacer al menos un par de escenarios mas con diferente número de particiones.

Como ya comentamos antes, todas estas particiones apuntaran al mismo filegroup y fichero, por lo que en realidad no se trata de paralelizar las escrituras en ficheros o unidades diferentes; una vez mas recuerdo que solo pretendemos reducir la contención en las estructuras internas de SQL Server.

Así pues, nuestro particionado quedaría tal y como muestra el siguiente diagrama:

A continuación os muestro el script de creación de mi nueva tabla, así como la función y esquema de particionado que he empleado, y el nuevo índice clustered:

CREATE PARTITION FUNCTION pf_hash (TINYINT) 
AS RANGE LEFT FOR VALUES 
(0x00, 0x01, 0x02, 0x03, 0x04, 0x05, 0x06, 0x07)

CREATE PARTITION SCHEME ps_hash
AS PARTITION pf_hash TO ([ALL])
GO

CREATE TABLE dbo.Test
(
    ID uniqueidentifier NOT NULLDEFAULT NEWID(),
    Payload varchar(20) NULL,
    Hash tinyint NOT NULL
) ON ps_hash(Hash)

CREATE UNIQUE CLUSTERED INDEX CIX_Hash 
ON dbo.Test (ID ASC, Hash ASC) ON ps_hash(Hash)

Además del particionado, voy a adelantarme a un potencial problema de contención de bloqueos en la tabla asegurándome que mi índice no permita bloqueos de pagina ni fila, y estableciendo la política de escalado de bloqueos de la tabla a Auto:

ALTER INDEX CIX_Hash ON dbo.Test
SET (ALLOW_PAGE_LOCKS = OFF, ALLOW_ROW_LOCKS = OFF)

ALTER TABLE dbo.Test SET (LOCK_ESCALATION = AUTO)

El código de la prueba es similar a la versión anterior, pero agregando el código hash a cada una de los Tasks, de modo que cada Task enviará sus inserts a una partición diferente:

        private static void DoWork(int hash)
        {

            int countIterations = 0;
            while (countIterations < 63)
            {
                using (SqlConnection conn = new SqlConnection(connStr))
                {
                    conn.Open();

                    using (SqlCommand cmd = new SqlCommand())
                    {
                        cmd.Connection = conn;

                        int countValues = 0;
                        var builder = new StringBuilder();

                        builder.Append("INSERT INTO Test(Id,Payload, Hash) VALUES ");

                        while (countValues < 1000)
                        {
                            builder.Append("(NEWID(), REPLICATE('X',20), ");
                            builder.Append(hash.ToString());


                            if (countValues != 999)
                                builder.Append("),");
                            else
                                builder.Append(")");

                            countValues++;
                        }

                        cmd.CommandText = builder.ToString();
                        cmd.ExecuteNonQuery();
                        countIterations++;
                    }
                }
            }
        }

Y todo esto.. ¿para que?

Solo hay una respuesta a esta pregunta: para derrotar, y humillar si cabe, a Unai y su MongoDB :P Vamos a ver si lo hemos conseguido!

Bueno, en este caso no me entretendré demasiado con los resultados; simplemente os diré que después de los cambios consigo la inserción de los 500.000 registros en 1,8 segundos estables.

Esta solución esta ligeramente por detrás de los 1,6 segundos del MongoDB de Unai, pero aun así me siento muy satisfecho porque es muy estable en tiempos y, bueno… si miro atrás al primer día del reto, no creía que pudiera bajar de los 20 segundos!

Aun así, ya estoy trabajando en la siguiente idea… No se si será mas rápida, pero os garantizo que es bastante espectacular! ;)

Conclusiones:

A pesar de que aún falta lo más importante, el cara a cara final sobre el mismo metal, parece que ya podemos ir obteniendo algunas conclusiones buenas:

Para empezar, y contra todo pronóstico (al menos por mi parte), parece que en esté escenario concreto SQL Server puede plantar cara a MongoDB. Aún tengo un as en la manga, pero incluso en el caso de que finalmente SQL Server salga derrotado en este pequeño juego, ya me resulta increíble estar en el mismo orden de magnitud de tiempos, así que no digamos estar en una situación tan reñida y con posiciones de victoria.
Aun no llegamos al limite de nuestras CPUs en este escenario; estoy convencido de que algo más podremos hacer… y aquí entra en juego mi as en la manga.
En este caso hemos tratado de mejorar las esperas que no se corresponden con las entradas en el log de transacciones; ¿podríamos mejorar este otro frente, que supone el otro 50% del tiempo en nuestro escenario original? Esta parte es mas difícil, por no decir imposible si no podemos realizar el proceso con operaciones mínimamente logadas (BULK), así que no creo que podamos ganar nada por ahí sin hacer trampas a Unai.

Igual que hice en la ocasión anterior, os voy a dejar una pista de lo que será mi siguiente intento para mejorar el rendimiento en las inserciones; solo os diré que voy a tratar de reducir las esperas por SOS_SCHEDULER_YIELD :)

Cuando publiquemos los resultados definitivos, publicaremos también el código de ambas implementaciones; me encantaría que alguien mas se animara a realizar las pruebas y extraer conclusiones!

Por último, quizá sea interesante reflexionar si realmente es necesario tanto esfuerzo para ganar, en este caso, simplemente dos segundos.

Keep Rockin’!

Rock Tip:

“Ready to Roar, ready to rock, ready to give it all I’ve got” reza el estribillo de ‘Roar’, uno de os temas más espectaculares del increíble ‘Coup de Grace’, el último disco de la ya venerable banda de Hard Rock melódico sueca Treat.

Y eso es precisamente lo que me dije a mi mismo cuando Unai y su MongoDB empezaron a apretarme las tuercas! Ready to give it all I’ve got! De hecho, este disco me estuvo acompañando durante gran parte de las pruebas que iba realizando; debería poner al final un grupo de los artistas, discos y temas involucrados en todo el reto ;)

Hot: Inserciones Masivas en MongoDB vs SQL Server

Pablo Alvarez — Thu, 17 Nov 2011 02:09:00 GMT

Esta semana estoy en San Sebastián, impartiendo una pequeña formación sobre optimización de SQL Server. A priori, la semana se presentaba tranquila y con gran carga turística al tratarse de la primera ocasión que visito esta ciudad, y mi predilección general por estas tierras del norte.

Lamentablemente, todos mis planes se torcieron tan pronto como descubrí que Unai estaba en la misma ciudad que yo. Como no podía ser de otro modo, ente pintxo y pintxo nuestros temas técnicos favoritos empezaron a surgir en nuestras conversaciones. Y, como cualquiera que conozca a nuestro Unai podrá intuir, no pasó demasiado tiempo antes de que MongoDB secuestrara todos nuestros hilos conversacionales y se convirtiera en nuestro particular trending topic, por delante de otras apasionantes cuestiones como la entropía de la demografía en el postmoderno barroco, o el peculiar criterio que tengo a la hora de escoger mis guitarras.

He de confesar que no recuerdo muy bien la cadena de acontecimientos que nos condujo a la historia que os voy a contar; quizá fuera mi falta de conocimiento respecto a este producto tan de moda (MongoDB), o el número de zuritos que nos habíamos tomado… No lo acabo de tener muy claro, pero el hecho es que, de algún modo, me metí de lleno en un juego/apuesta que acabaría con el escaso tiempo libre que me quedaba a lo largo de la semana.

La Apuesta

Las reglas eran muy sencillas: el ganador sería aquel de nosotros dos que fuera capaz de insertar una carga de trabajo acordada previamente en menos tiempo. Él con su MongoDB de marras, y yo con mi viejo, fiable, pero no siempre bien ponderado SQL Server 2008 R2, ¡como no!

Tras duras negociaciones de paz, Unai y yo llegamos a un acuerdo para evitar emplear armas de destrucción masiva; por este motivo finalmente decidimos no evaluar la que es, de lejos, la manera más rápida de insertar datos en SQL Server: las Bulk Inserts.

La carga de trabajo que nos pusimos de objetivo fue 500.000 registros, cada uno conteniendo un GUID y 20 caracteres textuales (no unicode).

Descargo de Responsabilidad: Siempre que escribo acerca de una tecnología ajena al ecosistema de Microsoft acabo con problemas de fanatismos y guerras de religión. Por ello, dejadme que deje muy claro que este post solo pretende contar la historia de un pique interesante con un compañero, así como tratar de aprovechar la ocasión para comentaros un par de técnicas no triviales para realizar cargas rápidas de datos en SQL Server. Vaya por delante que MongoDB me resulta un producto más que interesante y con escenarios para los que es más idóneo que una base de datos relacional.

Construcción del Entorno de Prueba

En entorno de prueba inicial consistió simplemente en una base de datos que contiene la tabla sobre la que vamos a insertar nuestros 500.000 registros. La única preparación inicial que he realizado de cara a mejorar un poco el rendimiento ha sido dimensionar de modo apropiado los ficheros (para evitar autocrecimientos por uso del log de transacciones en las inserciones) y establecer el modelo de recuperación a SIMPLE.

A continuación os dejo el script inicial, aunque como veréis más adelante hemos realizado algún que otro cambio:

CREATE DATABASE DemoInserts ON PRIMARY 
( 
    NAME = 'DemoInserts', 
    FILENAME = 'c:\Databases\DemoInserts.MDF', 
    SIZE = 200, 
    FILEGROWTH = 10% 
) 
LOG ON 
( 
    NAME = N'DemoInserts_Log', 
    FILENAME = N'c:\Databases\DemoInserts_Log.LDF', 
    SIZE = 200, 
    FILEGROWTH = 10% 
) 
GO 
ALTER DATABASE DemoInserts SET RECOVERY SIMPLE 
GO 
USE DemoInserts 
GO 
CREATE TABLE [Test] 
( 
    ID UNIQUEIDENTIFIER NOT NULL DEFAULT NEWID(), 
    Payload VARCHAR(20) NULL, 
)

¡Vamos a Insertar Filas!

La primera solución consistirá en un simple bucle de 500.000 ejecuciones, en el que para cada iteración insertamos una fila. Su única ‘optimización’ fue el empleo de la opción NCOUNT ON para evitar saturar el output buffer con los típicos mensajes de (1 row affected), tal como se puede ver en el siguiente fragmento de código:

SET NOCOUNT ON

DECLARE @cont INT 
SET @cont = 0

WHILE (@cont < 500000) 
BEGIN 
   INSERT INTO Test(ID, Payload) VALUES (DEFAULT, REPLICATE('X', 20)) 
   SET @cont = @cont + 1 
END

El tiempo de ejecución de la inserción en mi equipo fue de 3 minutos y 8 segundos.

NOTA: Todos los tiempos tomados en este artículo se han calculado realizando el promedio de tres ejecuciones sucesivas.

Evidentemente, desde antes de realizar esta prueba yo era consciente de que este mecanismo no iba a arrojar buenos resultados, pero me serviría para tener una línea base respecto a la que poder evaluar las mejoras posteriores y para hacerme una idea respecto a lo que podría esperar de SQL Server.

Llegados a este punto le comenté a Unai que me daría con un canto en los dientes si era capaz de bajar mi tiempo de inserción por debajo de los 20 segundos. Mi amigo y competidor me corrigió, asegurándome que sería él mismo quien se encargaría de darme con el susodicho canto en toda mi dentadura si conseguía tal hazaña. Creo que en ese momento empecé a tomarme nuestra pequeña competición en serio ;)

Manos a la Obra… ¿Dónde esta mi cuello de botella?

Siempre hay un cuello de botella; ¡siempre! Aunque el rendimiento sea excelente, siempre hay un factor limitante, y solo uno. En este caso, un vistazo rápido al Task Manager me permitió ver que la CPU no eran en este caso el problema:

Esto me dio una buena idea para el siguiente intento: realizar una pequeña aplicación en C# que se encargara de lanzar INSERTS modo masivo en paralelo, usando múltiples hilos, para tratar de aprovechar al máximo las cuatro CPUs de las que dispone mi equipo de pruebas.

A continuación os pongo el código exacto que he empleado para esta prueba, aunque casi me da vergüenza ;) No me juzguéis por él, es solo un ejemplo ‘quick and dirty’!:

using System;
using System.Collections.Generic;
using System.Linq;
using System.Text;
using System.Threading.Tasks;
using System.Data.SqlClient;
using System.Diagnostics;

namespace ConsoleApplication5
{
    class Program
    {

        static void Main(string[] args)
        {
            Stopwatch watch = Stopwatch.StartNew();

            var mainTask = new TaskFactory().StartNew(() =>
            {
                new Task(() => DoWork(125000), TaskCreationOptions.AttachedToParent).Start();
                new Task(() => DoWork(125000), TaskCreationOptions.AttachedToParent).Start();
                new Task(() => DoWork(125000), TaskCreationOptions.AttachedToParent).Start();
                new Task(() => DoWork(125000), TaskCreationOptions.AttachedToParent).Start();
            });

            mainTask.ContinueWith((t) =>
            {
                watch.Stop();
                Console.WriteLine(watch.Elapsed);
            }, TaskContinuationOptions.OnlyOnRanToCompletion);

            Console.ReadLine();
        }

        private static void DoWork(int rows)
        {
            string connStr = "Data Source=.;Initial Catalog=DemoInserts
;Integrated Security=true;Application Name=TestInserts";

            int countIterations = 0;
            while (countIterations < rows)
            {
                using (SqlConnection conn = new SqlConnection(connStr))
                {
                    conn.Open();

                    using (SqlCommand cmd = new SqlCommand())
                    {
                        cmd.Connection = conn;
                        cmd.CommandText = "INSERT INTO Test(Id,Payload) VALUES (NEWID(), REPLICATE('X',20))";
                        cmd.ExecuteNonQuery();
                        countIterations++;
                    }
                }
            }
        }
    }
}

Como podéis ver, el código simplemente instancia 4 tareas (una por cara núcleo disponible en mi máquina). Estas tareas reciben el número de filas a insertar, y proceden a realizar estas inserciones como comandos SQL dentro de un bucle.

La inserción de las dichosas 500.000 filas por este mecanismo se produjo en 1 minuto y 7 segundos; si bien el valor no está nada mal en términos de mejora, sabía que aún me quedaba mucho para tener un tiempo competitivo. Una nueva visita al Task Manager me hizo darme cuenta rápidamente de que, si bien había aumentado mucho mi consumo de CPU, aparentemente aún disponía de mucho margen adicional:

A la vista de esto, decidí probar a aumentar el número de hilos empleados para lanzar las sentencias INSERT, y monitorizar tras cada prueba tanto la duración de la misma como la utilización de los procesadores durante el transcurso de las inserciones. De este modo pude lograr grandes usos del procesador, pero es importante tener presente una cuestión: el incremento de la actividad de CPU no implica necesariamente un mejor rendimiento en las inserciones.

Para demostrar este punto, os adjunto una pequeña gráfica que muestra los tiempos obtenidos en función del número de hilos empleados:

(Atiende que graficazaaa… ¿verdad que una de estas ayuda a darle un look más profesional a cualquier artículo? ;))

Como se puede apreciar, el sweet spot de este proceso de inserción en mi equipo se encuentra en los 8 hilos, con un tiempo de ejecución de 43 segundos. A continuación os muestro la gráfica de uso de CPU de esta ejecución, para que podáis contrastarla con la primera de todas y apreciéis el notable incremento en la utilización que hemos logrado:

¿Por donde seguimos ahora?

Bien, llegados a este punto ya tenía mas o menos claro el punto más idóneo de paralelismo desde el lado de la aplicación C# de inserciones, pero no conocía lo que estaba sucediendo por parte de SQL Server. Por esto, decidí estudiar las esperas del servidor; borre las estadísticas de esperas, lancé el proceso y a su finalización, use el celebérrimo script de Glenn Berry, personalizado por Paul Randal para la agregación de información de esperas por recursos en SQL Server.

El resultado de la prueba, si bien era de esperar, resulta revelador:

Como se puede ver, un 99.22% del tiempo total de la prueba se destino a realizar entradas en el log de transacciones; esto se debe al hecho de que las inserciones, salvo casos muy puntuales en escenarios de BULK INSERT, son operaciones completamente logeadas. Dicho a lo bestia: por cada inserción, a parte del dato en si, hay que escribir la intención de realizar la inserción previamente en el log de transacciones. Esta operación es síncrona, y es la que esta provocando una gran cantidad de esperas.

Para tratar de remediarlo, se me ocurrió tratar de reducir el número de cláusulas INSERT que enviamos al servidor mediante las sentencias de inserción múltiples de SQL Server 2008, que nos permiten insertar en el mismo statement hasta mil filas(*). Ya sabéis, algo así:

INSERT INTO Test(ID, Payload) VALUES
(NEWID(), 'AAA'),
(NEWID(), 'BBB'),
...
(NEWID(), 'XXX')

Modifique un poco la aplicación para realizar estas sentencias, quedando el código del siguiente modo:

using System;
using System.Collections.Generic;
using System.Linq;
using System.Text;
using System.Threading.Tasks;
using System.Data.SqlClient;
using System.Diagnostics;

namespace ConsoleApplication5
{
    class Program
    {

        static void Main(string[] args)
        {
            Stopwatch watch = Stopwatch.StartNew();

            var mainTask = new TaskFactory().StartNew(() =>
            {
                new Task(() => DoWork(), TaskCreationOptions.AttachedToParent).Start();
                new Task(() => DoWork(), TaskCreationOptions.AttachedToParent).Start();
                new Task(() => DoWork(), TaskCreationOptions.AttachedToParent).Start();
                new Task(() => DoWork(), TaskCreationOptions.AttachedToParent).Start();
                new Task(() => DoWork(), TaskCreationOptions.AttachedToParent).Start();
                new Task(() => DoWork(), TaskCreationOptions.AttachedToParent).Start();
                new Task(() => DoWork(), TaskCreationOptions.AttachedToParent).Start();
                new Task(() => DoWork(), TaskCreationOptions.AttachedToParent).Start();
            });

            mainTask.ContinueWith((t) =>
            {
                watch.Stop();
                Console.WriteLine(watch.Elapsed);
            }, TaskContinuationOptions.OnlyOnRanToCompletion);

            Console.ReadLine();
        }

        private static void DoWork()
        {
            string connStr = "Data Source=.;Initial Catalog=DemoInserts;Integrated Security=true;
Application Name=DemoInserts";

            int countIterations = 0;
            while (countIterations < 63) // 63
            {
                using (SqlConnection conn = new SqlConnection(connStr))
                {
                    conn.Open();

                    using (SqlCommand cmd = new SqlCommand())
                    {
                        cmd.Connection = conn;

                        int countValues = 0;
                        var builder = new StringBuilder();

                        builder.Append("INSERT INTO Test(Id,Payload) VALUES ");

                        while (countValues < 1000)
                        {
                            builder.Append("(NEWID(), REPLICATE('X',20)) ");

                            if (countValues != 999)
                                builder.Append(",");

                            countValues++;
                        }

                        cmd.CommandText = builder.ToString();
                        cmd.ExecuteNonQuery();
                        countIterations++;
                    }
                }
            }
        }
    }
}

Con esta nueva versión, usando ocho hilos, baje el tiempo a… (redoble de tambor, por favor) 4 segundos escasos!!!!

Llegados a este punto me sorprendí yo mismo; no creí que pudiera bajar tanto el tiempo de estas inserciones, y por primera vez vi peligrar mi dentadura ;) Como me encanta tener datos y números de cada mejora que voy logrando, volví a lanzar la prueba y consulté las estadísticas de esperas del servidor durante el tiempo de ejecución de la misma:

Como podéis ver, el hecho de agrupar las inserciones en batches ha hecho milagros! ahora mismo el servidor esta dedicando aproximadamente el mismo tiempo a escribir en el log de transacciones que en en resolver bloqueos de latches, una situación más normal, y que ha repercutido de manera espectacular en el rendimiento de estas inserciones.

(*): Por si alguien se lo pregunta, yo tampoco tengo ni puñetera idea de por qué el hard-limit de mil filas.

Y por hoy ha estado bien, ¿no? ;)

Con esta entrada he buscado abriros un poco el apetito y, con un poco de suerte, picar a alguien más para que entre al pequeño juego que tenemos Unai y yo. He explicado mis aproximaciones iniciales, pero me reservo para la siguiente entrada la solución ‘buena, buena’ desde el lado del SQL Server.

Para los mas ansiosos os iré adelantando que se basa en particionar la tabla para evitar contención sobre la misma; los detalles de implementación los pondré en mi siguiente post, pero como mis actualizaciones son como los despertares del lazy_writer (ya sabéis, puede ser dentro de 3 milisegundos, o dentro de 3 años!), os he querido adelantar la técnica por si queréis investigarla por vosotros mismos.

A modo de resumen, voy a finalizar con otra gráfica de estas elegantes y vistosas, que hoy tengo el día ejecutivo ;)

Por cierto, si os preguntáis que tal lo hizo MongoDb… vais a tener que esperar a que Unai lo publique en su blog. No obstante, os puedo adelantar que fue capaz de bajar de estos 4 segundos….

...

¡¡¡¡Pero yo también!!!! Muahahahaha!!! ;)

Keep Rockin’!

Rock Tip:

Hacía mucho tiempo que no compartía con vosotros uno de mis rock tips… o mejor dicho, hacía mucho que no compartía nada con vosotros! Tengo el blog muy dejado, pero un servidor no da para más :(

En esta ocasión me traigo a uno de mis descubrimientos del año, los geniales Reckless Love. Banda finlandesa liderada por el increíble Olly Herman, quien fuera vocalista de Crashdiet por una breve temporada y una de las personas con mas carisma y buen rollo que he visto nunca sobre un escenario. Herederos de las mejores raíces del hard rock melódico ochentero, pero con un increíble toque dance y discotequero, puedo afirmar que verles en directo es la experiencia mas cercana a ver al David Lee Roth sin recurrir a un De Lorean con condensador de fluzo.

El tema que he escogido es el single de su segundo (y último hasta la fecha) disco: Hot. No tiene gran relación con la temática de la entrada, pero realmente me apetece compartir este tema con el mundo: si a uno solo de vosotros le hace sentir tan solo una decima parte de lo bien que me sienta a mi escuchar este temazo, ya habrá justificado saltarme mi costumbre de poner temas relacionados.

Forget Me Not: SQL Server Crash Dump Analysis at SQL Bits

Pablo Alvarez — Sat, 30 Oct 2010 22:36:00 GMT

Time flies! It’s been more than six months since I had the chance of speaking about SQL Server crash dump analysis at SQL Bits in London.

As you will understand, for me it was a huge honor to share event with SQL Server heroes like Simon Sabin, Ramesh Meyyappan and, obviously, Connor Cunningham – who came from Redmond to London just to give his lecture on my same slot and leave me with just a handful of attendants which I’m sure were left at my session because they thought Connor was the guy with long hair :)

Luckily, the organizers of the event recorded all the tracks and they are now available freely for everyone at their website, so in case you attended SQL Bits but wasn’t able to attend to my session, or if you were unable to get to SQL Bits at all, just click here and you will be able to see and download my session. By the way, I strongly recommend you to check the rest of the sessions; some of them were really impressive.

Lastly, I would like to send a big ‘thank you’ to all the organizers at SQL Bits. They did a tremendous job to achieve an excellent event, even though several factors were against them – such a little Icelandic volcano that I’m sure many of you will remember :) Thank you guys, you rock!

Rock Tip:

This post’s Rock Tip is ‘Forget Me Not’, one of the biggest hits from the L.A. band Bad English, led by the great voice of John Waite and the unmistakable guitar of Mr. Neal Schon. A great song, released on 1989, which blends the melodic AOR and West Coast style with some bright moments from Neal’s Les Paul.

Why did I choose this song for this post? To begin with, because even though it’s already been a while since this event took place, I won’t forget it for a long time! Not only because I had the chance of meeting great people, speak about something I’m passionate about in an excellent venue and attend some great sessions, but also because I was involved in one of my craziest journeys; trying to reach a customer while all European transport and accommodation system were about to collapse due to the eruption of some Icelandic volcano was definitely one of the highlights of my life! J

On the other hand, the song seemed so appropriate because it was composed and performed by Bad English and… well, let’s say that my English skills used to be a lot better that what is shown on that video; sadly, it was a long time since I had last spoken publicly in English, and that shows on the recording. I just hope it is not so bad that you can’t follow it!

Forget Me Not: Análisis de Volcados de Memoria en SQL Server

Pablo Alvarez — Sat, 30 Oct 2010 21:51:00 GMT

¡Cómo pasa el tiempo! Fue ya hace más de medio año, exactamente el pasado 16 de Abril, que tuve la oportunidad de hablar un poco sobre depuración de volcados de memoria de SQL Server para el diagnóstico avanzado de problemas en la sexta edición del SQL Bits de Londres.

Como os podréis imaginar, para mi fue un inmenso honor compartir escenario con grandes de la talla de Simon Sabin, Ramesh Meyyappan y, sobre todo Connor Cunnigham, Principal Software Architect del equipo del Query Optimizer, que se vino desde Redmond a Londres con el único propósito de dar una charla en el mismo slot que yo y dejarme sin asistentes! ;)

Afortunadamente, la organización del evento grabó todas las sesiones y acaban de ponerlas a disposición de todo el mundo en su pagina web, por lo que si acudisteis al evento pero no pudisteis asistir a mi track, o si Londres os quedaba un poco lejos, aquí podéis ver y descargar mi sesión. Os recomiendo que echéis un vistazo a las mismas, porque muchas de ellas son realmente excelentes.

Por último, me gustaría agradecer a toda la organización del SQL Bits su esfuerzo para lograr un evento tan excelente, a pesar de que muchos factores se alinearon para complicarlo todo…. como cierto volcán islandés que nos dejó a muchos buscándonos la vida para atender nuestros compromisos fuera de Londres, y a otros tratando de llegar a tiempo para dar sus sesiones. Great job, guys…You rock! :)

NOTA: Evidentemente, todas las sesiones están en inglés.

Rock Tip:

En este caso, el rock tip será ‘Forget Me Not’, uno de los grandes exitazos de los angelinos Bad English, liderados por el británico John Waite a la voz y la inconfundible guitarra del señor Neal Schon. Un tema de 1989 que mezcla tan bien ese puntito de caña con el estilo melódico y West Coast que caracteriza a esta banda.

¿Por qué he seleccionado el Forget me Not? Pues para empezar, porque aunque ya hace bastante tiempo, no me había olvidado ni del evento, ni de la charla, ni de las peripecias que me sucedieron en ese viaje; creedme, esas no las olvidaré en la vida… Por otra parte, me pareció apropiado poner un tema de los Bad English, ya que en esa ocasión, como podréis comprobar los que veáis el video, no tenía yo mi mejor día en cuanto a soltura con la lengua de Shakespeare y Tim Minchin

Heaven: Taller de BI con SQL Server 2008R2 en Pamplona

Pablo Alvarez — Tue, 26 Oct 2010 17:48:00 GMT

Los días 3 y 4 de Noviembre voy a tener la oportunidad de impartir un taller sobre Business Intelligence con SQL Server 2008R2 en el Centro de Excelencia de Software de Navarra, lo que supondrá una oportunidad magnífica para darle un repaso al estado del stack de Business Intelligence en la plataforma de Microsoft, comentar algunas cosas interesantes que se pueden hacer con los juguetes nuevos que tenemos a mano (estoy pensando en PowerPivot y en integración con StreamInsight aqui ;)) y, como no, disfrutar un poco de las tierras navarras, su vinito y sus pintxos que tanto me gustan!!

A continuación os dejo la agenda establecida para el curso, para ir poniéndoos los dientes largos :)

Vistazo a la Plataforma de BI de Microsoft
- SSIS, SSAS y SSRS
- Integración con Sharepoint
- Consideraciones de Despliegue e Infraestructura
Introducción a SQL Server 2008 Integration Services
- Desarrollo de Soluciones ETL con SSIS
- Depuración y Gestión de Errores
- Configuración y Despliegue de Paquetes
Introducción a SQL Server 2008 Server Analysis Services
- Desarrollo de Soluciones Multidimensionales con SSAS
- Trabajando con Cubos y Dimensiones
- Trabajando con Hechos y Grupos de Medidas
- Consultando soluciones Multidimensionales
- Personalizando la funcionalidad del cubo (Drilldown, Reports, etc...)
- Introducción a la Minería de Datos
- Mejoras en SQL Server 2008 / SQL Server 2008 R2
Introducción a SQL Server 2008 Server reporting Services
- Creación de Informes Básicos
- Mejorando los Informes Básicos
- Manipulando DataSets
- Empleando Report Models
- Publicación y Ejecución de Informes
- Subscripciones para Distribución de Informes
- Administración del Report Server
- Informes con Código
- Mejoras en SQL Server 2008 / SQL Server 2008 R2
Otras Caracterésticas:
- Clientes: Excel y PowerPivot
- Monitorización de Rendimiento y Estabilidad

Si estáis interesados y tenéis esos días disponibles, no dejéis de visitar la página del Centro de Excelencia de Software de Navarra para consultar la información detallada del evento, así como la forma de registro.

Rock Tip:

Como la mayoría de vosotros sabéis, tengo la costumbre de acompañar cada entrada de este blog con un poquito de buen Rock n’ Roll; me encanta la idea de compartir con vosotros otra de mis pasiones, y quiero creer que en alguna ocasión haya podido descubriros algún grupo interesante. En alguna ocasión ya os comenté que a veces me resulta muy complicado escoger el tema, pues trato de que el título de la canción tenga alguna relación con la parte técnica del post… ¡creedme cuando os digo que esa tarea suele llevarme casi tanto tiempo como escribir la propia entrada!

Lamentablemente en esta ocasión me toca hacer una excepción; la canción escogida ha sido una decisión puramente personal y nada tiene que ver con el contenido técnico del blog. Los que me conocéis puede que sepáis que uno de mis grupos favoritos es Gotthard, una increíble banda de Hard Rock liderada por el simpatiquísimo Leo Leoni a la guitarra y la inconfundible voz y presencia de Steve Lee.

Lamentablemente, el día 5 de Octubre de 2010, la que ya estaba siendo una semana muy dura de por si se terminó de torcer para mí al conocer la noticia del fallecimiento de Steve Lee en un desafortunadísimo accidente de tráfico; solo nos queda el consuelo de que murió cumpliendo un sueño que llevaba planeando muchos años, un viaje interestatal en su Harley Davidson con sus amigos.

Se me ha hecho increíblemente difícil escoger una canción para esta entrada, pero al final me he decantado por una versión con voz en directo de su balada ‘Heaven’, donde seguro que se encuentra ahora cantando con algún ‘Angel’ este auténtico gentleman… Y aunque no acompañe al post, termino dejándoos el último videoclip que grabaron, para el tema ‘Need to Believe’; video que creo que tardaré años en poder ver sin que se me haga un nudo en la garganta…

Algún día le dejaré mi pequeño recuerdo en el paso del Gotardo, pero por ahora sirva este minúsculo homenaje para recordarle: Danke für alles, Steve… du gaben uns tolle Songs… du machte uns lächeln und glücklich seing. Mein Beileid geht an die Familie, Freunde und die Band.

Keep rockin’…

Tell Me Where To Go: Estudio de Consultas AdHoc en SQL Server

Pablo Alvarez — Tue, 27 Jul 2010 15:39:00 GMT

Uno de mis temas favoritos a la hora de dar charlas de rendimiento de SQL Server es el estudio de la cache de planes de ejecución y la presencia de consultas AdHoc. Puedo pasarme horas hablando sobre ello, y contando batallitas… muy a pesar de los pobres asistentes que deben acabar hasta las narices de las consultas AdHoc, de mí, y de mi santa madre :)

Pero no nos engañemos, si me apasiona tanto este tema es porque se trata de un aspecto muy importante de la salud del servidor y de las aplicaciones que le atacan. Y, además, resulta muy fácil comprobar si estamos sufriendo algún problema relacionado con la presencia masiva de consultas AdHoc en el sistema.

Lo curioso es que, a pesar de lo mucho que me gusta y lo importante que es el tema, no le he hecho justicia con artículos en este blog. Y con esto no quiero decir que no haya escrito acerca de ello; aquí podéis encontrar una breve descripción del ciclo de vida de las consultas en SQL Server, y aquí podéis leer sobre la opción de optimización para cargas de trabajo AdHoc en SQL Server 2008.

Sin embargo, creo que nunca he explicado como procedo a estudiar el estado de salud de la cache de planes de ejecución y procedimientos almacenados, así que espero redimirme un poquito con esta entrada.

NOTA: En esta entrada no voy a explicar el qué son las consultas AdHoc, ni el por qué pueden resultar perniciosas desde el punto de vista del rendimiento. Para esta explicación os recomiendo revisar los dos enlaces que os he puesto un poco más arriba. En esta ocasión solo me centraré en el proceso de estudio de estas consultas.

Vistazo General

Una de las maneras más rápidas y cómodas de comprobar si tenemos una elevada presencia de consultas AdHoc en el sistema es mediante los informes del SQL Server Management Studio (SSMS).

Aunque parezca mentira, voy a dedicar un par de párrafos y capturas de pantalla a detallar como localizar estos informes. Con el paso de los años y las charlas es ido aprendiendo que, curiosamente, estos informes son tan potentes como desconocidos. Lo más habitual es que más de la mitad de los asistentes a mis sesiones desconozcan la existencia de los mismos, por lo que aprovecho para presentarlos a quienes aún no los conozcáis.

Dentro de la interfaz del SSMS, y más concretamente, en el menú pop-up (el del botón derecho del ratón) de todos los nodos del Object Explorer, tenemos una opción llamada Reports.

Esta opción es contextual: vamos a tener informes a nivel de instancia, a nivel de base de datos, de usuarios, etc. Evidentemente, hay ciertos tipos de nodos que no tienen ningún informe predefinido, pero siempre podríamos crearnos informes personalizados incluso para los nodos vacíos; son simples ficheros RDLC.

Si bien en esta caso solo vamos a trabajar con un informe concreto, os recomiendo encarecidamente que os deis una vuelta por los informes que vienen predefinidos (Standard Reports), y especialmente por los definidos sobre el nodo de instancia y los definidos sobre los nodos de bases de datos específicas.

En esta caso concreto, nos interesa un informe llamado Server Dashboard, que se encuentra a nivel de instancia. Por tanto, para llegar a él, pinchamos con el botón derecho sobre el nodo de la instancia. Ahí vámos a Reports –> Standard Reports –> Server Dashboard.

NOTA: Esto habituado a trabajar con la versión del producto en inglés, por lo que me vais a perdonar que los pantallazos estén en este idioma, y que no realice las traducciones pertinentes.

Como su propio nombre indica, este informe nos muestra un vistazo general del servidor, con la configuración del mismo, versiones del producto, detalles de actividad, etc. Y, cómo no, también nos deja ver un par de gráficas de tarta que alegran el informe con su vivos colores :P

Estas gráficas muestran el porcentaje de utilización de CPU y de E/S por parte de cada una de las bases de datos del sistema, algo bastante útil para detectar si alguna de las bases de datos está monopolizando los recursos del sistema.

A continuación os muestro, a modo de ejemplo, un pantallazo del informe en mi máquina local:

Si os fijáis, las tareas que más CPU están empleando en mi entorno no son relacionadas con ninguna de las bases de datos presentes (msdb, PerfDW, ReportServer y db_ProcedimientosAdministrativos), sino con tareas AdHoc.

Como podéis ver, un rápido vistazo a este informe nos muestra que podríamos estar experimentando un problema de consultas AdHoc en el sistema, ya que el consumo de CPU de las consultas AdHoc muy es elevado. ¿Quiere esto decir que si en la gráfica no aparece un gran consumo de CPU o E/S por consultas AdHoc, estamos libres del problema?

… pues va a ser que no :)

Cierto es… aunque tengamos muy poca presencia de consultas AdHoc en el diagrama, es posible que las consultas de este tipo sean un problema en nuestro sistema. Desde aquí, haciendo un pequeño esfuerzo, puedo escuchar vuestras voces de incredulidad en la distancia:

- ¡¿Cómo es posible?! (…se oyen las voces desde más alla del Manzanares…)
- Das ist Unglaublich!! (…algun avezado lector desde la puerta de Brandemburgo…)
- Cómo ye, ¡ho! (…estremecedores palabras que oigo entre Mieres y La Moreda…)

¡Muy fácil! Puede ser que el sistema tenga miles de consultas AdHoc, muy livianas, cuya ejecución no es costosa ni en CPU ni en E/S, pero sin embargo genera presión por recompilación, etc.

Entrando en Detalle

Vale, ya sabemos que puede ser necesario investigar un poco más ¿Cómo podemos hacerlo? Yo recomiendo empezar por comparar el ratio entre consultas AdHoc y consultas No AdHoc. A continuación os pongo un ejemplo capturado de un cliente en el que he estado recientemente:

SELECT
COUNT(*)
FROM sys.dm_exec_cached_plans
WHERE objtype LIKE 'Adhoc'

En el caso concreto de este servidor, esta consulta ha devuelto 15636 planes adhoc. ¡No es precisamente un número pequeño de planes de ejecución en la cache! Vamos a ver ahora cuantos planes de ejecución no adhoc hay en la cache:

SELECT
COUNT(*)
FROM sys.dm_exec_cached_plans
WHERE objtype NOT LIKE 'Adhoc'

La consulta anterior nos indica que hay 706 planes de ejecución de consultas no AdHoc. Evidentemente, el ratio entre unas y otras es extremadamente preocupante, y signo evidente de que el sistema está generando constantemente consultas AdHoc.

NOTA: Es difícil dar reglas a seguir en estos casos, pero generalmente puedo decir que si detecto que más del 30% de las consultas de la cache son de tipo AdHoc, considero que hay un problema que investigar respecto a la generación y parametrización de las consultas.

El siguiente paso sería detectar la memoria empleada en planes reutilizados, y en planes no reutilizados, y catalogarlos apropiadamente. En este caso yo utilizo un script, basado en el excelente trabajo de Davide Mauri, que me viene de perlas en estos casos:

WITH Planes AS
(
    SELECT
        Reutilizado = CASE
                        WHEN usecounts > 1 THEN 'Plan Reutilizado (Mb)'
                        ELSE 'Plan No Reutilizado (Mb)'
                      END,
        size_in_bytes AS [Tamaño (Mb)],
        cacheobjtype AS TipoObjetoCache,
        objtype AS Tipo
    FROM
        sys.dm_exec_cached_plans
),
Agregado AS
(
    SELECT
        Reutilizado,
        Tipo,
        TipoObjetoCache,
        [Tamaño (Mb)] = SUM([Tamaño (Mb)] / 1024. / 1024.)
    FROM
        Planes
    GROUP BY
        Reutilizado,
        TipoObjetoCache,
        Tipo
),
Pivote AS
(
    SELECT *
    FROM
        Agregado a
        PIVOT
        ( SUM([Tamaño (Mb)]) FOR Reutilizado IN ([Plan Reutilizado (Mb)], [Plan No Reutilizado (Mb)]) ) p
)
SELECT
    Tipo,
    TipoObjetoCache,
    [Tamaño Reutilizado (Mb)] = SUM([Plan Reutilizado (Mb)]),
    [Tamaño No Reutilizado (Mb)] = SUM([Plan No Reutilizado (Mb)])
FROM
    Pivote
GROUP BY
    Tipo,
    TipoObjetoCache
    WITH ROLLUP
HAVING
    (Tipo IS NULL AND TipoObjetoCache IS NULL ) OR
    (Tipo IS NOT NULL AND TipoObjetoCache IS NOT NULL )

Volviendo al caso de mi cliente, la ejecución de esta consulta devolvió los siguientes resultados:

Como podéis comprobar, en este caso el tamaño no reutilizado es casi similar al listado para los planes reutilizados, lo cual es otro indicativo claro de que hay un gran problema de no reutilización de planes de ejecución debido a consultas AdHoc mal parametrizadas.

Después de comprobar que realmente estamos sufriendo el problema ¿cual sería mi siguiente paso? Pues el más divertido de todos… ¡buscar al culpable! ;)

Para ello, buscaría las consultas que aparecen en la cache, de tipo AdHoc, y cruzaría la vista con la funcion sys.dm_exec_sql_text para poder sacar el texto de la SQL a partir del handle:

SELECT
   refcounts,
   size_in_bytes,
   cacheobjtype,
   text
FROM
   sys.dm_exec_cached_plans
   CROSS APPLY sys.dm_exec_sql_text(plan_handle)
WHERE objtype LIKE 'Adhoc'

Os muestro una salida parcial para que veais el problema (sin mostrar toda la consulta y revelar parte del modelo de datos de mi cliente, evidentmente):

Como se puede ver, las consultas son iguales, variando exclusivamente en los parámetros; el hecho de que sigan recompilandose y no se reutilicen es significativo, y un potencial problema de rendimiento (como ya se comentó en los otros posts).

¡Ya tenemos nuestros culpables! ¡¡Yeah!!

Resumiendo

A modo de resumen, yo abordaría el estudio del siguiente modo:

Revisión del informe Server Dashboard para buscar presencia de consultas AdHoc
Consulta sobre sys.dm_exec_cached_plans para ver el ratio AdHoc/No AdHoc
Consulta para ver la memoria fugada en planes no reutilizados
Si procede, revisar las consultas problematicas.

Fácil, sencillo y para toda la familia :)

Después de ver esta información, tendremos una buena idea de si estamos siendo víctimas de algún tipo de problema derivado de la presencia masiva de consultas AdHoc en nuestro sistema. Si fuera así, habrá que comprobar la presencia de consultas dinámicas sin preparar, consultas sin parametrizar desde el cliente, etc.

Espero que os haya resultado interesante la entrada, y os animo a que probéis en vuestros servidores SQL Server: ¡seguro que más de uno de vosotros se lleva una sorpresa!

Rock Tip:

Los últimos rock tips, si bien han sido temazos, se han alejado un poco de mi corazoncito hardrockero ochentero, así que es buen momento de retomarlo. Y para ocasiones especiales, nada mejor que los grandísimos glam-metaleros noruegos Wig Wam.

Representantes de su país en el festival de Eurovisión de 2005, con el temazo ‘In My Dreams’, en esta ocasión nos quedamos con su balada ‘Tell Me Where To Go’ para acompañar este post.

A todo esto, apuntaros esta fecha en vuestros calendarios: 18 de Septiembre de 2010. Ese será el día que los chicos de WigWam nos visitarán en Madrid por primera vez, en la sala Ritmo y Compás ¡No creí que mis ojos fueran a ver esto! Ya solo queda ver por estas tierras a Steel Panther y seré un hombre plenamente feliz :)

I Know You’re Here: Materiales de Optimizacion de SQL Server en el CIIN

Pablo Alvarez — Mon, 26 Jul 2010 20:35:00 GMT

Aquí os dejo los materiales de la sesión de optimización de SQL Server que tuve la suerte de dar el pasado viernes en tierras cántabras, gracias a la invitación de los chicos del CIIN.

Quiero aprovechar para dar las gracias también a todos los asistentes por las interesantes preguntas y la atención a lo largo de una sesión de más de 5 horas… sé que es duro, y más aún en viernes y, sobre todo, siendo el primer día de las fiestas de Santander! :)

Para los que no hayáis podido ver la sesión el viernes ni presencialmente ni a través de LiveMeeting, pero tengáis interés en la optimización de SQL Server, os dejo aquí el enlace al evento grabado para que lo podáis descargar y ver tranquilamente a vuestro ritmo.

Si se me quedó alguna pregunta por responder, o tenéis más dudas, no dejéis de consultármelas a través del blog o de mi dirección de email!

Rock Tip:

“I Know You’re Here”, del grandísimo Steve Vai, es el tema que he escogido en esta ocasión como Rock Tip. Más que nada porque siempre es un placer ver que la gente sacrifica su tiempo personal por acudir a los eventos de la comunidad, por intentar aprender y compartir. Porque sé que siempre estáis ahi, por eso me pareción un Rock Tip apropiado ;)

¡¿Que decir de Steve Vai?! Creo que a todos los que nos gusta la música y nos apasiona la guitarra nos proporciona el mismo feeling: envidia cochina! XD Sus creaciones te pueden gustar más o menos, pero su estilo, su técnica y su virtuosísmo no te van a dejar indiferente. Como lo describiera Brian May en el concierto de leyendas de la guitarra, en Sevilla en 1991: “.. el genio, el maestro de la guitarra de la era espacial.. mr. Steve Vai”. Ahí es nada.

Pinball Map: Cuidado con los Mapeos en NHibernate

Pablo Alvarez — Tue, 08 Jun 2010 11:25:00 GMT

Ermm… si, chicos y chicas, sonará raro, pero hoy voy a hablar de NHibernate. Sé que me arriesgo a la condenación eterna en las llamas del infierno, pero yo soy así de altruista y me la juego por vosotros! ;)

Uno de los clientes con los que he estado esta semana(*) estaba experimentando problemas de rendimiento en el acceso a datos en su aplicación, sospechando que el causante pudiera ser una vista poco optimizada. Afortunadamente, el cliente tenía muy bien localizada la operativa más costosa, hasta el punto que podíamos llegar con gran facilidad a la consulta problemática, que era la siguiente:

EXEC sp_executesql N'
SELECT
   this_.ID as ID90_0_,
   this_.BorradoLogico as BorradoL2_90_0_,
   this_.Descripcion as Descripc3_90_0_,
   this_.Estado as Estado90_0_,
   this_.VisibleWeb as VisibleWeb90_0_,
   this_.CodigoDB2 as CodigoDB6_90_0_,
   this_.FechaPrevistaInicioComercializacion as FechaPre7_90_0_,
   this_.FechaFinComercializacion as FechaFin8_90_0_,
   this_.Comentarios as Comentar9_90_0_,
   this_.URLFoto as URLFoto90_0_,
   this_.Orden as Orden90_0_,
   this_.URLFotoMiniatura as URLFoto12_90_0_,
   this_.SufijoID as SufijoID90_0_,
   this_.MarcaID as MarcaID90_0_,
   this_.VersionId as VersionId90_0_
FROM
   VistaProblematica this_
WHERE
   this_.CodigoDB2 in (@p0, @p1, @p2, @p3, @p4, @p5, @p6, @p7, @p8, @p9) and
   this_.SufijoID in (@p10, @p11, @p12, @p13, @p14) and this_.BorradoLogico = @p15',
N'@p0 nvarchar(5),@p1 nvarchar(5),@p2 nvarchar(5),@p3 nvarchar(5),@p4 nvarchar(5),@p5 nvarchar(5),@p6 nvarchar(5),@p7 nvarchar(5),@p8 nvarchar(5),@p9 nvarchar(5),@p10 bigint,@p11 bigint,@p12 bigint,@p13 bigint,@p14 bigint,@p15 bit',
    @p0 = N'040 ', @p1 = N'1F7 ', @p2 = N'1G3 ', @p3 = N'209 ',
    @p4 = N'3R3 ', @p5 = N'8S1 ', @p6 = N'8S6 ', @p7 = N'8T4 ',
    @p8 = N'8T8 ', @p9 = N'9AK ', @p10 = 1819, @p11 = 1820, @p12 = 1821,
    @p13 = 1822, @p14 = 3614, @p15 = 0

De un primer vistazo, podemos ver que la consulta esta generada automáticamente por NHibernate. No es que sea inherentemente malo, solo lo digo a título informativo :)

Procedimos a comprobar los tiempos de esta consulta con SET STATISTICS TIME ON:

SQL Server Execution Times:
CPU time = 703 ms, elapsed time = 796 ms.

A la vista del tamaño de filas y la vista, sí que es cierto que el tiempo de ejecución de casi un segundo parece ser demasiado elevado. Por ello, procedimos a analizar el número de operaciones de E/S de cada elemento involucrado en la consulta, mediante SET STATISTICS IO ON:

(50 row(s) affected)
Table 'Worktable'. Scan count 51, logical reads 92037, physical reads 0, read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.
Table 'Versiones'. Scan count 53, logical reads 316, physical reads 0, read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.
Table 'Modelos'. Scan count 106, logical reads 424, physical reads 0, read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.
Table 'Sufijos'. Scan count 9852, logical reads 20996, physical reads 0, read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.
Table 'Colores'. Scan count 10, logical reads 292, physical reads 0, read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.

Como se puede ver, hay bastante actividad de E/S en casi todas las tablas, pero lo que me llamó la atención por encima de todo fue la elevada actividad en las worktables…

¿¡Worktables?! ¡¿Que mi madre es eso?!

Pues las worktables son un concepto muy importante en SQL Server, y a la vez, muy poco conocido. En muchas ocasiones son la causa de la degradación de rendimiento de un procedimiento almacenado al suministrarle diferentes parámetros, el origen de los temidos Sort Warning y Hash Warning, y la raíz de todos los males de la huma… perdón, que me dejé llevar :)

Las worktables en realidad son un mal necesario; no son más que unas tablas temporales que se crean en tempDb para las operaciones de Sort y Hash que no han conseguido suficiente memoria como para hacerlas sobre el Buffer Pool, u operaciones grandes de cursores o tipos de datos LOB… en definitiva, son una solución de emergencia para cuando deseamos realizar una operación que va a requerir gran cantidad de memoria.

Habría muchos ejemplos de su utilización, pero os voy a poner uno muy sencillo: Imaginad que tenemos un procedimiento almacenado para realizar un proceso que hace una JOIN de las filas de dos tablas en un periodo de tiempo determinado. Este procedimiento recibe dos parámetros: fecha de inicio y fecha de fin.

Ahora imaginad que la primera vez que se despliega ese procedimiento, se ejecuta para un rango de un solo día. Ese procedimiento va a compilarse tratando de optimizar la ejecución para ese rango de fechas: SQL Server podría decidir realizar la JOIN mediante un operador HASH JOIN debido a que el número de filas no es demasiado elevado, y reservará la cantidad de memoria justa para realizar la operacion de HASH para esas filas.

Supongamos que al día siguiente, esta consulta se realiza para un rango temporal de un mes entero; SQL Server ya tiene el plan cacheado, por lo que va a tratar de reutilizarlo, pero la asignación de memoria para la operación de HASH era la justa para las filas de un día. Al comenzar a ejecutar la consulta, el procesador de consultas detectará que no tiene memoria suficiente y decidirá terminar la operación sobre una Worktable en TempDb. Esto es mucho más lento, pero al menos garantiza que la operación pueda finalizar.

Volviendo al Turrón:

A la vista de la actividad de E/S en Worktables, decidí confirmar mis sospechas, por lo que adjunté una traza de profiler:

¡Bingo! Podemos comprobar que aparece un evento de Hash Warning al ejecutar la consulta.

Bien, ya sabemos la razón de nuestro problema de rendimiento: el uso de tempDb. Ahora solo nos queda saber por qué esta consulta esta ejecutándose en TempDb.

Después de un par de ideas no muy afortunadas basadas en la recompilación de esa consulta, decidí estudiar los tipos de datos de la definición de esa tabla, para ver si coincidían con los que se pasaban como parámetros en el sp_executesql.

A continuación os muestro las columnas de la vista en cuestion. Permitidme que antes os avise de que lo que vais a ver a continuación puede herir la sensibilidad de más de un desarrollador o arquitecto de datos(**) :)

Como podéis ver, la columna CodigoDB2 está definida como char(5), pero en el código de la consulta que genera NHibernate nos pasa el parámetro como nvarchar(5), lo cual aumenta el peso de la consulta considerablemente, y puede estar provocando que la memoria reservada para la consulta no sea suficiente y tenga que volcar la operación sobre worktables en tempDb.

Hicimos la prueba, cambiando los tipos de datos sobre la consulta generada por NHibernate en el sp_executesql, quedando la misma así:

EXEC sp_executesql N'
SELECT
   this_.ID as ID90_0_,
   this_.BorradoLogico as BorradoL2_90_0_,
   this_.Descripcion as Descripc3_90_0_,
   this_.Estado as Estado90_0_,
   this_.VisibleWeb as VisibleWeb90_0_,
   this_.CodigoDB2 as CodigoDB6_90_0_,
   this_.FechaPrevistaInicioComercializacion as FechaPre7_90_0_,
   this_.FechaFinComercializacion as FechaFin8_90_0_,
   this_.Comentarios as Comentar9_90_0_,
   this_.URLFoto as URLFoto90_0_,
   this_.Orden as Orden90_0_,
   this_.URLFotoMiniatura as URLFoto12_90_0_,
   this_.SufijoID as SufijoID90_0_,
   this_.MarcaID as MarcaID90_0_,
   this_.VersionId as VersionId90_0_
FROM
   VistaProblematica this_
WHERE
   this_.CodigoDB2 in (@p0, @p1, @p2, @p3, @p4, @p5, @p6, @p7, @p8, @p9) and
   this_.SufijoID in (@p10, @p11, @p12, @p13, @p14) and this_.BorradoLogico = @p15',
N'@p0 char(5),@p1 char(5),@p2 char(5),@p3 char(5),@p4 char(5),@p5 char(5),@p6 char(5),@p7 char(5),@p8 char(5),@p9 char(5),@p10 bigint,@p11 bigint,@p12 bigint,@p13 bigint,@p14 bigint,@p15 bit',
    @p0 = N'040 ', @p1 = N'1F7 ', @p2 = N'1G3 ', @p3 = N'209 ',
    @p4 = N'3R3 ', @p5 = N'8S1 ', @p6 = N'8S6 ', @p7 = N'8T4 ',
    @p8 = N'8T8 ', @p9 = N'9AK ', @p10 = 1819, @p11 = 1820, @p12 = 1821,
    @p13 = 1822, @p14 = 3614, @p15 = 0

Tras realizar los cambios, volví a ejecutar la consulta con la información de tiempos y actividad de E/S, y obtuve los siguientes resultados:

SQL Server Execution Times:
CPU time = 78 ms, elapsed time = 78 ms.

(50 row(s) affected)
Table 'Worktable'. Scan count 0, logical reads 0, physical reads 0, read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.
Table 'Colores'. Scan count 10, logical reads 292, physical reads 0, read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.
Table 'Sufijos'. Scan count 2, logical reads 27, physical reads 0, read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.
Table 'Versiones'. Scan count 4, logical reads 22, physical reads 0, read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.
Table 'Modelos'. Scan count 8, logical reads 32, physical reads 0, read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.

¡No está nada mal! Hemos conseguido que la consulta se ejecute diez veces más rápido, sin hacer ninguna modificación real sobre la misma. Toda esa pérdida de tiempo se estaba produciendo por el uso de tempdb como consecuencia de la diferencia entre la memoria estimada y la necesaria.

Al final, el cliente arregló el mapeo del tipo de datos, estableciendo el sql-type de modo explícito, lo que eliminó este problema puntual. La gran noticia es que, con toda seguridad, este cambio en el mapeo afectará a muchas otras consultas, por lo que se espera un incremento generalizado del rendimiento en todas las consultas.

Conclusiones:

Es muy importante garantizar la corrección de los tipos de datos en los mapeos de cualquier solución de persistencia.
Revisad el uso de vuestras tempdb, la creación de worktables y la presencia de eventos de tipo Hash Warning o Sort Warning en vuestros sistemas; es muy posible que os llevéis alguna sorpresa!
Estaba claro que si yo iba a hablar acerca de NHibernate, no iba a ser enteramente para bien… ;)

Keep Rockin’!

(*): Soy perfectamente consciente de lo mal que puede llegar a sonar esa frase!
(**): Tengo que dejarlo claro: el modelo de datos NO es mío!!! :)

Rock Tip:

En esta ocasión, voy a dar un poquito más de caña de lo habitual. Los que seguís este blog y sus Rock Tips(tm) sabéis que casi siempre me decanto por un puntito hardrockero melódico, que es lo que suelo escuchar gran parte del tiempo. Sin embargo, en esta ocasión creo que os voy a sorprender con uno de mis grupos favoritos, aunque son de un palo bastante mas heavy: se trata de los suecos ‘In Flames’, grupo fundado y liderado hasta hace poco por ese genio que es Jesper Strömblad.

Cuando estaba escribiendo este post sobre el mapeo en Hibernate, no pude evitar que se me viniera a la cabeza su tema ‘Pinball Map’; quizá fue simplemente por la palabra map, o quizá porque necesitaba un poco de buen death metal melódico sueco para desintoxicarme de NHibernate xD Sea como sea, me apetece compartirlo con vosotros, así que.. enjoy! ;)

Rainbow In The Dark: Materiales de la sesión de Optimización de SQL Server

Pablo Alvarez — Tue, 01 Jun 2010 18:13:00 GMT

El pasado Jueves 27 tuve la oportunidad de pasar un par de horas muy agradables en compañía de la gente de MAD.NUG, hablando de optimización de SQL Server. En resumen, vine a explicar un poco el proceso que yo sigo a la hora de enfrentarme a un problema de rendimiento en un entorno SQL Server que, en la práctica totalidad de los casos, me resulta desconocido.

Empezamos repasando algunos de los informes básicos que el producto pone a nuestra disposición, para hacernos una idea de la salud general del servidor, y fuimos bajando de nivel y obteniendo más detalle gracias a la utilización de alguna de las muchas DMVs del sistema. Repasamos y explicamos las esperas del servidor (sys.dm_os_wait_stats) y aproveché para contar un par de batallitas sobre optimizaciones extremas mediante la eliminación de CPUs :)

Por último, dedicamos la última parte de la sesión a estudiar algunos escenarios curiosos de rendimiento, como el uso inapropiado de UDFs en los predicados de las consultas, el tan conocido empleo de cursores, los peligros de las consultas Ad Hoc y por último, un escenario muy interesante de ordenación en tempDb por problemas de estimación de memoria y parameter sniffing.

He de admitir que, para ser una sesión de SQL Server, me lo pasé bien! y es que no solo de WinDbg vive el hombre ;)

Aprovecho para dejaros aquí los materiales de la sesión, tanto las PPTs como los scripts que utilicé durante la misma.

Gracias a todos los asistentes (muy buenas preguntas!) y por supuesto, a la organización de Mad.Nug :)

Keep Rockin’!

Rock Tip:

Podría tratar de encontrar algún rebuscado nexo entre el Rock Tip de hoy y el texto del post; como que espero que los consejos que compartí con vosotros os sirvan en alguna ocasión como ese ‘arcoíris en la oscuridad’ para resolver algún problema en vuestros entornos SQL Server, o que algunos de esos scripts valen más que el oro al otro lado del arcoíris…

Pero esta vez no. Esta vez no necesito justificación para mi Rock Tip. Hoy se trata de un homenaje, y para eso no son necesarias excusas. Ronnie James Dio, la voz del heavy metal, el padre de la mano cornuta (los cuernos heavies de toda la vida!) nos abandonó el día 16 del pasado mes. Un hombre que, pese a sus 67 años, seguía subiéndose a al escenario con una tremenda energía, con una voz asombrosa y sobre todo, con unas ganas de entretener y de ganarse el cariño de sus fans noche tras noche.

Se nos ha ido un grande, pero está claro que será recordado siempre por su legión de seguidores desde los años 70, los chavales de hoy y, sin duda, los que vendrán.

Aquí os dejo una versión del “Rainbow In The Dark” en directo en el Wacken de 2004, donde podemos ver que el gran Ronnie James Dio seguía estando como un chaval y disfrutando como si aún estuviera en Black Sabbath allá por 1979!

Looks that Kill: Componentes de DevExpress y ThreadAbortException

Pablo Alvarez — Mon, 31 May 2010 23:12:00 GMT

Aviso a Navegantes: El siguiente post no va a ser políticamente correcto. Es más, creo que este año los chicos de Developer Express Inc. no me van a enviar un jamoncito ni una botella de vino por Navidad, precisamente. Y sin embargo, me siento en la obligación de compartir esto con vosotros… así que ¡allá vamos!

Últimamente he pasado bastante tiempo en tierras Navarras: alegrándome la vista con el verdecito que ya voy echando tanto de menos, disfrutando como un enano de los increibles pintxos de Pamplona y, de cuando en cuando, tirando de WinDbg para resolver algunos problemas de rendimiento que tiene uno de nuestros clientes aquí :)

Y es que en estas semanas he visto muchos escenarios interesantes: las tradicionales fugas de memoria por manejadores de eventos en páginas ASP.NET, problemas con el tamaño de sesión y el histórico de ViewStates, un curioso caso de excepciones indeseadas en cada invocación a un Servicio Web con transacciones que espero poder postear en breve… vamos, ¡que no me he aburrido!

Uno de estos problemas, y uno de los más llamativos, tenía que ver con la increible cantidad de excepciones lanzadas en el frontal web de la aplicación; estamos hablando de varias decenas de miles a la hora! A estas alturas no hace falta que os diga que el mero hecho de lanzar una excepción (aunque esta sea capturada por nuestro código) supone un impacto negativo en el rendimiento, y debemos tratar de evitar estas situaciones.

Si bien el contador de rendimiento # of Excepts Thrown en .NET CLR Exceptions era suficiente para detectar el problema, necesitabamos algo más para averiguar el tipo de excepiones lanzadas y poder investigar mejor el problema real. Como no podía ser de otra manera, ese algo más fue WinDbg :)

Después de adjuntarme al proceso, le pedí a WinDbg que se detuviera cada vez que saltara una excepcion .NET (sxe clr) y que en cada una de ellas, me mostrara la información de la excepción (!pe), la pila de llamadas administrada (!clrstack) y que prosiguiera la ejecución sin manejar la excepción (gn):

sxe –c “!pe; !clrstack; gn” clr

La salida demostró que había dos tipos que conformaban la práctica totalidad de las excepciones:

MissingManifestResourceException:

Esta excepción no me preocupaba demasiado, porque en número era muy inferior a la que veremos a continuación. Sin embargo, es curioso el hecho de que siempre sucedía en unas DLLs de DevExpress.

A continuación os pongo una ocurrencia del problema (omitiendo la pila de llamadas, que en este caso no es relevante):

(d18.11b4): CLR exception - code e0434f4d (first chance)
Missing image name, possible paged-out or corrupt data.
Exception object: 0000000240991ed8
Exception type: System.Resources.MissingManifestResourceException
Message: Could not find any resources appropriate for the specified culture or the neutral culture. Make sure "Resources.DevExpress_XtraScheduler_v9_3_Core.resources" was correctly embedded or linked into assembly "App_GlobalResources.2gule58b" at compile time, or that all the satellite assemblies required are loadable and fully signed.
InnerException: <none>
StackTrace (generated):
<none>
StackTraceString: <none>
HResult: 80131532

Después de revisar la solución, comprobamos que todas las referencias a todas las DLLs de DevExpress estaban aparentemente bien, por lo que decidimos involucrar al soporte de Developer Express en este caso.

ThreadAbortException:

Esta excepción ya suena peor ¿verdad? Hacía no mucho, en este mismo cliente, nos habíamos encontrado con el conocido bug de la plataforma en el método Response.End(), pero…. ¡no adelantemos acontecimientos!

Primero veamos un ejemplo de una de las excepciones que capturamos y su volcado de pila:

(d18.11b4): CLR exception - code e0434f4d (first chance)
Exception object: 0000000200f83940
Exception type: System.Threading.ThreadAbortException
Message: Thread was being aborted.
InnerException: <none>
StackTrace (generated):
SP               IP               Function
000000000911E8E0 0000000000000001 System.Threading.Thread.AbortInternal()
000000000911E8E0 000006427834300A System.Threading.Thread.Abort(System.Object)
000000000911E930 00000642BC9131D6 System.Web.HttpResponse.End()
000000000911E980 0000064281AC2EA6 DevExpress.Web.ASPxClasses.Internal.HttpUtils.EndRespons

StackTraceString: <none>
HResult: 80131530
OS Thread Id: 0x11b4 (23)
Child-SP         RetAddr          Call Site
000000000911e980 00000642803d1965 DevExpress.Web.ASPxClasses.Internal.HttpUtils.EndResponse()
000000000911e9c0 00000642803d049d DevExpress.Web.ASPxClasses.Internal.ResourceManager.ProcessRequest()
000000000911ea80 00000642bc8f2eb0 DevExpress.Web.ASPxClasses.ASPxHttpHandlerModule.BeginRequestHandler(System.Object, System.EventArgs)
000000000911eab0 00000642bc8e449b System.Web.HttpApplication+SyncEventExecutionStep.System.Web.HttpApplication.IExecutionStep.Execute()
000000000911eb10 00000642bc8f2215 System.Web.HttpApplication.ExecuteStep(IExecutionStep, Boolean ByRef)
000000000911ebb0 00000642bc8e3553 System.Web.HttpApplication+ApplicationStepManager.ResumeSteps(System.Exception)
000000000911ec60 00000642bc8e7874 System.Web.HttpApplication.System.Web.IHttpAsyncHandler.BeginProcessRequest(System.Web.HttpContext, System.AsyncCallback, System.Object)
000000000911ecc0 00000642bc8e745c System.Web.HttpRuntime.ProcessRequestInternal(System.Web.HttpWorkerRequest)
000000000911ed50 00000642bc8e608c System.Web.HttpRuntime.ProcessRequestNoDemand(System.Web.HttpWorkerRequest)
000000000911ed90 000006427f602012 System.Web.Hosting.ISAPIRuntime.ProcessRequest(IntPtr, Int32)

Como se puede ver, uno de los métodos de las librerias de DevExpress, DevExpress.Web.ASPxClasses.Internal.HttpUtils.EndResponse está invocando a System.Web.HttpResponse.End(), el cual a su vez lanza una excepción de tipo ThreadAbortException.

Mmm… antes hablabamos de un caso conocido de excepción ThreadAbortException en las llamadas a HttpResponse.End(), así que una rápida busqueda nos lleva al KB312629, que si no conoceis os recomiendo que leais y comprobéis si vuestras aplicaciones se ven afectadas por él.

Una comprobación del código fuente del método de DevExpress (con la siempre inestimable ayuda de .NET Reflector), nos revela que los desarrolladores del producto son conscientes del problema, implementando un catch para el ThreadAbortException:

public static void EndResponse()
{
    HttpContext.Current.ApplicationInstance.CompleteRequest();
    try
    {
        GetResponse().End();
    }
    catch (ThreadAbortException)
    {
    }
}

Sin embargo, esta solución no evita el lanzamiento descontrolado de las excepciones que, como ya se ha comentado, a pesar de ser controladas, siguen teniendo un impacto sobre el rendimiento de la aplicación, ¡por no hablar del ruido que meten a la hora del monitorizar el sistema!

Con esta información en la mano, elaboré un documento detallado (mucho más que este post) para que mi cliente pudiera abrir un caso de soporte con la gente de DevExpress, esperando que resolvieran el problema que nos estaba impactando severamente en producción, mediante la implementación condicional de una llamada a HttpContext.Current.ApplicationInstance.CompleteRequest() en lugar de invocar al método HttpResponse.End().

La respuesta de la gente de DevExpress no se hizo esperar mucho (punto para ellos!), y se resume en lo siguiente:

No van a cambiar el código, ni a dejar la opcion al desarrollador de asumir el cambio con el CompleteRequest.
Del problema de las MissingManifestResourceException simplemente nos comentaron que esas excepciones son esperadas y que no nos preocupemos.
Con las dos respuestas (a todas luces insuficientes y debatibles) llegó la notificación del cierre del caso. Sin derecho a réplica.

En esta ocasion, lo que más rabia me da no es la parte técnica; puedo entender los problemas que tengan para realizar el cambio (aunque no es de recibo que su código levante tantas excepciones), hasta casi puedo entender que su código levanta excepciones buscando recursos localizados inexistentes… pero por lo que no paso es por la dejadez y el mal trato al usuario en el soporte técnico.

Asi que… ¡Avisados estais! :) Vamos a por el mini-resumen del día…

Resumiendo:

¿Habéis monitorizado su vuestra aplicacion tira excepciones? Si no es así, revisad los contadores de rendimiento y tirad de WinDbg… ¡a lo mejor os llevais una sorpresa!
Comprobad si teneis ThreadAbortException, y si es así, evaluad el workaround descrito en el KB.
¿Estais planteandoos adquirir una licencia para controles de usuario para un nuevo proyecto? ¡Aseguraos de tener un buen soporte, no sabeis lo útil que puede llegar a ser!

Keep Rockin’!

Rock Tip:

No podía ser de otra manera, este post solo lo podían presentar los chicos de Mötley Crüe con su “Looks that Kill”. Apropiado, porque en este caso la vistosa interfaz de usuario de la aplicación es la que contiene un pequeño veneno, como hemos visto ;)

Bang Bang!: Optimización Económica en SQL Server

Pablo Alvarez — Tue, 25 May 2010 20:41:00 GMT

Soy un impresentable. No hay manera de que actualice el blog, y cuando lo hago, es para promocionarme de mala manera. Y, como no podía ser de otra manera, esta es una de esas ocasiones :)

Esta vez tengo que agradecer a Gisela, Luis y el resto de chicos de Madrid.NET la oportunidad de pasar un ratito ~~friki~~ serio, formal y productivo hablando de optimización económica de SQL Server. La idea será aprender a localizar de dónde vienen los problemas, en lugar de tratar de optimizar las consultas en base a su duration elevado de modo sistemático… vamos, la venerable metodología ASM (A Salto deMata(tm)).

La primera parte del evento abordará las técnicas de revision que yo suelo emplear en mi trabajo en el equipo DOT de Plain Concepts, mientras que la segunda parte se centrará en una serie de casos particulares de optimización que me encuentro en algunos clientes y que, a pesar de que alguno de ellos es muy frecuente, siguen siendo problemas bastante desconocidos para los que no nos pasamos delante de un SQL Server todo el dia :)

Si el plan os resulta interesante o apetecible, ya sabeis.. ¡nos vemos el jueves! El evento será en las oficinas de Microsoft en La Finca, y los datos del registro los teneis en el siguiente enlace:

https://msevents.microsoft.com/CUI/EventDetail.aspx?EventID=1032451680&Culture=es-ES

Keep rockin’!

Rock Tip:

Hoy me toca hacer algo que no me gusta, y que creo que solo hice en otra ocasión en este blog: voy a repetir un Rock Tip. Y voy a hacer esto por tres razones totalmente justificadas:

El nombre es apropiado… vamos a hacer nuestro el lema de ’Biggest Bang for the Buck’, así que el Bang Bang! nos viene que ni pintado…
Estamos hablando de la que posiblemente sea la mejor canción del mejor grupo de la historia. Punto pelota. xD
El blog es mio y…. mmmm, creo que recurro con demasiada frecuencia a este punto :)

Por todo esto, hoy le ha tocado el turno a Bang Bang, un tema del primer disco de Danger Danger. Si os apetece oir una cancion happy, que anima al instante, probadla. Como la gente que me conoce sabe de sobra, esta banda neoyorkina es mi grupo favorito, así que no me extenderé en detalles porque podría llegar a aburriros :)

Si os interesa la musica de guitarristas para guitarristas, principalmente instrumental, no os perdais los trabajos en solitario de su guitarrista, Andy Timmons, que para mi es el guitar hero con mas estilo que ha parido madre :) Por cierto, el señor Timmons ha estado esta pasada semana en Madrid… así que también lo celebraremos con un temazo suyo: Cry for You.

Photograph: SQL Server Crash Dump Analysis

Pablo Alvarez — Mon, 12 Apr 2010 14:32:38 GMT

Just a small post to remind that this week I’ll be presenting at SQLBits VI, in UK! I’m going to talk about SQL Server crash dump analysis – some post-mortem debugging techniques that help us to discover what went wrong and why our SQL Server crashed, using mostly WinDbg. We will also do a little tour on managed debugging, showing how these techniques and tools can be useful when trying to detect anomalous behaviors on our .NET Applications accessing the database.

It goes without saying that I’m really excited to be able to share event with such an incredible list of speakers! There are other incredible tracks at the same time: Conor Cunningham will come all the way from Redmond to London to share with us some of the internals and secrets the Query Optimizer, James will deliver a very interesting session on sequential I/Os (I wish I could invite some of my customers to that session!) and Satya will share his huge experience with us in a best practices session. With this great sessions at the same time, I understand many of you that could be interested in attending my session won’t be able to! So if you cannot attend my session, just catch me anytime on the venue and I will be more than happy to have a nice chat about post-mortem debugging, WinDbg or whatever… by the way, I’m the one with the cowboy boots and long hair! :)

See you at SQL Bits on Thursday!

Rock Tip:

Each time that I write a new entry on this blog I use to spend a ridiculous amount of time looking for a song that fits the post; you know I don’t want my Rock Tips to be just a bunch of songs that I like without a reason. Well, this time the job was really easy! Think about it: the session is going to be in the UK… so a band from the country is definitely a must. And I’m going to be talking about memory snapshot analysis… about ‘photographs’ of the process memory… so, without further ado, let me introduce you the Rock Tip of the day: Photograph, by Def Leppard.

One of that classic 80’s tunes that I love so much, and definitely one of my fave from this always impressive bands. This time I’ve chosen to link the song to a live performance of the band, and not to the promotional video of the single, so you can enjoy the impressive work on the backing vocals, the acting and the always missed guitar playing of the late Steve Clark.

Just Push Play: Depuración Avanzada (2ª Parte) en Second Nug

Pablo Alvarez — Tue, 15 Dec 2009 02:30:00 GMT

Lo se, lo se… ¡os tengo muy abandonados! y de hecho, la entrada de hoy no va a cambiar mucho la situación, ya que será muy breve; un simple ejercicio de autopromoción :)

Solo quería recordaros que mañana, Martes 15 de Diciembre, tengo el placer de poder dar la continuación del evento de Depuración Avanzada que dí en colaboración con los chicos y chicas de Second Nug.

A continuación teneis los detalles de registro para el evento de mañana:

PISTA: Pinchad en la imagen :)

En el abordaremos alguna demo de depuración con WinDbg que nos quedó pendiente en la primera sesión, así como depuracion con CLR 4.0. Por ultimo, terminaremos echando un vistazo a las neuvas características de depuración de Visual Studio 2010, que son sencillamente espectaculares. De echo, para una vez que escribo, voy a tirar la casa por la vetnana y también os recuerdo el link a la descarga de Visual Studio 2010 Beta 2, para que podais jugar con él :)

Keep Rockin’!!!

Rock Tip:

Ya sabéis, los chicos de Aerosmith están de actualidad por el espectáculo de prensa rosa que están protagonizando últimamente; la útlima barbaridad que yo he escuchado es que Lenny Kravitz quiere sustituir a Steven Tyler a la voz!! Yo me quedo con la idea de que es todo un truco publicitario, la necesidad de hacer un poco de ruido. Y si es así, les ha funcionado porque aqui estoy yo para recordaros a todos lo grande que es esta banda!

En este caso, hemos querido dedicarle el tema Just Push Play… un tema que nos va a venir al pelo al analizar los volcados de memoria desde el Visual Studio 2010, ¡ya veréis! :)

Beat The Bullet: Aplazado el Evento de SQL Server en Coruña

Pablo Alvarez — Thu, 16 Jul 2009 10:28:00 GMT

No os podéis imaginar lo que me fastidia tener que daros esta noticia, pero me he visto obligado a tener que posponer mi sesión de Optimización de SQL Server que los chicos de .NUGG habían organizado en Coruña.

Estamos intentando moverla al Viernes de la semana que viene; se que es precipitado, pero si esperamos más, nos metemos en periodo de vacaciones. Espero editar este post a lo largo de la tarde y daros la confirmación definitiva.

A todos los que estabais apuntados para el evento, por favor, aceptad mis disculpas. A veces estas cosas pasan.

Parece que esa Estrella Galicia va a tener que esperar un poquito :) Keep Rockin’!

Rock Tip:

Como ya sabréis, Beat The Bullet es una expresión que viene a querer decir algo así como ‘aguantar estoicamente cuando algo va mal’, una expresión que ya emplee en otra entrada de este blog, curiosamente para hacer referencia a otra sesión en Coruña. En aquella ocasión, el Beat the Bullet hacia mención al mejor tema del mejor grupo de la historia, el Beat the Bullet de los Danger Danger.

Como no me gusta repetir temas en los Rock Tips, en esta ocasión haré mención a otro temazo con el mismo nombre, el Beat the Bullet de Vain.

Speed of Light: Evento sobre Optimización de SQL Server en Coruña

Pablo Alvarez — Mon, 13 Jul 2009 23:20:00 GMT

Este Viernes 17 voy a tener la oportunidad de volver a pasarme por tierras gallegas. En esta ocasión, los chicos de .NUGG han tenido a bien invitarme a presentar una sesión sobre Optimización de SQL Server, así que antes de nada, permitidme que agradezca a Edu y a Euge su invitación y la organización del evento! Gracias chicos!

Para ser sinceros, esta sesión no deja de ser una deuda contraída con los asistentes a mi última sesión en Coruña sobre Depuración y Optimización con WinDbg. En ella se demostró un claro interés por la optimización de SQL Server, y prometí volver con un temario centrado en exclusiva en este tema. Como lo prometido es deuda, y como necesitaba alguna excusa para tomarme una Estrella Galicia en buena compañía, este viernes nos veremos en Coruña!

Aquí os dejo los detalles de la sesión, a la que os podéis registrar pulsando aquí. ¡¡Nos vemos en Coruña!!

Speed of Light: Optimización de SQL Server

Fecha: viernes, 17 de julio de 2009
Horario: 17:00 - 19:00
Lugar:
- UNIVERSIDADE DA CORUÑA
- Aula 1, Edificio Xoana Capdevielle
- Campus de Elviña s/n A Coruña 15071

Descripción:

Esta sesión está dedicada a detallar las técnicas y herramientas que nos permitirán exprimir el rendimiento de nuestro SQL Server al máximo, haciendo un repaso por la teoría implicada, y pasando directamente a ejemplos del Mundo Real™. Se abordarán buenas prácticas de indizado, las consideraciones de almacenamiento más relevantes, el análisis de planes de ejecución, así como la utilización de nuevas características de SQL Server 2008 para optimizar cargas de trabajo.

1.- Arquitectura general de SQL Server
2.- Metodología Waits & Queues: Monitorización de Esperas en SQL Server
3.- Optimización de Almacenamiento
4.- Optimización del Uso de Memoria
5.- Aislamiento Transaccional
6.- Optimización de Consultas

Rock Tip:

Esta vez, tanto la sesión como el post comparten rock tip, que no podía ser otro que el ‘Speed of Light’ de los speed-metaleros fineses Statovarius. Un tema clásico, con una formación clásica en la banda, antes de que al señor Timo Tolkki le diera por seguir las instrucciones que le dictaba una patata en llamas, a fingir un asalto y acuchillamiento en plena gira, o a hacer cambios ridículos en la formación de la banda con fines promocionales.

¡Vamos a poner nuestros servidores SQL Server a la velocidad de la luz! Keep Rockin’!

Modern Day Cowboy: SOSEX para WinDbg

Pablo Alvarez — Tue, 23 Jun 2009 17:33:00 GMT

Quiero pediros un favor. Quiero que digáis todos en alto "Gracias, Steve! Tu molas!”. Y quiero que lo digáis mirando hacia el oeste. Y quiero que lo digáis alto. Y quiero que lo digáis en inglés (dejo la traducción como ejercicio al lector XD).

No se si Steve Johnson podrá oírnos, pero desde luego se merece nuestro reconocimiento y agradecimiento, pues es el autor de una de las extensiones de WinDbg más espectaculares que he probado nunca, y de la que hoy os quiero hablar: las SOSEX 2.0

Pero antes, vamos a hablar un poquito de las extensiones en WinDbg…

El Depurador Extensible

Las extensiones de WinDbg son una de sus características estrella, y lo que le convierten en un depurador tan especial. Estas extensiones son DLLs que exportan funciones que agregan ciertas capacidades al depurador a través de los comandos de extensión.

Si habéis seguido alguna de mis entradas anteriores sobre depuración de código administrado con WinDbg, ya habréis empleado comandos de extensión, ya que la archiconocida SOS.dll es una extensión de WinDbg, y comandos como !dumpheap, !printexception o !eeheap son comandos de extensión exportados por la SOS.dll. Todos los comandos que empiezan con el carácter ! (bang, en inglés), son comandos de extensión.

Podemos consultar todas las extensiones cargadas en WinDbg, y su orden, a través del comando .chain. Un ejemplo de salida de .chain en mi WinDbg:

0:001> .chain
Extension DLL search Path:

Extension DLL chain:
    dbghelp: image 6.11.0001.404, API 6.1.6, built Thu Feb 26 03:10:27 2009
        [path: C:\Program Files\Debugging Tools for Windows (x64)\dbghelp.dll]
    ext: image 6.11.0001.404, API 1.0.0, built Thu Feb 26 03:10:26 2009
        [path: C:\Program Files\Debugging Tools for Windows (x64)\winext\ext.dll]
    exts: image 6.11.0001.404, API 1.0.0, built Thu Feb 26 03:10:17 2009
        [path: C:\Program Files\Debugging Tools for Windows (x64)\WINXP\exts.dll]
    uext: image 6.11.0001.404, API 1.0.0, built Thu Feb 26 03:10:20 2009
        [path: C:\Program Files\Debugging Tools for Windows (x64)\winext\uext.dll]
    ntsdexts: image 6.1.7015.0, API 1.0.0, built Thu Feb 26 03:09:22 2009
        [path: C:\Program Files\Debugging Tools for Windows (x64)\WINXP\ntsdexts.dll]

Como se puede ver, tengo cargadas las extensiones dgbhelp, ext, exts, uext y ntsdexts, que son las extensiones que WinDBG carga por defecto, y gracias a las cuales tenemos comandos de extensión como !analyze y !locks en cualquier despliegue por defecto de WinDbg.

Ahora que hemos hecho un pequeño repaso a las extensiones y los comandos de extensión, os podéis descargar las SOSEX v2.0 desde esta entrada en el blog de Steve, y copiar la DLL en vuestro directorio winext dentro de las Debugging Tools for Windows. A partir de ese momento, mediante el comando .load sosex podréis cargar las extensiones y empezar a jugar.

SOSEX 2.0

NOTA: Una vez cargadas las SOSEX, estas pasan a la primera posición del chain de extensiones, con lo que si invocamos al comando !help, estaremos llamando realmente a !SOSEX.help. A lo largo de toda la entrada me ahorrare el prefijar las llamadas a los comandos de extensión.

Mediante !help vamos a obtener la lista de los comando expuestos por SOSEX. A continuación os detallo los que me resultan más interesantes:

!dlk:

Este comando nos muestra los interbloqueos producidos entre dos o más sync blocks, lo que en la practica supone mostrarnos los interbloqueos producidos en código administrado.

Las viejas SOS nos permitían ver todos los objetos de sincronización a través de la extensión !syncblk, pero la búsqueda de interbloqueos no era trivial, ya que nos obligaba a ver todos los call stacks de los hilos involucrados.

La salida de !dlk nos muestra información mucho más directa y concisa:

0:016> !dlk
Deadlock detected:
CLR thread 3 holds sync block 00000000024af3b8 OBJ:00000000105cfcb8[System.Object]
waits sync block 00000000024af1c0 OBJ:00000000105cfde8[System.Byte[]]
CLR thread 5 holds sync block 00000000024af1c0 OBJ:00000000105cfde8[System.Byte[]]
waits sync block 00000000024af3b8 OBJ:00000000105cfcb8[System.Object]
CLR Thread 3 is waiting at DemoThreading.Monitor.WriterFunc()+0x37(IL)
[c:\demosDOT\DemoThreads\Monitor.cs, line 63]
CLR Thread 5 is waiting at DemoThreading.Monitor.ReaderFunc()+0x15(IL)
[c:\demosDOT\DemoThreads\Monitor.cs, line 42]
1 deadlock detected.

Si os fijáis, no solo nos detecta la situación de interbloqueos, sino que es capaz de decirnos el fichero y la línea de código que se estaba ejecutando en cada uno de los hilos involucrados. Esto es impagable.

!dumpgen:

En mi día a día como especialista en depuración, una de las tareas a las que más tiempo dedico es a detectar fugas de memoria. No vamos a tratar en este artículo sobre las fugas de memoria administradas, pero me basta que sepáis con que es muy útil detectar los objetos que viven en una generación de memoria determinada. Mediante el comando !dumpgen, SOSEX nos ayuda a estudiar los objetos almacenados en generación concreta.

A modo de ejemplo, si quisiéramos monitorizar los objetos que viven en generación 2 podríamos ejecutar !dumpgen 2 –stat. Podéis pensar en el como un !dumpheap que, en lugar de inspeccionar todo el managed heap, inspecciona solo un heap particular.

!gcgen:

Siguiendo en la línea del !dumpgen, el !gcgen de las SOSEX nos permite averiguar en que generación reside un objeto concreto. Por ejemplo:

0:000> !gcgen 00000422714a7dd1
Gen 1

Esto es muy interesante en multitud de escenarios del Mundo Real(tm). Recientemente he estado empleando muy frecuentemente el comando !gcgen en un .foreach de un !dumpheap –mt para que me vuelque la generación en la que viven todos los objetos de un determinado tipo, con el fin de poder evaluar que porcentaje de ellos viven en generación 2. Generalmente busco por conexiones a la base de datos, y si el valor es muy elevado, en gran parte de los escenarios se deberá a que se mantienen referencias a esos objetos que impiden su recolección a tiempo. Un ejemplo de este uso sería el siguiente:

.foreach (obj {!dumpheap –mt <MT del Objeto> -short}) {!gcgen ${obj}}

!refs:

El comando de extensión !refs nos muestra una lista con todos los objetos que están referenciando a un objeto determinado, así como otra lista con todos los objetos que son referenciados por este.

Pensad un poco en ello… es un comando salvaje para averiguar porque un objeto determinado no se va de memoria, quien mantiene referencias sobre el. Es una autentica joya a la hora de buscar fugas de memoria administrada.

A continuación os pongo un ejemplo que he sacado del blog de John Robbins:

0:004> !refs 0000000002696918
Objects referenced by 0000000002696918 (System.Diagnostics.DefaultTraceListener):
00000000026941c0     40    System.String    STRVAL=Default
0000000002696b78     24    System.Collections.Specialized.StringDictionary
00000642787c78c8     26    System.String
Objects referencing 0000000002696918 (System.Diagnostics.DefaultTraceListener):
00000000026941e8     160    System.Diagnostics.ListenerElement
0000000002695468     24    System.Object
0000000002697150     48    System.Collections.ArrayList+ArrayListEnumeratorSimple
Thread 4
stack:000000001c1be7c8
stack:000000001c1be880
stack:000000001c1be8b0
stack:000000001c1be8e0
stack:000000001c1be8f0
stack:000000001c1be920
stack:000000001c1be930

¡Espectacular!

!mdt:

Dejo para el final el que seguramente sea mi comando favorito de las SOSEX. !mdt es la versión administrada del mítico comando dt de los escenarios de depuración nativa de WinDbg. Sirve para inspeccionar cómodamente un objeto, de modo que podríamos verlo como un sustituto para el venerable !dumpobject de las SOS.dll. Una de mis características favoritas es su parámetro –r, que permite explorar los objetos que componen el objeto de estudio de modo recursivo.

A continuación os pongo un ejemplo de !mdt sobre un objeto de tipo Oracle.DataAccess.Client.ConnectionPool:

0:044> !mdt 000000007fffe9d8 -r
000000007fffe9d8 (Oracle.DataAccess.Client.ConnectionPool)
   m_connections:000000007fffeae0 (System.Collections.Stack+SyncStack)
      _array:000000007fffeb18 (System.Object[], Elements: 10)
      _size:0x0 (System.Int32)
      _version:0x0 (System.Int32)
      _syncRoot:NULL (System.Object)
      _s:000000007fffea48 (System.Collections.Stack)
         _array:000000007fffea70 (System.Object[], Elements: 10)
         _size:0x0 (System.Int32)
         _version:0x8 (System.Int32)
         _syncRoot:000000007fffeb88 (System.Object)
            <NO FIELDS>
      _root:000000007fffeb88 (System.Object)
         <NO FIELDS>
   m_mtsConnections:000000007fffebe0 (System.EnterpriseServices.ResourcePool)
      _cb:000000007fffeba0 (System.EnterpriseServices.ResourcePool+TransactionEndDelegate)
         _target:000000007fffe9d8 (Oracle.DataAccess.Client.ConnectionPool)
            <RECURSIVE>
         _methodBase:NULL (System.Reflection.MethodBase)
         _methodPtr:00000642800fda60 (System.IntPtr)
         _methodPtrAux:0000000000000000 (System.IntPtr)
         _invocationList:NULL (System.Object)
         _invocationCount:0000000000000000 (System.IntPtr)
         <NO FIELDS>
   m_semAvaNumOfCons:0000000000000000 (System.IntPtr)
   m_timer:000000007ffff008 (System.Threading.Timer)
      __identity:NULL (System.Object)
      timerBase:000000007ffff028 (System.Threading.TimerBase)
         timerHandle:0000000005d40e10 (System.IntPtr)
         delegateInfo:0000000006bc0b90 (System.IntPtr)
         timerDeleted:0x1 (System.Int32)
         m_lock:0x0 (System.Int32)
   m_clonedCtx:000000007fffee98 (Oracle.DataAccess.Client.OpoConCtx)
      opsConCtx:0000000000000000 (System.IntPtr)
      opsErrCtx:0000000000000000 (System.IntPtr)
      pOpoConValCtx:0000000000000000 (System.UIntPtr)
      opoConRefCtx:000000007fffef50 (Oracle.DataAccess.Client.OpoConRefCtx)
         serverVersion:000000007fffe880 (System.String: "<censurado ;)>")
         userID:000000007fffe8b0 (System.String: "<censurado ;)>")
         password:000000007fffe8e0 (System.String: "<censurado ;)>")
         dataSource:000000007fffe910 (System.String: "<censurado ;)>")
         newPassword:00000000dfff0370 (System.String: "")
         proxyUserId:00000000dfff0370 (System.String: "")
         proxyPassword:00000000dfff0370 (System.String: "")
         dbName:000000007fffe938 (System.String: "<censurado ;)>")
         hostName:000000007fffe960 (System.String: "<censurado ;)>")
         instanceName:000000007fffe988 (System.String: "<censurado ;)>")
         serviceName:000000007fffe9b0 (System.String: "<censurado ;)>")
         clientID:NULL (System.String)
         pITransaction:NULL (System.EnterpriseServices.ITransaction)
      conString:000000007fffd350 (System.String: "<censurado ;)>")
      pool:NULL (Oracle.DataAccess.Client.ConnectionPool)
      maxPoolSize:0x64 (System.Int32)
      minPoolSize:0x0 (System.Int32)
      poolIncSize:0x5 (System.Int32)
      poolDecSize:0x1 (System.Int32)
      poolRegulator:0xB4 (System.Int32)
      creationTime:000000007fffef28 (System.DateTime) 2009/06/23 18:53:51.511 VALTYPE (MT=0000064278476ad8, ADDR=000000007fffef28)
      lifeTime:000000007fffef30 (System.TimeSpan) VALTYPE (MT=00000642784769d8, ADDR=000000007fffef30)
         _ticks:0x0 (System.Int64)
      timeOut:000000007fffef38 (System.TimeSpan) VALTYPE (MT=00000642784769d8, ADDR=000000007fffef38)
         _ticks:0x0 (System.Int64)
      pooledConCtx:NULL (Oracle.DataAccess.Client.PooledConCtx)
      poolName:NULL (System.String)
      bErrorOnOpen:false (System.Boolean)
      validateCon:0x0 (System.Int32)
      gridCR:0x0 (System.Int32)
      gridRLB:0x0 (System.Int32)
      dataSrc:NULL (System.String)
      metaPool:0x1 (System.Int32)
      origLifeTime:000000007fffef40 (System.TimeSpan) VALTYPE (MT=00000642784769d8, ADDR=000000007fffef40)
         _ticks:0x0 (System.Int64)
      origPoolDecSize:0x1 (System.Int32)
      origMinPoolSize:0x0 (System.Int32)
      exceptMsg:NULL (System.String)
      m_conPooler:NULL (Oracle.DataAccess.Client.ConPooler)
   m_counter:000000007ffff108 (Oracle.DataAccess.Client.Counter)
      total:0x0 (System.Int32)
      potentialTotal:0x0 (System.Int32)
      threadWait:0x0 (System.Int32)
      totalAvailable:0x0 (System.Int32)
      bOwnedByCPCtx:false (System.Boolean)
   m_skipDecrement:false (System.Boolean)
   m_cpCtx:NULL (Oracle.DataAccess.Client.CPCtx)
   m_rlbGravCounter:0x0 (System.Int32)
   m_attemptedRequests:0.000000 (System.Single)
   m_bSynchronizeStack:false (System.Boolean)

No se como lo veis vosotros, pero a mi esto me encanta. Normalmente “pierdo” mucho tiempo explorando los objetos con una sucesión casi interminable de !dumpobject, y este pequeño comando me ahorra muchísimo tiempo.

Hay más comandos de extensión interesantes en las SOSEX, como los relacionados con los breakpoints en código administrado, la búsqueda de cadenas en el volcado o la inspección de ensamblados, pero los más interesantes y prácticos para mi, hasta el momento, han sido estos que os he descrito. Espero que los disfrutéis y que esta entrada os sirva para ahorrar tiempo y pasarlo aun mejor en vuestras sesiones de depuración.

En resumen…

Esta librería ha pasado a formar parte de mi kit de depuración hasta el punto que, en el 95% de los casos, al abrir un volcado de memoria en el WinDbg sigo la misma rutina:

.reload /v /f
.loadby sos mscorwks
.load sosex
¡Empezamos a depurar!

No podía dejar pasar la oportunidad de recomendaros su uso, y a la vez, aprovechar el artículo para hablar de la extensiones de WinDbg. ¡Espero que lo hayáis disfrutado!

PS: Thanks Steve! I owe you a beer… or a full six-pack!:)

Rock Tip:

Hoy os traigo una buena noticia; vamos a tener la suerte de recibir a los californianos Tesla en nuestras tierras, ya que este Martes 23 actuarán en Barcelona, y el Miércoles 24 en Madrid, en la sala Heineken. Allí espero estar mañana a la noche, disfrutando de temazos como Paradise, Stir It Up, Modern Day Cowboy…

Precisamente este último tema me pareció apropiado como Rock Tip para éste artículo; no lo puedo evitar, cuando abro el WinDbg e inicio una sesión de depuración, me veo a mi mismo en un camino polvoriento y pedregoso, embarrado desde las botas camperas hasta el sombrero de cowboy, con la seis cuerdas a la espalda, y mis armas listas para la acción. ¿Flipado? Si… pero ¿y lo bien que me lo paso? :)

En este caso mis armas son mis herramientas, y las SOSEX son una de las últimas adiciones a mi arsenal de depuración. Pensar en las SOSEX como arma me dio la idea de emplear el ‘Stick to Your Guns’ de Bon Jovi para este post, pero luego recordé que Tesla tocan esta semana en España y que aun no habían aparecido en ningún Rock Tip de este, vuestro blog :)

Por cierto, si alguno de vosotros va a ver a los chicos de Jeff Keith este Miércoles en Madrid avisadme, y ya puestos os podéis estirar y invitar a una cervecilla ¿no? :)

Keep Rockin’!

Another Day: Sesión de Depuración y Optimización en Barcelona

Pablo Alvarez — Mon, 08 Jun 2009 07:18:00 GMT

… y seguimos con la pequeña gira sobre Depuración y Optimización que estamos realizando este año los integrantes del DOT Team de Plain Concepts. Después de Santander, Bilbao, A Coruña y Madrid, le llega el turno a la Ciudad Condal, donde tendré el placer de presentar una sesión sobre Depuración y Optimización Avanzada de aplicaciones con WinDbg.

El evento se realizará el próximo día 17 de Junio en las oficinas de Microsoft en Barcelona, en horario de 16:00 a 18:00. Lo cierto es que, si fuera por mi, estaríamos hablando una semana entera sobre el asunto; los que ya me conocéis sabéis la gran razón que tiene esa señora madre mía cuando dice que yo no callo ni debajo del agua. Aun así, intentaremos aprovechar al máximo esas dos horitas. Los interesados podéis apuntaros en este enlace: http://msevents.microsoft.com/CUI/EventDetail.aspx?EventID=1032417766&Culture=es-ES

Como siempre, ¡se aceptan invitaciones a cervecitas! XDD ¡Nos vemos en Barcelona!

Rock Tip:

Otro día más presentando mis juguetes favoritos de depuración, otro día más de charlita de internals de .NET y de Windows. Por eso me pareció muy interesante como Rock Tip para esta entrada el ‘Another Day’, uno de los temas mas conocidos de los increíbles Dream Theater. Esta banda americana de metal progresivo combinan de un modo espectacular el virtuosismo de sus músicos (todos ellos salidos del Berklee College of Music!) con una musicalidad poco común en este género.

Este tema en cuestión apareció en el espectacular Images And Words, de 1992. Un disco muy, pero que muy recomendable para todos los amantes de la buena música y del virtuosismo. Por otra parte estamos de enhorabuena, ya que los chicos de Dream Theater acaban de publicar su último trabajo, el Black Clouds & Silver Linings.

Gimme Three Steps: Creando nuestro Servidor de Símbolos

Pablo Alvarez — Wed, 15 Apr 2009 08:05:00 GMT

Hace unos días, conversando con Rodri y con Jose Luis, surgió la necesidad de crear un documento interno de Plain Concepts acerca de la utilización de symstore para la creación de un servidor de símbolos a nivel de empresa. Al momento nos dimos cuenta de que esto podía interesar a mas geeks como nosotros, así que he decidido crear una guía muy breve para la creación de un servidor de símbolos básico.

¡Espero que os resulte interesante!

¿Un Servidor de Símbolos? ¿Para que quiero yo eso?

NOTA: En esta entrada no voy a explicar que son los símbolos, ni para que nos sirven, etc. Todo eso está explicado en múltiples artículos de la MSDN, en la documentación de los depuradores correspondientes y entradas de blog tan magníficas como esta. Y no es por que sea mía :)

Como ya sabréis los que me conocéis personalmente, para mi una sesión de depuración post-mortem es como la quema de iglesias para los blackmetaleros nórdicos; una fuente de diversión inagotable. Sin embargo siempre hay momentos frustrantes, y casi todos ellos tienen que ver con la carencia de símbolos apropiados, o el echo de que WinDbg no puede localizarlos adecuadamente.

Para facilitar la vida a nuestros depuradores y herramientas varias que necesiten acceder a esta información simbólica de depuración vamos a construir un servidor de símbolos donde se almacenaran tanto los símbolos de nuestras aplicaciones como los que nos descarguemos de otros servidores, como el servidor de símbolos públicos de Microsoft (http://msdl.microsoft.com/download/symbols).

Construyendo nuestro Servidor de Símbolos

Vamos a necesitar de tres simples pasos para construir el servidor de símbolos:

Obtener un lugar físico donde almacenar los símbolos:

Esta parte es la mas sencilla. Necesitamos un lugar donde almacenar los ficheros .pdb, para lo que crearemos un directorio en algún servidor accesible a nivel de nuestra organización y compartiremos esta carpeta. Así de simple :)

En el resto del articulo supondremos que hemos creado un share llamado Symbols en el servidor DevSrv01. Por tanto, el servidor de símbolos se encontrará en \\DevSer01\Symbols.

Configurar las herramientas para que utilicen ese lugar como servidor de símbolos:

Ahora debemos instruir a nuestra aplicación de que busque los símbolos en nuestro servidor concreto. En el caso de WinDbg podemos recurrir directamente a la configuración de la ruta de búsqueda de símbolos desde File –> Symbol File Path… o Ctrl+S. Desde ahí podemos establecer la ruta, que en nuestro ejemplo bien podría ser “SRV*\\DevSrv01\Symbols*http://msdl.microsoft.com/download/symbols”, indicando que el servidor de símbolos estará en nuestro servidor, y que también buscará en el servidor público de símbolos de Microsoft.

NOTA: Para mas información respecto a las cadenas de búsqueda de símbolos, recomiendo mirar la documentación de las Debugging Tools For Windows.

A medida que vayamos recargando símbolos (por ejemplo, mediante .reload en WinDbg), buscara la presencia de la versión correcta de los mismos en el servidor de símbolos (\\DevSrv01\Symbols) y, caso de no encontrarlos, iria al siguiente elemento en la cadena de búsqueda y los descargaría, copiandolos en el servidor \\DevSrv01\Symbols; de este modo, la segunda vez que fuera necesario cargar los símbolos, estos ya se encontrarían en nuestro nuevo y flamante servidor.

Una alternativa más práctica es emplear la variable de entorno _NT_SYMBOL_PATH, estableciéndola a nuestra cadena de búsqueda de símbolos. Prácticamente todas las aplicaciones que hace uso de los símbolos intentan buscar primero en esa variable de entorno, como es el caso de WinDbg, adplus, etc… Sin embargo, hay una notable excepción: el Process Explorer de SysInternals. Como seguramente sabréis, ésta magnifica herramienta también puede emplear los símbolos para generar volcados de memoria, ver la información de los call stacks de los diferentes threads de un proceso en ejecución, etc. En esta herramienta tendremos que establecer el servidor de símbolos manualmente, ya que no lee de _NT_SYMBOL_PATH. ¡Avisados estais! :)

Poblar el servidor de símbolos con cada nueva build:

Como ya sabréis, el mayor problema de los servidores de símbolos es mantener el orden dentro del caos que suponer tener múltiples versiones de un mismo módulo. Con cada nueva compilación, las direcciones de memoria de los distintos objetos pueden cambiar, asi como los offset, etc. Si intentamos depurar un proceso o un volcado de memoria con una versión incorrecta de los módulos los resultados pueden ser imprevisibles.

Os voy a comentar un ejemplo típico de depuración con símbolos incorrectos que seguro que os suena a más de uno: ¿alguna vez habéis realizado una depuración paso a paso con un depurador integrado en el entorno de desarrollo, y habéis comprobado que, en cierto momento, la línea que estáis ejecutando apunta a una línea inexistente o en blanco? Eso generalmente se debe a la utilización de unos .PDBs antiguos. Por ejemplo, se han agregado unas cuantas líneas de código a un método, pero al depurar empleamos la información de cuando ese método ocupaba menos, etc. Ala.. ¡un nuevo misterio resuelto! xD

Para evitar estos problemas, lo mejor es asegurarnos de que, cada vez que realizamos una nueva compilación, copiamos los nuevos .PDB al servidor de símbolos. La idea es buena, pero ahora tenemos que ver como la implementamos; daros cuenta que no puedo copiar directamente el fichero .pdb porque habría colisión de nombres. Si tengo un ensamblado llamado miEnsamblado.exe, y lo compilo cinco veces, tendré cinco ficheros miEnsamblado.pdb. Hay que buscar un mecanismo que permita almacenarlos sin que se sobrescriban, y haciendo posible que una herramienta que consuma los símbolos pueda coger el adecuado para una versión concreta.

Esto se consigue a través de una estructura de directorios especial en el servidor, basada en un hash del modulo, que no vamos a explicar en detalle en esta entrada. Lo que si os diré es que, gracias a una pequeña utilidad llamada symstore, que se distribuye con las propias Debugging Tools for Windows, podemos agregar nuevos .PDBs a nuestro servidor y automática se colocarán correctamente.

Un ejemplo de uso de symstore sería el siguiente:

symstore add /r /f c:\sources\aplicacion\bins\*.* /s \\DevSrv01\Symbols /t "Aplicacion 1" /v "Build 123"

En ese ejemplo agregamos al servidor todos los símbolos que se encuentran en la ruta definida, especificando el nombre de producto (/t) y la versión (/v). Para ver todos los parámetros, nuevamente recomiendo recurrir a la documentación de las Debugging Tools for Windows.

Ahora solo necesitamos automatizar el proceso después de la build, ya sea mediante una acción post-build, msbuild, o vuestro mecanismo favorito :)

Resumen

En este articulo no hemos entrado en profundidad en ninguno de los puntos; no hemos explicado que son los símbolos y para que valen, ni la sintaxis de la ruta de búsqueda de símbolos, ni como se genera el hash de cada versión de los símbolos y como éste se emplea para estructurarlos en el sistema de ficheros, etc. No, ese no era el objetivo de esta entrada del blog. El objetivo era, única y exclusivamente, contaros que se puede hacer y daros unas indicaciones básicas de cómo lograrlo; abriros un poco el apetito y de paso, publicar algo de lo que estamos haciendo internamente en Plain Concepts.

¡Espero que os haya sido de utilidad! Keep Rockin’!

Rock Tip:

Allá por 1973 Lynyrd Skynyrd publicaron su primer disco, su gran debut, “pronounced 'lĕh-'nérd 'skin-'nérd”; este disco incluía temazos como el Simple Man (para mi una de las mejores canciones de toda la historia… así de simple ;)) y el Free Bird, recientemente revitalizado gracias al Guitar Hero.

En aquel álbum aparecía también el tema que protagoniza el rock tip de este articulo; Gimme Three Steps. En realidad, la historia que cuenta esta canción no tiene mucho que ver con este artículo; esos tres pasos de los que habla la canción son los que le pide una chica a su captor para escapar corriendo de él. La letra es muy buena, espectacular, pero yo hago una reinterpretación y me quedo con los tres simples pasos que necesitamos para montar nuestro servidor de símbolos mediante symstore.

Bueno chicos, este fue el rock tip de hoy… ya veis que tengo el día sureño! :)

Calling On You: Sesión de Depuración y Optimización en A Coruña

Pablo Alvarez — Tue, 14 Apr 2009 15:47:11 GMT

Después de pasar una tarde genial en Bilbao con los chicos de Artalde.NET hablando sobre depuración avanzada con WinDbg, ahora le toca el turno a otra ciudad norteña; el grupo de usuarios de A Coruña (.NUGG) ha tenido a bien invitarme a hablar durante un par de horillas sobre uno de mis temas favoritos: la depuración y optimización de aplicaciones usando WinDbg y algún que otro juguetito :) El evento será el próximo Viernes 24 en la Facultad de Informática de A Crouña.

Aquí podéis acceder a la pagina de inscripción al evento y consultar los detalles del mismo: https://msevents.microsoft.com/cui/eventdetail.aspx?eventid=1032412774&culture=es-es y ya sabéis, si estáis por cerca de la Coruña y os apetece dedicar un par de horas a descubrir herramientas y técnicas de depuración avanzada y charlar un poquillo sobre internals de .NET, no dejéis de pasaros por el evento.

Y ya aprovechando el post, tengo que confesaros una cosa: cuando me plantee la idea de recorrer diferentes grupos de usuarios de .NET para hablar principalmente de WinDbg pensé que, o bien directamente la idea fuera descartada por los grupos, o bien no tendríamos afluencia de gente. Y una vez más, como viene siendo habitual en mi para este tipo de previsiones, me equivoque de mala manera :) Hasta el momento me he encontrado con gran asistencia y, lo que es mejor aun, multitud de preguntas y comentarios, tanto síncronamente (en los propios eventos) como asíncronamente (por correo, blog, etc.). De verdad, ¡muchas gracias a todos por vuestra participación e interés!

Rock Tip:

No es la primera vez que los heavies cristianos Stryper hacen acto de presencia por aquí en este humilde blog, y seguramente no sea la última tampoco; ya sabéis como va esto… el blog es mío y traigo a quien me apetece xD En este caso, se trata del que, para mi, es uno de sus mejores temas: ‘Calling on You’, aparecido en su discazo ‘To Hell With the Devil’ de 1986. Si no los conocéis, pegadles un orejazo. Encontrareis muy buenas melodías, técnica a patadas en todos los instrumentos y, sobre todo, una voz principal y unos coros que no os dejaran indiferentes.

Me pareció un rock tip apropiado para este post, ya que es un pequeño llamamiento para que vengáis a acompañarnos en el evento. Sea como sea, el Viernes 24 volverá a sonar el Calling on You en A Coruña :)

Keep Rockin’!

Enemy In Me: Sesión de Depuración y Optimización en Bilbao

Pablo Alvarez — Mon, 30 Mar 2009 18:45:00 GMT

Como ya comentó Ibon en su blog, este miércoles voy a tener la oportunidad de pasar un magnifico rato con los chicos de Artalde.NET hablando de uno de mis temas favoritos: la depuración avanzada de aplicaciones .NET.

Pasaremos un ratito entretenido (¡o eso espero!) hablando de WinDbg y su uso para detectar bugs esquivos y problemas de rendimiento; por el camino discutiremos ciertos detalles de la implementación de .NET e internals que de seguro nos resultarán útiles para hacer código mas robusto, estable y eficiente. Y después… tapitas y pinchitos por Bilbao!! No se a vosotros, pero a mi el plan me suena de maravilla :)

Así que ya sabéis, si estáis por Bilbao este Miércoles y os apetece bajar a las trincheras, no dejéis de registraros aquí y pasar a hacernos una visitilla.

NOTA: A la finalización del evento subiré aquí mismo los materiales del mismo.

NOTA2: Ya ha finalizado el evento, y con el retraso que me caracteriza (¡sorry!) os pongo el enlace a la descarga de las presentaciones de la sesión. Aprovecho también para dar las gracias a todos los asistentes: ¡que bien me cuidáis en Bilbao!

Rock Tip:

Como dice el titulo de este gran tema de los Vains of Jenna, muchas veces el enemigo esta en nosotros mismos; esta frase me parece muy apropiada para las sesiones de depuración, sobre todo cuando nos toca depurar nuestro propio código. Por ello, este rock tip va para esta banda de sleaze rock tan poco conocida pero tan interesante.

Enjoy, and Keep rockin’!!!