Last Updated: February 25, 2016

Tus logs no son sólo para debuguear

Imprimiendo tus logs con cierto formato, podrás analizarlos, extraer estadísticas e incluso recibir notificaciones cuando ciertos eventos sucedan.

Formatea tus logs usando logfmt

Hay varios formatos que se pueden usar para extraer información de tus logs. Acá vamos a hablar de logfmt.

La idea es formatear tu información usando KVP(Key Value Pairs). Consiste en dividir la información en pares de llave y valor. Luego los imprimes separados por un signo de igual.

Ejemplos:

Si quieres imprimir el status http y el URL que visitó un usuario.

En lugar de:

el status es 200 y la página es /trip/mex-mty-18-12-2014

Imprimirias:

status=200 path="/trip/mex-mty-18-12-2014”

Si quieres imprimir el nombre y apellido de una persona

En lugar de:

El nombre del pasajero es Elias, el apellido es Matheus

Imprimirias:

passenger.name=Elias passenger.lastname=Matheus

Consulta tus logs "SQL style" usando Logentries

Al tener los valores formateados, puedes consultarlos, usando una aplicacion, de manera similar a las consultas de una base de datos. Un ejemplo de dicho aplicacion es Logentries.

LogEntries

Puedes realizar consultas sencillas("WHERE"), contar resultados("COUNT"), agrupar resultados de acuerdo a una llave("GROUP BY"), sumar los resultados("SUM"), sacar el promedio de un valor, entre otras cosas.

La sintaxis es parecida a los pipes de linux. Para explicarla, mejor usamos un ejemplo.

Ejemplo con el Router de Heroku:

El router de Heroku imprime una linea por cada llamada que recibe tu aplicación en los logs. Por ejemplo:

at=info method=GET path="/api/terminals.json?q=c" host=www.reserbus.mx request_id=bfac49de-cf37-4caf-9094-587f7dd6f4eb fwd="201.127.220.150" dyno=web.2 connect=1ms service=42ms status=200 bytes=1565

at=info method=POST path="/payments/27964432/complete" host=www.reserbus.mx request_id=3e432617-2318-4a88-8f74-4289beecb99e fwd="187.193.105.108" dyno=web.1 connect=1ms service=51ms status=200 bytes=1029

at=info method=GET path="/viajes/san-luis-potosi/t-casas-grandes" host=www.reserbus.mx request_id=6ed170ba-548b-405c-bbd2-f01ca8c59f40 fwd="157.55.39.86" dyno=web.1 connect=0ms service=506ms status=200 bytes=9754

at=info method=POST path="/payments/27961432/complete" host=www.reserbus.mx request_id=3e432617-2318-4a88-8f74-4289beecb99e fwd="187.193.105.101" dyno=web.1 connect=1ms service=51ms status=500 bytes=1029

Leyendo la primera linea, vemos muchos KVP's. En la primera linea, vemos la llave "at", seguida del valor "info". Este atributo significa el nivel de logging de la llamada. Luego viene la llave "method", seguido del valor "GET". Esto se refiere al metodo HTTP de la llamada. Luego viene el atributo path, seguido del valor "/api/terminals.json?q=c". Esto se refiere al path que visito el usuario.

Entendiendo el formato, podemos realizar búsquedas usando logentries.

Regresa todas las llamadas realizadas por la IP "187.193.105.101"

fwd=187.193.105.101

Para nuestro ejemplo, devolvería:

at=info method=POST path="/payments/27961432/complete" host=www.reserbus.mx request_id=3e432617-2318-4a88-8f74-4289beecb99e fwd="187.193.105.101" dyno=web.1 connect=1ms service=51ms status=500 bytes=1029

Cuenta el número de requests a pagos que hayan dado status 500

"path=/.&ast;payments.&ast;/ status=500 | count"

En este caso vemos dos cosas interesantes. La primera es que se pueden hacer búsquedas con atributos usando una expresión regular. La segunda es que vemos un pipe("|" ) casi al final de la búsqueda. Esto nos va a permitir introducir un comando nuevo, que en este caso es contar.

Para nuestro ejemplo, hacer esta búsqueda devolvería: