Lección 06 – Debug

Aventuras en Megadrive: Debug

 

Fuentes del SGDK:

https://github.com/Stephane-D/SGDK/blob/master/inc/kdebug.h
https://github.com/Stephane-D/SGDK/blob/master/inc/tools.h
https://github.com/Stephane-D/SGDK/wiki/Tuto-Maths

 

El SGDK incluye una serie de funciones para poder hacer debug en tiempo de ejecución.
Estas funciones están pensadas para utilizarlas junto con el compilador GensKmod.

En esta entrada voy a explicar las formas más sencillas y habituales de debug. Más adelante y en otra entrada, explicaré formas más sofisticadas.

En mi github podrás encontrar un ejemplo bastante completo sobre esta entrada.

 

Antes de comenzar

Hemos de añadir siempre a nuestro programa:

#include "KDebug.h"
#include "tools.h"
#include "timer.h"

Si no lo añadimos, CB lo añadirá por nosotros y nos advertirá al compilar.

En GensKmod hemos de activar Option / Debug / Active Development Features:

captura36

La ventana Debug Message se encuentra en CPU/Debug/Messages:

captura35

 

KDebug en GensKmod

Funciones útiles para debuggear con GensKmod:

-- de "KDebug.h" --
void KDebug_Halt();
void KDebug_Alert(const char *str);
void KDebug_AlertNumber(u32 nVal);
void KDebug_StartTimer();
void KDebug_StopTimer();
-- de "tools.h" --
void KLog(char* text);

 

PAUSAR JUEGO

KDebug_Halt();

Pausa el juego. Pulsando ESC continua.

En la ventana debug se muestra el texto «Pause requested by game»

captura37

¡Ojo! Antes de pulsar ESC haz clic en la ventana principal del GensKmod para dejarla como ventana activa. Si tenemos como ventana activa la ventana Messages, pulsar ESC la cierra ( y tendremos que volver a abrirla).

 

MOSTRAR MENSAJES

KDebug_Alert(const char *str);

Muestra en la ventana CPU/DEBUG/MESSAGES un texto cualquiera, por ejemplo TEST:

KDebug_Alert("TEST");

Siempre se va a escribir una línea por cada KDebug_Alert() ejecutado. Por tanto podemos insertar líneas en blanco en la Ventana de Debug simplemente haciendo:

KDebug_Alert(" ");

Es útil para separar diferentes cosas cuando se imprimen muchos mensajes.

También podemos mostrar el contenido de una variable. Si la variable es numérica,  antes debemos convertirla a una cadena. Debemos asegurarnos de usar la función de conversión adecuada. Por ejemplo:

char *char_entrada = "esto es una cadena de ejemplo";
char char_salida[32];

//imprime "esto es una cadena de ejemplo";
KDebug_Alert(char_entrada);

//imprime un número entero,antes debemos convertirlo a texto
int mi_numero = 1200;
intToStr(mi_numero,char_salida,1);
KDebug_Alert(char_salida);

//imprime un número entero negativo
mi_numero = -1200;
intToStr(mi_numero,char_salida,1);
KDebug_Alert(char_salida);

//imprime un número en punto fijo positivo
fix32 mi_numero32 = FIX32(5.4);
fix32ToStr(mi_numero32,char_salida,1);
KDebug_Alert(char_salida);

//imprime un número en punto fijo negativo
mi_numero32 = FIX32(-5.4);
fix32ToStr(mi_numero32,char_salida,1);
KDebug_Alert(char_salida);

captura38

Puntualizar dos cosas.

  • El SGDK nos proporciona funciones específicas para evitar tener que hacer las conversiones. Las veremos a continuación.
  • Usar números de punto fijo (fix16 y fix32) tiene inconveniente del redondeo. En el código anterior metemos la cantidad de 5.4 en una variable y, al mostrar el valor por la ventana de Debug, obtenemos 5.39  . Hablaremos de esto en un futuro post de funciones matemáticas.

 

MOSTRAR VARIABLES NUMÉRICAS

KDebug_AlertNumber(u32 mi_variable);

Escribe en la ventana CPU/DEBUG/MESSAGES el valor de «mi_variable».

Mucho ojo con esta función, porque como entrada hemos de proporcionarle el valor de mi_variable en formato u32 (32 bits unsigned integer,  equivalent to unsigned long).

