|
3. Depuración y análisis de perfiles de ejecución La depuración en Euphoria es mucho más fácil que en el resto de los lenguajes de programación. La extensa verificación en tiempo de ejecución provista por el intérprete Euphoria captura muchos bugs que en otros lenguajes podría tomar horas. Cuando el intérprete captura un error, siempre obtendrá un breve informe en pantalla y uno detallado en el archivo llamado ex.err. Estos informes incluyen la descripción de lo ocurrido, completamente en inglés, junto con un vuelco de la pila. El archivo ex.err también contendrá un volcado de todos los valores de las variables, y opcionalmente una lista de las sentencias ejecutadas recientemente. Para programas extremadamente extensos, solamente se muestra un volcado parcial. Si ex.err no es conveniente, puede elegir otro nombre de archivo, en cualquier parte de su sistema, llamando a crash_file(). Además, puede crear tipos definidos por el usuario que determinan precisamente el conjunto de valores legales para cada una de las variables. Se generará un informe de errores en el momento en que se asigne un valor ilegal a una variable. A veces, un programa se comportará mal sin fallar en ninguna verificación en tiempo de ejecución. En cualquier lenguaje de programación puede ser buena idea estudiar el código fuente y replantear el algoritmo codificado. También puede ser útil insertar sentencias de impresión en puntos estratégicos de forma de monitorear la lógica interna del programa. Esta aproximación es particularmente conveniente en un lenguaje interpretado como Euphoria, ya que simplemente puede editar el código y volver a ejecutarlo sin tener que esperar una nueva compilación/enlazado. El intérprete le provee poderosas herramientas adicionales para depuración. Usando trace(1) puede trazar la ejecución de su programa en una pantalla mientras es testigo de la salida del programa en otra. trace(2) es lo msimo que trace(1), pero la pantalla de trazado será monocromática. Finalmente, usando trace(3), puede registrar todas las sentencias ejecutadas en un archivo llamado ctrace.out. La utilidad completa de trazado es parte de la Edición Completa de Euphoria, pero está habilitada en la Edición de Dominio Público para programas de hasta 300 sentencias. Las sentencias especiales with trace / without trace seleccionan las partes del programa en las que quiere habilitar el trazado. Frecuentemente, insertará simplemente una sentencia with trace casi al comienzo del código fuente para hacer que el trazado sea completo. A veces es mejor ubicar el primer with trace después de todos sus tipos definidos por el usuario, por lo que no se realiza el trazado dentro de esas rutinas después de cada asignación a una variable. Otras veces, puede conocer exactamente que rutina o rutinas le interesa trazar, y solamente seleccionará alguna de ellas. Por supuesto, una vez que esté en la ventana de trazado, puede saltear la ejecución de cualquier rutina presionando la flecha abajo del teclado, en lugar del Enter. Solamente debería ocurrir un error en tiempo de ejecución con las líneas trazables pueden aparecer en ctrace.out o en ex.err como "Traced lines leading up to the failure". Si quiere esta información y no la obtiene, debería insertar un with trace y volver a ejecutar su programa. La ejecución será más lenta con líneas compiladas con with trace, especialmente cuando se use trace(3). Después de predeterminar las líneas que serán trazadas, el programa tiene que provocar dinámicamente que la utilidad de trazado se active, ejecutando la sentencia trace(). Podría escribir: with trace
trace(1)
al inicio del programa, por lo que se inicia el trazado
no bien comienza la ejecución. Más comúnmente querrá
disparar el trazado cuando se ejecute una cierta rutina, o surja alguna
condición, por ejemplo:
if x < 0 then
trace(1)
end if
Puede desactivar el trazado ejecutando la sentencia trace(0). También lo puede desactivar interactivamente escribiendo 'q' para abandonar el trazado. Recuerde que with trace tiene que aparecer fuera de cualquier rutina, mientras que trace() puede aparecer tanto dentro de una rutina como fuera de ella. Podría querer activar el trazado desde dentro de un tipo. Suponga que ejecuta su programa y éste falla, con el archivo ex.err mostrando que una de sus variables se estableció con un valor extraño, aunque no ilegal y quisiera saber cómo esto puede haber ocurrido. Simplemente cree un tipo para esa variable de manera que ejecute trace(1) si el valor que se le asigna a la variable no está comprendido entre los que espera, por ejemplo: type positive_int(integer x)
if x = 99 then
trace(1) -- ¿cómo puede ser esto?
return 1 -- keep going
else
return x > 0
end if
end type
Cuando positive_int() regresa, verá la sentencia exacta que causó que la variable se haya establecido a un valor extraño, y podrá verificar los valores de las otras variables. También podrá verificar la pantalla de salida para ver que ocurrió en ese preciso momento. Si define positive_int() para que devuelva 0 para el caso del valor extraño (99) en lugar de 1, puede forzar un volcado de diagnóstico a ex.err. Cuando el intérprete ejecuta la sentencia trace(1) o trace(2), la pantalla principal de salida se guarda y aparece la pantalla de trazado. Ésta muestra una vista de su programa, con la sentencia próxima a ejecutarse resaltada, y mostrando también, algunas líneas anteriores y posteriores a ella. Al final de la pantalla se reservan algunas líneas para mostrar los nombres de las variables y sus valores. La línea superior muestra los comandos que puede ingresar en este punto:
A medida que traza su programa, en la parte inferior de la pantalla aparecerán automáticamente los nombres de las variables y sus valores. Toda vez que una variable sea asignada, verá aparecer su nombre y el nuevo valor que recibe. Este valor se mantiene siempre actualizado. La variables privadas se borran automáticamente cuando las rutinas a las que pertenecen terminan. Cuando el área en que se muestran las variables se llena, las variables referenciadas menos recientemente se descartan para hacer lugar a las nuevas. El valor de una secuencia grande se cortará después de 80 caracteres. Para su comodidad, los números que están en el rango de los caracteres ASCII imprimibles (32-127), se muestran junto con el caracter ASCII correspondiente. El caracter ASCII estará en un color diferente (o entre comillas si el monitor es monocromático). Esto se hace para todas las variables, ya que Euphoria no sabe en general, cuando usted está pensando en un número como un caracter ASCII o no. También verá caracteres ASCII (entre comillas) en ex.err. Esto puede hacer que la pantalla se vea algo "ocupada", pero la información ASCII frecuentemente es muy útil. La pantalla de trazado adopta el mismo modo gráfico que la pantalla principal de salida. Esto hace la conmutación entre ellas más rápido y más fácil. Cuando un programa trazado requiere de un ingreso por teclado, aparecerá la pantalla principal de salida para permitirle escribir la entrada, tal como lo haría normalmente. Esto funciona bien para una entrada gets() (que lee una línea). Cuando se llama a get_key() (que muestrea rápidamente el teclado), tiene 8 segundos para ingresar el caracter, o de lo contrario asumirá que no hay entrada para esta llamada a get_key(). Esto le permite probar los casos de entrada y no entrada para get_key(). Cuando el programa llama a trace(3), se activa el trazado a un archivo. El archivo, ctrace.out, se creará en el directorio actual, conteniendo las últimas 500 sentencias Euphoria que el programa ejecutó. Este archivo funciona como un búfer circular que mantiene como máximo 500 sentencias. Toda vez que se alcanza el final del archivo ctrace.out, la próxima sentencia se escribe otra vez al comienzo. La última sentencia ejecutada está seguida siempre por "=== THE END ===". Debido a su naturaleza circular, la última sentencia ejecutada puede aparecer en cualquier parte de ctrace.out. La sentencia que sigue a "=== THE END ===" es la última de las 500 anteriores. Esta forma de trazado está soportada tanto por el intérprete de la Edición Completa, como por el Traductor Euphoria a C. Es particularmente útil cuando ocurren errores a nivel de máquina que le evitan a Euphoria escribir en el archivo de diagnóstico ex.err. Al mirar la última sentencia ejecutada, puede conjeturar acerca de la razón por la que el programa se abortó. Quizás la última sentencia era un poke() a una posición ilegal de memoria. Quizás fue una llamada a una rutina de C. En algunos casos podría ser un bug en el intérprete o el Traductor. El código fuente de una sentencia se escribe en ctrace.out, y se descarga justo antes que la sentencia se ejecute, por lo que la caida del programa ocurrirá durante la ejecución de la última sentencia que ve en ctrace.out.
3.2 Análisis de perfiles de ejecución (solamente en la Edición Completa) Si especifica with profile (DOS32, WIN32 o Linux), o with profile_time (solo DOS32), el intérprete producirá un listado especial de su programa, llamado perfil, al finalizar la ejecución. Este listado se guarda en el archivo ex.pro del directorio actual. Hay dos tipos disponibles de análisis de perfiles: análisis por conteo de ejecución, y análisis por tiempo. El análisis por conteo de ejecución se obtiene al especificar with profile. El análisis por tiempo se obtiene al especificar with profile_time. No puede mezclar los dos tipos de análisis en una sola corrida del programa. Necesitará hacer dos corridas separadas. Corrimos el programa de pruebas sieve8k.ex en demo\bench para ambos tipos de análisis. Los resultados están en sieve8k.pro (análisis por conteo de ejecución) y sieve8k.pro2 (análisis por tiempo). El análisis de perfiles por conteo de ejecución muestra en forma precisa la cantidad de veces que cada sentencia del programa se ejecutó. Si una sentencia no se ejecuta nunca, el campo de conteo estará en blanco. El análisis de perfiles de ejecución por tiempo (solo DOS32) muestra una estimación del tiempo total consumido en ejecutar cada sentencia. Esta estimación se expresa como procentaje del tiempo consumido por analizar su programa. Si una sentencia no se muestreó nunca, el campo de procentaje estará en blanco. Si ve 0.00 significa que la sentecia se muestreó, pero no fue suficiente para obtener un puntaje de 0.01. Solamente las sentencias compiladas con with profile o with profile_time se muestran en el listado. Normalmente especificará tanto with profile como with profile_time al inicio de su archivo .ex principal, por lo que puede obtener un listado completo. Abra este archivo en el editor de Euphoria editor para verlo en colores. El análisis de perfiles de ejecución puede ayudarlo de muchas formas:
A veces querrá enfocarse en particular en una acción realizada por el programa. Por ejemplo, en el juego Language War, encontramos que el juego en general era suficientemente rápido, pero cuando explotaba un planeta, disparando 2500 píxeles en todas direcciones, el juego se hacía lento. Queríamos acelerar la rutina de la explosión. No nos importaba el resto del código. La solución fue llamar a profile(0) al comienzo de Language War, sólo después de with profile_time, para desactivar el análisis, y luego llamar a profile(1) al comienzo de la rutina de la explosión y profile(0) al final de ella. De esta forma pudimos correr el juego, creando numerosas explosiones, y registrando muchas muestras, solo para el efecto de la explosión. Si las muestras se cargaron contra otras rutinas de bajo nivel, sabríamos que esas muestras ocurrieron durante una explosión. Si hubiéramos analizado el programa entero, el cuadro no habría sido tan claro, ya que las rutinas de bajo nivel habrían sido usadas también para mover las naves, dibujar los phasors, etc. profile() puede ayudar en la misma forma cuando hace el análisis por tiempo.
Con cada pulso del reloj del sistema se genera una interrupción. Al especificar with profile_time Euphoria realizará un muestro del programa para ver cuales sentencias se ejecutan en el momento exacto que ocurre cada interrupción. Estas interrupciones normalmente ocurren 18.2 veces por segundo, pero si llama a tick_rate() puede elegir una tasa mucho más alta y así obtener un análisis de perfiles por tiempo más exacto, ya que estará basado en más muestras. Por defecto, si no llama a tick_rate(), entonces tick_rate(100) se llamará automáticamente cuando se inicie el análisis. Puede establecerlo aún más alto (hasta decir 1000) pero puede empezar a afectar el rendimiento del programa. Cada muestra necesita 4 bytes de memoria y el espacio de búfer, normalmente, se reserva para 25000 muestras. Si necesita más de 25000 muestras, puede solicitarlo así: with profile_time 100000 reservará espacio para 100000 muestras (poe
ejemplo). Si el búfer se desborda verá una advertencia al
comienzo de ex.pro. A 100 muestras
por segundo su programa puede correr por 250 segundos antes de usar las
25000 muestra por defecto. No es factible para Euforia agrandar dinámicamente
el búfer de muestra durante el manejo de una interrupción.
Esa es la razón por la que tiene que especificarlo en su programa.
Después de completar cada sentencia ejecutable de alto nivel, Euphoria
procesará las muestras acumuladas hasta ahora, y liberará
el búfer para más muestras. De este modo, el perfil puede
basarse en más muestras que en el espacio reservado que tiene realmente.
Los procentajes mostrados en el margen izquierdo de ex.pro, se calculan dividiendo la cantidad de veces que una sentencia en particular se muestrea, por la cantidad total de muestras tomadas. Por ejemplo, si una sentencia se muestrea 50 veces de un total de 500 muestras, entonces el valor 10.0 (10%) aparecería en el margen al lado de la sentencia. Cuando se deshabilita el análisis de perfiles con profile(0), se ignoran las interrupciones, no se toman muestras y la cantidad total de muestras no se incrementa. Tomando más muestras, puede obtener resultados más precisos. Sin embargo, una situación en la que hay que tener cuidado es el caso donde un programa se sincroniza con la inrerrupción del reloj, esperando a time() para avanzar. Nunca se tienen que muestrear las sentencias ejecutadas después del punto donde el reloj avanza, porque podrían dar una imagen muy distorsionada. Por ejemplo: while time() < LIMIT do
end while
x += 1 -- esta sentencia no se muestreará nunca
A veces, verá un porcentaje significativo al lado de una sentencia return. Esto se debe generalmente al tiempo consumido en la desasignación del almacenamiento de variables temporales y privadas usadas dentro de la rutina. También puede aparecer un tiempo significativo en la desasignación del almacenamiento, cuando asigna un nuevo valor a una secuencia grande. Si el intercambio a disco comienza a suceder, puede notar grandes tiempos atribuidos a las sentencias que necesitan tener acceso al archivo de intercambio, tal como sentencias que acceden a los elementos de una secuencia grande descargada al archivo de intercambio. |