ASM caliente para el alma del programador

Depurar programas paralelos es terriblemente complicado. Y cuando uno le suma a eso su propia idiotez el combo se torna mortal. Esta semana perdí dos días completos por culpa de un error de tipeo. Pero, como toda historia para que merezca ser contada debe tener algún lado bueno, en este caso, mis dos días de caza incluyeron el desarrollo de un par de funcionalidades nuevas en ZinjaI. Funcionalidades que al final de cuentas no necesitaba en absoluto para resolver ese problema, pero que en algún momento pensé que sí, y supongo que a futuro ya les daré mejor uso. Se trata de un par de paneles para inspeccionar el código de máquina generado por el compilador, y el estado de los registros internos del procesador durante la depuración. He aquí la anécdota completa y el resultado.

Vamos por partes: primero, el escenario que me llevó a pensar que necesitaba esto. Depurar es de por sí una ardua tarea en un programa no paralelo. Pero en un programa paralelo la cosa se pone peor: los bugs propios del paralelismo, particularmente los conocidos como data-races y race-conditions, dependen totalmente del "timing". Por ejemplo: suponga dos hilos que se ejecutan a la par y acceden a las mismas estructuras de datos en memoria. Si los accesos no están muy bien sincronizados, tarde o temprano habrá problemas. Pero, que estos problemas se manifiesten o no, depende de cómo se intercalen esos accesos de un hilo y otro. Y como ambos avanzan a la par cada uno por su cuenta, pequeñas e incontrolables diferencias de velocidades (por ejemplo, por culpa del planificador de tareas del sistema operativo) hacen que sea muy difícil reproducir dos ejecuciones con los mismo "patrones" de acceso, como para controlar, detectar o analizar estos errores. Y aún si el error se manifiesta con frecuencia en la ejecución normal, la intervención de un depurador en el camino cambia totalmente el escenario.

Multithreaded-programming: teoría vs. práctica. Una imagen vale más que 1k palabras.

Para colmo de males, puede ser que el programa en realidad use varias CPUs diferentes, y varios hilos en cada CPU. Entonces ya ni siquiera es un programa, sino que hay muchos (probablemente copias) para depurar en simultáneo. Y para terminar, cuando tenemos este último escenario, por lo general la ejecución es lanzada a través de alguna herramienta de la biblioteca/framework de paralelización, y no de la forma habitual. Entonces, el IDE (o el programador) no controla directamente la ejecución. Ya tengo en ZinjaI desde hace rato algunas facilidades para este último problema. Por un lado, en las propiedades del proyecto se puede configurar la ejecución para que ZinjaI la lance a través de otro script o ejecutable que haga las veces de wrapper. Por otro lado, como esto no sirve para lanzar el depurador, lo que hace ZinjaI es lanzar la ejecución sin depurador con ese wrapper, y luego, una vez que el wrapper haya comenzado a ejecutar nuestro programa, adjuntarlo (esto es hacer que se enganche al proceso cual garrapata). Dado que el depurador se adjunta luego de que la ejecución comenzó, el programa a depurar debe generar algún tiempo muerto al comienzo para darle oportunidad al depurador de realizar esta acción.

En las opciones de compilación y ejecución de proyecto en ZinjaI

 se puede configurar la ejecución mediante un script externo.

Pero en mi caso, como el error estaba justamente en el arranque, ese "tiempo muerto" hacía que el error ya no se vea, y entonces esta técnica era completamente inútil. Así que debí volver a la única herramienta de depuración superior al combo que ofrece ZinjaI: el cerebro. Fui hasta el pizarrón, borré todo lo que había, y empecé a analizar el comportamiento con diagramas de secuencia, pruebas de escritorio, y toda suerte de castillos en el aire, volviendo solo a la PC y al depurador de ZinjaI para verificar ciertos detalles finos particulares. Después de un buen rato, y varias idas y venidas entre ZinjaI/gdb y marcador/pizarrón, logré algunas conjeturas acerca de dónde podría ocasionarse el problema. El siguiente paso me da algo de vergüenza, porque fue agregar cout/cerr por todos lados (cuidado con el dinosaurio!). La idea era verificar si las instrucciones se intercalaban en cierto orden, pero sin usar el depurador, para no alterar tanto ese delicado "timing".

