Trabajando en un proyecto de logging, encontré una situación particular por la que no había pasado antes. En sí, el proyecto “Logxar” requiere tener la capacidad de loguear mensajes en distintos niveles, definidos tal que:
class LogLevel {
static #Debug = 0
static #Info = 1
static #Warn = 2
static #Error = 3
static #Critical = 4
}
Esta definición me permite tener bastante granularidad a la hora de elegir cuántos logs quiero en mi terminal.
Sin embargo, el simple hecho de enviar un texto al standard output (o a un archivo, en mi caso) no es suficiente, ya que necesito más información para facilitar el debugging.
La información que necesito es:
- Hora en la que fue ejecutado el log
- Nivel del log
- Archivo donde se ejecutó
- Línea donde se ejecutó
- Mensaje de log
Hasta acá parece fácil, pero ¿Cómo obtengo esa información con JavaScript nativo? Necesito hacer uso del stack trace.
Breve recordatorio: Call Stack
Un stack o pila, es una estructura de datos muy usada en programación. Está diseñada para almacenar una colección de elementos según el principio Last In First Out (LIFO). Esto quiere decir que el elemento añadido más recientemente será el primero en ser extraído.
Las pilas son cosas comunes del día a día:
- Una pila de libros
- Una pila de archivos
- Una pila de pizzas
En cada uno de estos casos, el último elemento añadido será el primero en ser retirado.
Ahora vamos a lo interesante: un call stack es un tipo de pila especial que lleva seguimiento de cada llamada de función. Cada vez que se llama a una función, la información se añade al call stack. A continuación se muestra ejemplo práctico:
function add(a, b) {
return a + b;
}
function multiply(a, b) {
return a * b;
}
function calculate() {
const x = 10;
const y = 5;
const result1 = add(x, y);
const result2 = multiply(add(1, 2), result1);
return result2;
}
calculate();
Cuando calculate es llamado, la información se añade encima de la pila. Luego, la función llama a add , que también añade su información a la pila. Cuando add termina su ejecución, se añade multiply al call stack.
Solución
El objetivo es obtener el stack trace, este es una representación del call stack en un momento dado, es decir, un registro de su estado actual.
Lo primero que me vino a la mente fue hacer uso de console.trace()
function foo() {
console.trace("Calling foo");
}
foo();
Trace: called foo
at foo (C:\Users\lazar\dev\test\index.js:2:11)
at bar (C:\Users\lazar\dev\test\index.js:10:3)
at main (C:\Users\lazar\dev\test\index.js:6:3)
...
Parece ser exactamente lo que necesito; esto imprime el stack trace en el momento dado de la ejecución. Se puede observar claramente como main llama a bar, que a su vez llama a foo, donde fue llamado el log.
El problema es que no me permite interactuar programáticamente con el resultado, sino que imprime directamente el call stack al stderr.
La solución real que encontré (sin usar librerías externas) fue hacer uso de la clase Error , tal que
try {
throw new Error("Test error");
} catch (error) {
console.log(error.stack);
}
Error: Test error
at foo (C:\Users\lazar\dev\test\index.js:3:11)
at bar (C:\Users\lazar\dev\test\index.js:14:3)
at main (C:\Users\lazar\dev\test\index.js:10:3)
...
Perfecto, ahora sí es posible acceder a la propiedad stackdel objeto Error y guardar la string del stack trace en una variable para manipular inmediatamente.
Ahora, es posible mejorar esta sintaxis haciendo uso de Error.captureStackTrace
const debugInfo = {}
Error.captureStackTrace(debugInfo)
console.log(debugInfo.stack)
Error
at foo (C:\Users\lazar\dev\test\index.js:3:9)
at bar (C:\Users\lazar\dev\test\index.js:12:3)
at main (C:\Users\lazar\dev\test\index.js:8:3)
¡Excelente! Ahora sí, una solución legible y programática para obtener el stack trace en un momento dado de la ejecución. Pero hay un problema más….
¿Cómo sé la línea exacta que necesito obtener?
Como expliqué antes, el call stack es una estructura LIFO, por lo que la línea superior es la llamada más reciente a una función (donde se capturó el stack).
Técnicamente, si conoces el flujo de llamadas en tu código (espero que si) podés deducir qué línea necesitás, por ejemplo:
function nivel1() {
nivel2();
}
function nivel2() {
nivel3();
}
function nivel3() {
const err = new Error("algo pasó");
Error.captureStackTrace(err);
console.log(err.stack);
}
nivel1();
Error: algo pasó
at nivel3 (<tu archivo>:9:9)
at nivel2 (<tu archivo>:5:3)
at nivel1 (<tu archivo>:2:3)
at <anonymous> (<tu archivo>:13:1)
si ya conoces el flujo de ejecución (sabés que siempre se llama nivel1 → nivel2 → nivel3), podés deducir que la línea que realmente te interesa para tu log es la segunda (at nivel2).
En código podrías hacer algo así:
function nivel3() {
const err = new Error();
Error.captureStackTrace(err);
const lines = err.stack.split("\n");
const relevant = lines[2].trim();
console.log(relevant);
}
En mi opinión, es una solución elegante que permite capturar el stack completo y generar un log lo más detallado posible para mejorar la Developer experience.