Apache: Añadir el tiempo de respuesta en los logs

Apache es una de esas herramientas tan complejas para las que todos utilizamos un porcentaje ínfimo de las opciones que incorpora (y tampoco necesitamos más). Esa complejidad probablemente será una de las razones por las que otros proyectos hayan apostado por alternativas más ligeras como nginx. Pero bueno, eso es otro tema. Aquí vamos a sacarle partido de esa complejidad.

Los logs de Apache tienen un formato predefinido en la configuración por defecto.  En el caso de Apache 2 en Ubuntu (y derivados de Debian), puedes encontrar una lista de los formatos de log dentro del archivo /etc/apache2/apache2.conf, con la directiva LogFormat:

LogFormat "%v:%p %h %l %u %t \"%r\" %>s %O \"%{Referer}i\" \"%{User-Agent}i\"" vhost_combined

LogFormat "%h %l %u %t \"%r\" %>s %O \"%{Referer}i\" \"%{User-Agent}i\"" combined

LogFormat "%h %l %u %t \"%r\" %>s %O" common

LogFormat "%{Referer}i -> %U" referer

LogFormat "%{User-agent}i" agent

Con lo anterior (en concreto con el formato combined) es perfectamente posible salir a la calle muy dignamente en la mayoría de casos. Eso ya nos aporta información sobre fechas, accesos, navegadores (incluyendo buscadores), respuestas y tamaños en bytes.

Crear un formato propio de log de Apache

Como puedes comprobar en los ejemplos por defecto, todas las variables vienen indicadas con un signo % y una lectra, o bien un %{nombre-entre-llaves} y una letra al final (para las variables de entorno la letra es la e, para las cabeceras de la petición es una i, etc.)

Para añadir un nuevo formato puedes partir de alguno de los casos anteriores (combined por ejemplo) y añadir tu variable:

LogFormat "%h %l %u %t \"%r\" %>s %O \"%{Referer}i\" \"%{User-Agent}i\" %I" sopadebits_combined

Puedes ver que hemos añadido el parámetro %I (número de bytes recibidos). Las dobles comillas puede que pasen desapercibidas pero son importantes: el formato de log va indicado dentro de comillas dobles, y si quieres añadir esas comillas dobles al log, es necesario escaparlas (\").

Con el log anterior, podemos acceder a nuestra configuración de host y modificar el formato del log que queremos:

CustomLog /var/log/apache2/localhost.log sopadebits_common

Añadir el tiempo de respuesta al log de Apache

Ahora sí, ya estamos a punto. Vamos a añadir el tiempo. Pues vaya, resulta que tenemos dos variables:

• %T proporciona el tiempo en segundos.
• %D lo proporciona en microsegundos

Pues ya puestos podríamos incluir las dos variables ¿verdad? Las añadiremos al final, después de user agent:

LogFormat "%h %l %u %t \"%r\" %>s %O \"%{Referer}i\" \"%{User-Agent}i\" %T %D" time_combined

Y como hemos hecho anteriormente, ya sólo debemos modificar la directiva CustomLog del virtualhost que queremos configurar con ese formato. Después de esto sólo queda utilizar un sistema para rastrear la información de los logs y detectar las peticiones más lentas. Pero eso queda para otra ocasión.

Otros casos podrían ser, por ejemplo, incluir el contenido de una cabecera de HTTP (por ejemplo generada por la propia aplicación) por ejemplo para llevar un control de las operaciones internas.