Si no lo hacemos, podemos obtener resultados cuanto menos curiosos.

Por ejemplo, si metemos un entero como valor de entrada, nos devuelve el valor en hexadecimal, no es precisamente intuitivo.

captura39

En el ejemplo tenemos la variable entera con el valor 100 (y después -100), y KDebug_AlertNumber() nos devuelve 64 y FFFFFF9C.

El 100 decimal equivale al 64 hexadecimal ( 100d = 64h ). Y -100d = FFFFFF9C h.

Para hacer estas conversiones de forma sencilla podemos utilizar la calculadora de Windows, en el modo programador (Ver/Programador):

captura40

No obstante para evitar tener que lidiar con molestas conversiones, existen toda una serie de funciones para mostrar formatos específicos en la ventana de Debug. Vamos a verlas.

 

MOSTRAR VARIABLES: FUNCIONES KLOG

Las funciones Klog() nos proporcionan funciones específicas para mostrar textos y valores por la ventana de Debug. Aquí tienes todos los incluidos en el SGDK, veremos los más importantes:

 

Mostrar texto

void KLog(char* text);

Muestra un texto en la ventana Debug.

 

Mostrar texto + numero entero positivo

void KLog_U1(char* t1, u32 v1);

Muestra un texto (opcional) seguido del valor del entero positivo (unsigned,u32).
Por ejemplo, para mostrar el valor de mi_variable sin ningún texto delante:

int mi_variable = 100;
KLog_U1("", mi_variable);

Mostrar texto + numero entero positivo (varias veces)

void KLog_U2(char* t1, u32 v1, char* t2, u32 v2);
void KLog_U3(char* t1, u32 v1, char* t2, u32 v2, char* t3, u32 v3);
void KLog_U4(char* t1, u32 v1, char* t2, u32 v2, char* t3, u32 v3, char* t4, u32 v4);

Podemos mostrar hasta 4 textos y 4 variables enteras positivas utilizando estas funciones. Todo depende de nuestras necesidades, usarlas nos evita tener que estar concatenando cadenas y variables numéricas.

Por ejemplo podemos sacar los valores (x,y) de un sprite en tiempo real.

 

Mostrar texto + numero entero (positivo o negativo)

void KLog_S1(char* t1, s32 v1);
void KLog_S2(char* t1, s32 v1, char* t2, s32 v2);
void KLog_S3(char* t1, s32 v1, char* t2, s32 v2, char* t3, s32 v3);
void KLog_S4(char* t1, s32 v1, char* t2, s32 v2, char* t3, s32 v3, char* t4, s32 v4);

Funciona como los anteriores con la diferencia que internamente usa un s32 (unsigned), por tanto coge números enteros positivos y negativos.

De la misma forma hay funciones equivalentes para imprimir por ventana de Debug varios textos y números enteros.

 

Mostrar texto + numero en punto fijo (16 bits)

void KLog_f1(char* t1, fix16 v1);
void KLog_f2(char* t1, fix16 v1, char* t2, fix16 v2);
void KLog_f3(char* t1, fix16 v1, char* t2, fix16 v2, char* t3, fix16 v3);
void KLog_f4(char* t1, fix16 v1, char* t2, fix16 v2, char* t3, fix16 v3, char* t4, fix16 v4);

El equivalente para imprimir fix16, números en punto fijo de 16 bits. En la última versión del SGDK fix16 se puede abreviar como f16.

 

Mostrar texto + numero en punto fijo (32 bits)

void KLog_F1(char* t1, fix32 v1);
void KLog_F2(char* t1, fix32 v1, char* t2, fix32 v2);
void KLog_F3(char* t1, fix32 v1, char* t2, fix32 v2, char* t3, fix32 v3);
void KLog_F4(char* t1, fix32 v1, char* t2, fix32 v2, char* t3, fix32 v3, char* t4, fix32 v4);

El equivalente para imprimir fix16, números en punto fijo de 16 bits. En la última versión del SGDK fix32 se puede abreviar como f32.

 

 

TEMPORIZADORES / CONTADORES

KDebug_StartTimer();
KDebug_StopTimer();

Estas funcionen nos sirven para medir un evento. Por ejemplo puede servir para saber cuánto tarda una función en efectuar una serie de cálculos, y comparar con esa otra función que hemos encontrado en un foro.

La primera función pone en marcha un contador, la segunda lo para y, automáticamente, muestra el número de ciclos en la pantalla de Debug.

Son 7.61 millones de ciclos por segundo (=7.61 MHz del M68K). Por tanto para sacar a segundos divide el número que te sale en la ventana Debug por 7.610.000

KDebug_StartTimer();  y KDebug_StopTimer();  son funciones son muy sencillas de usar, no obstante sólo es (1) un temporizador y sólo se puede consultar el resultado en la ventana Debug. No podemos usar el resultado en nuestro programa, almacenarlo o  compararlo.

 

 

OTROS TEMPORIZADORES / CONTADORES

Afortunadamente tenemos los temporizadores que timer.h pone a nuestra disposición.

Advertencia: estas funciones utilizan V-Int para contar, por tanto desactivar V-Int hace que estos métodos no funcionen.

 

SUBTICKS

u32 getSubTick();

Desde que se inicia la consola (o desde que pulsamos RESET), el sistema inicia un contador. Con esta función obtenemos cuantos subticks lleva ese contador.

Son aprox. 76800 ‘subticks’ por segundo ( constante SUBTICKPERSECOND ).

Llamando a esta función dos veces y restando, obtenemos cuantos subticks han pasado.

 u32 starttime = getSubTick();
...
//hacemos cosas
...
u32 endtime = getSubTick();
 //sacamos la diferencia
char outputString[16]; 
uintToStr(endtime - starttime, outputString, 16);
VDP_drawText(outputString, 5, 6); // imprime por pantalla
KLog(outputString);               //imprime en la ventana debug

Para sacarlo en segundos sólo debemos hacer este cambio (no saca décimas de seg ojo)

uintToStr((endtime - starttime)/SUBTICKPERSECOND, outputString, 16);

 

Si no queremos tanta precisión, podemos hacer lo mismo con

u32 getTick()

El funcionamiento es el mismo, son 300 ticks por segundo ( TICKPERSECOND ).

 

Para sacar décimas de segundo lo tendremos que calcular a mano sabiendo que una décima de segundo son 7680 subticks / 30 ticks.

 

16 TIMERS

startTimer(numTimer);
u32 getTimer(numTimer, TRUE | FALSE);

Tenemos 16 temporizadores (del 0 al 15) que podemos lanzar, por ejemplo, así:

startTimer(0); //lanza el temporizador 0
//..
//hacemos cosas
//..
num_subticks = getTimer(0, FALSE);

startTimer() «lanza» el temporizador correspondiente. En realidad lo que hace el guardar el número de subticks de ese instante (recordemos que se van contando desde que se inicia la consola).

Tras «hacer cosas», getTimer() lee el núm de subticks en ese instante y hace la resta con el valor obtenido en el paso anterior. Devuelve este resultado y, si pusimos FALSE, detiene el timer. Si pusimos TRUE, vuelve a lanzar de nuevo el timer (internamente lanza startTimer de nuevo).

 

FPS

Para mostrar los fps utilizaremos:

VDP_showFPS(FALSE);      // TRUE = con decimales

La cantidad sale en pantalla en una posición fija ( no se puede cambiar ).

 

 

 

Debug en pantalla

Si preferimos pintar datos en pantalla, el SGDK nos proporciona, entre otras, la función

VDP_drawText(texto, x, y);  //(x,y) en tiles

Podemos escribir texto directamente («hola»)  o  bien variables numéricas siempre que hagamos la conversión adecuada, ejemplo:

static void pinta_debug()
{
u16 num_sprites = SPR_getNumActiveSprite();
char integer_string[32];

sprintf(integer_string, "%d", num_sprites); //convertimos a string

VDP_drawText("NUM SPRITES:", 2, 20);
VDP_drawText(integer_string, 16, 20);
}

En este ejemplo hacemos uso de la función

 SPR_getNumActiveSprite(); //cantidad de meta-sprites activos

No nos engañemos, SPR_getNumActiveSprite() no va a devolverte el número de sprites si no el número de meta-sprites que está manejando el SGDK.

Por HW, la mega puede manejar sprites de hasta 4×4 tiles (32×32 píxels), pero el SGDK nos permite utilizar sprites mayores de lo que permite el HW, 16×16 tiles ( 128×128 píxels), y para ello utilizar grupos de HW-sprites.

Por tanto cuidado en cómo interpretamos esta función, puede ser engañosa.

 

Problemas de conversión con sprintf

Por comodidad siempre utilizamos el tag %d para introducir variable numéricas en el sprintf(). Esto funciona bien porque normalmente usamos enteros positivos pequeños.

Hasta que el número es mayor que 32767 y VDP_drawText() pinta números negativos.

¿Por qué? En C un INT (entero, con signo) se representa con 16 bits (2 elevado a 16), eso son 65536 números. La mitad (positivos) van del 0 al 32767, por tanto si intentamos meter un número mayor en un INT, C entiende que nos vamos a la parte negativa: 32768 es el -1, 32769 es el -2,etc.

Si usamos una variable u16 (unsigned int, entero sin signo) para guardar un número mayor de 32767, lo hará correctamente, pero si utilizamos el código anterior, tampoco se pintará bien, veremos números negativos.

Sí, la variable u16 usa todos los 16 bits un rango de números positivos, del 0 al 66535, e internamente ha guardado el número correcto, PERO el tag %d del sprintf() entiende que el número que le estás introduciendo es un número con signo y actúa en consecuencia, de ahí la confusión de usar un número grande y ver números negativos en pantalla.

En este caso hemos de utilizar el tag %u :

sprintf(integer_string, "%u", num_sprites); //convertimos a string

 

— RESUMEN —
%d : números enteros (con signo): de -32768 a 32767
%u : números enteros (sin signo) : de 0 a 65535

 

¿Y si quiero usar variables de 32 bits?

No se recomienda el uso de variables de 32bits por ser especialmente lentas.

Dicho esto, sprintf() no soporta variables de 32bits (u32 / s32) con el SGDK.
Para solucionarlo puedes usar intToStr():

s32 s32_fuente = 700000;
char string_destino[32];
intToStr(s32_fuente, string_destino, 1);
VDP_drawText(string_destino, 16, 20);

Recuerda que intToStr() está limitado a números entre [-500.000.000 … 500.000.000].

 

Problemas de visibilidad con sprintf

Los textos de la fuente que lleva por defecto el SGDK se pintan con el color 15 de la paleta PAL0. El fondo se colorea por defecto con el color 0 de la PAL0.

Por defecto, el SGDK inicializa las paletas de la siguiente forma (ejemplo Hello World, primera lección):

En este ejemplo fondo negro y texto en blanco.

Podemos cambiar la paleta seleccionada con

VDP_setTextPalette(PAL0/1/2/3);

PAL0: El texto usará el color 15 (que es el color 16 de la paleta completa, recordar que empieza en 0)
PAL1: El texto usará el color 31 (que es el color 32 de la paleta completa...)
PAL2: El texto usará el color 47 (que es el color 48 de la paleta completa...)
PAL3: El texto usará el color 63 (que es el color 64 de la paleta completa...)

Mucho cuidado porque si usamos el mismo color para fondo y texto no veremos nada.
Típico fondo negro y color de texto negro, se pinta el texto pero no se ve.

Además de cambiar el color se pueden usar fuentes personalizadas, que no es más que cargar una serie de tiles con todas los caracteres necesarios (letras, números, caracteres especiales, etc) y pintados con el color de la paleta que queramos, como si fuesen un sprite o un fondo.

Más adelante profundizaré en este tema ( funciones VDP_loadFont, VDP_loadBMPFont(), etc).

 

 

 

 

Errores Típicos

Lanzar una función en un momento determinado

Lanzamos una función en un momento determinado (por ejemplo cuanto pasan 3 segundos) pero los resultados no son los esperados.

¿Has tenido en cuenta que para cuando hagamos…

if  (tiempo==3)  lanzar_funcion();

… la mega ejecutará hasta 50/60 veces ese código?

Es decir, estás dando por hecho que en el 3er segundo sólo se ejecutará esa condición 1 vez, pero la consola lanzará esa función hasta 50/60 veces (como máximo) ya que el tiempo solemos calcularlo en función de un contador que se ejecuta 1 vez por frame (al menos yo, contador/60 = segundo actual).

 

GITHUB

El código de esta lección, y de todas las demás, lo podrás encontrar en mi github:

https://github.com/danibusvlc/aventuras-en-megadrive