Algo de Linux: octubre 2009

martes, 27 de octubre de 2009

Analizar los logs de access.log de squid

Me he dado cuenta, viendo los reports de sarg, que el mayor consumo de ancho de banda de mi centro se lo llevan las actualizaciones de windows update de los ciclos. Así que, me he puesto a trabajar en intentar reducir ese consumo mediante el proxy-caché squid.

No voy a entrar en detalles de cómo configurar squid porque lo que ahora me interesa es terminar de configurarlo para que cachee lo máximo posible. Aunque intentaré hacerlo en otro artículo, más que nada para recordar cómo monté el proxy, por si necesito hacerlo en otro momento.

Para hacer pruebas, he necesitado analizar los logs del archivo access.log, en el que hay un montón de líneas que al principio pueden parecernos complicadas, pero que cuando nos familiarizamos con ellas entenderemos cómo funciona el cacheo de archivos.

Lo primero que he hecho es hacer pasar el tráfico de una máquina por el proxy. Esto es fácil si tenemos un servidor dhcp en el que hacemos que la puerta de enlace asignada sea la ip del proxy.

Luego, en el proxy he ejecutado el comando tail para que me vaya mostrando lo que se va almacenando en el access.log:

# tail -f /var/log/squid/access.log

Y he comenzado a realizar actualizaciones en la máquina cliente para ver cómo trabaja el proxy.

Al ejecutar el comando, tail -f /var/log/squid/access.log veremos circular por la pantalla una serie de mensajes.

Básicamente, hay 2 tipos de mensajes:
Veamos los mensajes TCP, que son los que nos interesan para estudiar las peticiones que nos llegan por el puerto HTTP y realizar el cacheo:

TCP_ HIT: Hay una copia válida del objeto solicitado en la caché. Por tanto, se servirá el objeto desde la caché.

TCP_MISS: El objeto solicitado no se encontraba en la caché. Por tanto, squid tendrá que descargarlo desde internet.

TCP_REFRESH_HIT: El objeto solicitado estaba en la caché, pero es viejo. Se hace una petición de traer un archivo más nuevo.

TCP_REF_FAIL_HIT: El ojeto solicitado estaba en la caché, pero era viejo. La petición de validación del objeto falló. Por lo tanto se servirá el objeto de la caché.

TCP_REFRESH_MISS: El objeto solicitado estaba en la caché, pero era viejo. Se hizo una petición de trajer un objeto más nuevo y se trajo.

TCP_CLIENT_REFRESH: Este mensaje nos indica que el cliente abre una página que tiene orden de obtener siempre un archivo nuevo.

TCP_CLIENT_REFRESH_MISS: El cliente solicita el refresco de una web determinada, pidiendo una nueva versión.

TCP_IMS_HIT: El cliente ha solicitado una nueva versión de un objeto que estaba cacheado, pero se encuentra que el objeto de la caché aún no estaba caducado, es decir, que ya era lo más nuevo posible.

TCP_IMS_MISS: El cliente solicita nueva copia acerca de un objeto viejo.

TCP_SWAPFAIL: Se cree que el objeto se encuentra en la caché, pero por alguna razón no se puede acceder.

TCP_DENIED: Se deniega el acceso a dicha petición. Veamos las posibles denegaciones:
  • TCP_DENIED/400 indica que la petición tenía una mala sintaxis. El usuario (o un link a una página web) hizo algo mal.
  • TCP_DENIED/401 indica que la página requiere autorización.
  • TCP_DENIED/403 lo más probable es que sea un sitio bloqueado por una de las listas de control de acceso del Squid.
  • TCP_DENIED/407 indica que el proxy está configurado para usar alguna forma de autenticación y esta autenticación está fallando.
Mensajes UDP con los que podemos encontrarnos:Además, veremos también códigos de resultado de la fuente de la página:
Por otra parte, es interesante también observar los mensajes del archivo /var/log/squid/store.log. Si al descargar un archivo por primera vez, hacemos un:

# tail -f /var/log/squid/store.log

Veremos un mensaje con un GET por el que nos damos cuenta de que el archivo va a ser descargado, y cuando el archivo termine de descargarse, veremos un mensaje con un SWAPOUT, que nos indica que el archivo ha sido sacado de la caché para ofrecérselo al cliente.

Si volvemos a descargar el mismo archivo y no hay una versión más nueva en internet, ya no veremos un GET, sino que encontraremos un mensaje de SWAPOUT.

Si queremos ver estadísticas de resultados, recomiendo instalar Calamaris, un generador de informes de la actividad de caché que nos permitirá obtener datos estadísticos de uso de la caché de squid en formato ASCII o HTML.