Todo este lío dio finalmente un resultado, y llegué a la conclusión de que esta pelea se definiría entre una condition_variable y un método de una cola de trabajos. Una condition_variable es un instrumento de comunicación entre hilos, que usualmente se usa cuando algunos hilos producen trabajos que otros hilos resuelven, para que los primeros les avisen a los segundos cuando empezar a resolver. Resulta que el problema se daba cuando el hilo que preparaba los trabajos, avisaba que ya estaba listo el primer trabajo tan rápido, que el hilo que debía resolverlo todavía no se había terminado de preparar para escuchar esos avisos, y entonces se lo perdía. No es una situación tan rara y hay soluciones para esto, la mía dependía de un if que le preguntaba a la cola de trabajos si estaba o no vacía. Y sin dudas, esa pregunta estaba fallando. Pero el código del método que hacía la pregunta era tan pero tan trivial, que ni valía la pena depurarlo.

Así que empecé a ver fantasmas, y a sospechar de las cosas que pasaban a muy bajo nivel, en el hardware. Como todavía no conozco con tooodo el detalle que quisiera el modelo de memoria que se introdujo en C++ entre los estándares 11 y 14, y ni hablar de los detalles propios de cada compilador, siempre me queda lugar para la duda en esos temas. Por eso me armé una hipótesis relacionada a las optimizaciones que hace el compilador para reducir los accesos a RAM mediante el uso de registros adicionales. No voy a hilar más fino porque esto ya viene largo, pero digamos en mi defensa que de haber sido cierta no habría sido la primera vez que lidiaba con eso. Y si no era eso, era el corazón de la condition_variable, y yo ya estaba dispuesto a llegar hasta el final. En cualquier caso, aquí es cuando aparece la necesidad de ver el código de máquina generado por el compilador, y/o el estado de los registros durante la ejecución.

Primera versión del nuevo panel que muestra la versión compilada y desensamblada del código.

Por motivos que ya tendrán su propio post (y porque a esta altura realmente me costaba poco) decidí agregar estas funcionalidades a ZinjaI (que de paso hacía rato que las quería para mi caja de herramientas). El estado de los registros me los da directamente gdb, así que ponerlos en una tabla fue muy poco trabajo. Respecto al desensamblado, hay tres opciones: pedírselo a gdb (para lo cual tengo que poder ejecutar el programa con el depurador y a veces llegar con la ejecución a ese punto), pedírselo a gcc (lanzando una compilación, pero diciéndole que no la haga completa, que solo llegue hasta el ensamblado), o usar algún desensamblador (como objdump, que ya viene con las binutils). La primer opción es en caliente (ejecutando), mientras que las otras dos son en frío. Así que es bueno tener ambas "temperaturas" disponibles. Para la versión en frío opté por objdump porque era simple de implementar, y porque me da el assembler "anotado". Esto es, me intercala entre las instrucciones de máquina referencias que dicen a qué linea del código fuente corresponden y en cual método/función estaban. Esto me sirve para filtrar la partecita que me interesa en medio de tooodo el kilométrico desensamblado. Además, en las llamadas a funciones, me aclara a qué función corresponde cada dirección de memoria. La única pega es que requiere información de depuración en el ejecutable.

Nuevo panel para visualizar el estado de los registros del procesador.

Por completitud, comento cual era mi error: un simple, estúpido y malévolo error de tipeo. Puse mal la constante en un #ifdef, y eso hizo desaparecer ese método "tan trivial que ni valía la pena depurarlo". El programa compilaba igual, porque el método estaba en una clase heredada, y usaba en su lugar el método homónimo de la clase base. Si bien el desensamblado me mostró que la función a la que se invocaba no era la que yo creía, de entrada no lo ví (no era eso lo que buscaba allí), sino que al ratito me dí cuenta por otro lado. Y por eso, en este caso realmente no era imprescindible el desensamblado, pero me sirvió igual el camino recorrido para entender el problema, y me quedaron como side-effects un par de buenas mejoras en ZinjaI para la próxima release.

Porque como dijo una vez el grandísimo John Carmack: "la programación de bajo nivel es buena para el alma del programador". No sé exactamente si con "bajo nivel" se refería a un lenguaje como C, o directamente a código de máquina, pero en cualquier caso es entendible su gusto, porque cuando uno necesita exprimir hasta el último bit disponible ambos mundos se cruzan obligadamente... Y valla si lo necesitaba él para hacer que una bestialidad como Doom corriese con 4MB de RAM y un micro de 30MHz mucho más fluido de que lo que corre hoy en día un "simple" editor de textos "moderno" en mi PC del trabajo, de 8GB de RAM y 4 núcleos a 2.9GHz cada uno... Hay más cache en ese segundo micro que RAM en aquel primero! ¿Cuando fue que nos desviamos tanto? Perdón, ya me salí del tema otra vez, dejemos esas reflexiones para otro día.