Hola, siento el tiempo que llevo sin escribir y además hoy nos vamos a desviar un poco de la administración de sistemas aunque intentaremos no alejarnos mucho del tema ya que utilizaremos los conocimientos adquiridos con este post para mejorar nuestra comprensión de lo que pasa con nuestro servidor apache en base a sus logs.
Como ya os comenté en otro post, antes de probar logstash implementé una solución en python para analizar los logs de apache, y como no vamos a ningún sitio sin un poco de programación vamos a revisar este miniproyecto que igual os puede servir para implementar cosas más grandes.
Como se suele decir en esto casos podéis hacer un fork del proyecto en esta dirección de GitHub. Ahí tenéis explicado en un perfecto inglés cómo poner en marcha los scripts, pero aquí vamos a explicar un poco más a fondo cómo se articula todo el código.
La idea global es la siguiente: tenemos un servidor postgresql, una clase de python que utiliza la librería sqlalchemy, un script que genera el esquema en la base de datos y otro script que mediante el uso de esta clase introduce la información contenida en un archivo de logs de apache.
Empecemos por el principio. Partiremos de una configuración de apache en la que tendremos la siguiente línea:
[...]
# LogFormats
LogFormat "%V\t%p\t[%{outstream}n/%{instream}n(%{ratio}n%%)]\t%a\t%t\t%m\t%U\t%q\t%H\t%s\t%B\t\"%{Referer}i\"\t\"%{User-agent}i\"\t%{Cookie}i\t%{Accept-Language}i\t%{Content-Language}o\t%{Accept-Encoding}i\t%{Content-Encoding}o\t%{Content-Location}o\t%{Vary}o\t%{Content-Type}o\t%{BALANCER_SESSION_STICKY}e\t%{BALANCER_SESSION_ROUTE}e\t%{MYCOOKIE}C\t%{BALANCER_WORKER_ROUTE}e\t%{BALANCER_ROUTE_CHANGED}e\t%D" combined
[...]
En el proyecto tenéis un archivo de ejemplo con unas 50 líneas para experimentar. Antes de ver cómo generamos el esquema en la base de datos y cómo le añadimos datos mostraremos la clase python con la que interactuaremos.
Lo que más me gusta de python, aparte del origen de su nombre, es que su sintaxis es muy clara y yo diría que incluso autoexplicativa. Partiré de la base de que conocéis un poco el lenguaje aunque cualquier tutorial os pondrá a un nivel adecuado para aplicar y ampliar los scripts que vamos a comentar aquí.
Veamos el código del script apachelogs.py:
#!/usr/bin/python
# -*- coding: utf-8 -*-
from sqlalchemy import DateTime, Column, Integer, BigInteger
from sqlalchemy import String, Sequence
from sqlalchemy.ext.declarative import declarative_base
Base = declarative_base()
class ApacheLog(Base):
__tablename__ = 'apache_log'
id_apache_log = Column(
Integer, Sequence('apache_log_id_seq'), primary_key=True)
server_name = Column(String)
port = Column(Integer)
original_deflate = Column(Integer)
final_deflate = Column(Integer)
ratio_deflate = Column(Integer)
remote_address = Column(BigInteger)
timestamp = Column(DateTime)
request_method = Column(String)
url_path_requested = Column(String)
query_string = Column(String)
request_protocol = Column(String)
status = Column(Integer)
response_size = Column(Integer)
header_referer = Column(String)
header_user_agent = Column(String)
header_cookie = Column(String)
header_accept_lang = Column(String)
reply_content_lang = Column(String)
header_accept_enc = Column(String)
reply_content_enc = Column(String)
reply_content_location = Column(String)
reply_vary = Column(String)
reply_content_type = Column(String)
# Added for back apache proxy extra configuration
balancer_session_sticky = Column(String)
balancer_session_route = Column(String)
my_cookie = Column(String)
balancer_worker_route = Column(String)
balancer_route_changed = Column(String)
request_duration = Column(Integer)
La librería SQLAlchemy nos sirve para interactuar con la base de datos como si estuviéramos tratando con objetos python. Lo primero que aparece en nuestro código son las importaciones necesarias, Integer, String, etc. Estos tipos son comunes a todos los interfaces que soporta SQLAlchemy, podríamos trabajar con MySQL utilizando esta misma clase e incluso con SQLite3, más adelante veremos dónde se define la entrada a la base de datos en la que nosotros configuraremos el acceso a postgresql.
La última importación es la función con la que vamos a declarar la tabla que utilizaremos. Con esta forma de declarar simplemente nombraremos las columnas y les asignaremos su tipo, para esto eran las importaciones de tipos. Tenemos más opciones y algunas incluso específicas de cada base de datos aunque para este caso tan simple no las usaremos.
La única cosa distinta que vemos en la declaración es el atributo __tablename__ con el que tendremos controlada la tabla en la propia base de datos por si queremos acceder a ella mediante el propio cliente de PostgreSQL, si no definiésemos este nombre sqlalchemy lo elegiría por nosotros y en casos más complejos se nos haría más difícil el seguimiento.
Por supuesto tenemos muchas más opciones para interactuar con nuestra base de datos favorita, sobre todo las relaciones entre tablas y cómo podemos realizar búsquedas en base a si cierto objeto está relacionado con otro utilizando la simplicidad de este lenguaje, pero por ahora nos quedamos con una clase única.
Una vez que tenemos declarada la tabla ya podemos pasar a crearla en la base de datos para ello utilizaremos el siguiente script, create_apache_logs_schema.py:
#!/usr/bin/python
# -*- coding: utf-8 -*-
from sqlalchemy import create_engine
from sqlalchemy.orm import sessionmaker
from apachelogs import Base
import argparse
parser = argparse.ArgumentParser()
parser.add_argument('-host', help='Database host')
parser.add_argument('-user', help='Databse user')
parser.add_argument('-port', help='Database port')
parser.add_argument('-database', required=True, help='Database name')
parser.set_defaults(host='localhost', user='postgres', port='5432')
args = parser.parse_args()
# We open the connection with the main ddbb
db = create_engine('postgresql://' + args.user + '@' + args.host + ':' +
args.port + '/' + args.database)
Base.metadata.bind = db
Base.metadata.create_all(db)
DBSession = sessionmaker(bind=db)
session = DBSession()
# Commit the session
session.commit()
La función create_engine es la que utilizaremos para definir la conexión con la base de datos, luego explicaremos los campos necesarios, pero antes veremos cómo conseguirlos a partir de la invocación del script. Para este cometido hemos utilizado la librería argparse que como su nombre indica nos permite analizar los argumentos que le pasamos al script desde la línea de comandos. Como podéis ver la sintaxis es muy simple, primero creamos el objeto de la clase ArgumentParser y le vamos añadiendo los argumentos que necesitemos, el servidor, el usuario para autenticarse en él, el puerto por el que escucha nuestra base de datos y por supuesto, el nombre de la base de datos. Este último es el único obligatorio por lo que si ejecutáis el script sin más parámetros os aparecerá el siguiente mensaje de error:
(venv35) $ python create_apache_logs_schema.py
usage: create_apache_logs_schema.py [-h] [-host HOST] [-user USER]
[-port PORT] -database DATABASE
create_apache_logs_schema.py: error: the following arguments are required: -database
Bastante fácil no? Quizá os preguntéis qué es ese mensaje que aparece entre paréntesis venv35. Esto está explicado también en el README.md del proyecto pero vamos a detenernos un momento aquí.
El problema cuando estamos trabajando con nuestro sistema operativo es que tenemos que limitarnos a utilizar las librerías que vienen empaquetadas con nuestra distribución, pero todos sabemos que si queremos hacer experimentos con gaseosa siempre nos quedaremos obsoletos rápidamente, especialmente con las librerías python. Para lidiar con este inconveniente yo siempre utilizo lo que python llama entornos virtuales, que no son más que unas jaulas con una versión concreta del intérprete de python y la colección de librerías que nosotros elijamos, sin relación con las del sistema. En este caso vamos a definir nuestro entorno con la versión 3.5 que es la que actualmente tengo disponible en mi debian unstable, cuando en el futuro los responsables de la distribución sustituyan el intérprete con la nueva versión nosotros podremos mantener nuestra jaula perfectamente usable y plantearnos una migración de forma más controlada ya que no dependeremos del sistema principal. Manos a la obra:
# apt install python-virtualenv
A partir de ahora podemos realizar todas las operaciones con nuestro usuario raso:
$ virtualenv -p /usr/bin/python3.5 venvpy35
Running virtualenv with interpreter /usr/bin/python3.5
Using base prefix '/usr'
New python executable in <home>/venvpy35/bin/python3.5
Also creating executable in <home>/venvpy35/bin/python
Installing setuptools, pkg_resources, pip, wheel...done.
$ source venvpy35/bin/activate
(venvpy35) $ pip install sqlalchemy psycopg2
Y ahí tenemos a nuestro misterioso amigo, aparece una vez activado el entorno virtual. De paso hemos instalado las dependencias que necesitaremos para trabajar con nuestros scripts. Como podéis ver utilizaremos el comando pip para realizar estas tareas y las librerías necesarias son sqlalchemy y psycopg2. La primera es obvia y la segunda es la que será utilizada por ésta para interactuar con la base de datos postgresql.
Ahora vamos a necesitar una base de datos con la que trabajar. Suponiendo que hemos instalado el servidor postgresql con las opciones por defecto podemos hacer lo siguiente:
# su - postgres
$ createdb apache_logs
Ya tenemos nuestra base de datos vacía, teniendo en cuenta que en el script hemos definido el resto de valores con los que se instalan por defecto en las distribuciones de postgresql sólo necesitaremos pasarle el nombre de la base de datos:
(venv35) $ python create_apache_logs_schema.py -database apache_logs
Si no os dado ningún error es que el esquema se ha creado correctamente. Podremos comprobarlo mediante el siguiente comando:
$ psql -U postgres apache_logs
psql (9.6.1)
Digite «help» para obtener ayuda.
apache_logs=# \d apache_log
Tabla «public.apache_log»
Columna | Tipo | Modificadores
-------------------------+-----------------------------+---------------
id_apache_log | integer | not null
server_name | character varying |
port | integer |
original_deflate | integer |
final_deflate | integer |
ratio_deflate | integer |
remote_address | bigint |
timestamp | timestamp without time zone |
request_method | character varying |
url_path_requested | character varying |
query_string | character varying |
request_protocol | character varying |
status | integer |
response_size | integer |
header_referer | character varying |
header_user_agent | character varying |
header_cookie | character varying |
header_accept_lang | character varying |
reply_content_lang | character varying |
header_accept_enc | character varying |
reply_content_enc | character varying |
reply_content_location | character varying |
reply_vary | character varying |
reply_content_type | character varying |
balancer_session_sticky | character varying |
balancer_session_route | character varying |
my_cookie | character varying |
balancer_worker_route | character varying |
balancer_route_changed | character varying |
request_duration | integer |
Índices:
"apache_log_pkey" PRIMARY KEY, btree (id_apache_log)
Si os ha dado un error al crear el esquema puede ser porque como usuario local no tengamos permisos para acceder a la base de datos. El problema más común se arregla cambiando el método de acceso expresado en el archivo /etc/postgresql/9.6/main/pg_hba.conf por trust:
[...]
# Database administrative login by Unix domain socket
local all postgres trust
# TYPE DATABASE USER ADDRESS METHOD
# "local" is for Unix domain socket connections only
local all all trust
# IPv4 local connections:
host all all 127.0.0.1/32 trust
# IPv6 local connections:
host all all ::1/128 trust
[...]
Al reiniciar el servidor ya deberíais poder crear el esquema sin problemas. Si detectáis algún problema diferente contádmelo en los comentarios porque igual se me ha escapado alguna configuración extra.
Volviendo a nuestro script una vez más, si observáis las últimas líneas veréis cómo se articula el acceso a la base de datos para realizar cambios. Una vez creado el motor, variable db, se lo pasamos a la clase Base en el método de clase bind perteneciente a la función metadata para que python conozca los datos de conexión, que a su vez pueda invocar el método create_all y abrir una sesión en ella para escribir datos. Cada vez que queramos hacer permanentes los cambios en la base de datos invocaremos el método commit perteneciente a la sesión que hemos creado y listo. En este caso sólo hemos creado el esquema pero en el siguiente script veremos como darle caña.
Espero que hasta aquí esté todo claro porque ahora viene el trabajo duro para python. Trataremos un archivo de logs de apache comprimido en bzip2 y crearemos un objeto del tipo ApacheLog por cada línea, y diréis: esto qué tiene que ver con la base de datos? Muy sencillo, cuando invoquemos el commit estos objetos se guardarán en la base de datos de forma permanente. Veamos el código y lo entenderéis:
#!/usr/bin/python
# -*- coding: utf-8 -*-
import bz2
import argparse
from sqlalchemy import create_engine
from sqlalchemy.orm import sessionmaker
from apachelogs import ApacheLog, Base
import ipaddress
# To check if an ip address is valid
def valid_ip(address):
try:
int(ipaddress.ip_address(address))
return True
except:
return False
# We parse the arguments from the command line
parser = argparse.ArgumentParser()
parser.add_argument('-host', help='Database host')
parser.add_argument('-user', help='Databse user')
parser.add_argument('-port', help='Database port')
parser.add_argument('-database', required=True, help='Database name')
parser.add_argument('-log', required=True, help='Log file to parse')
parser.set_defaults(host='localhost', user='postgres', port='5432')
args = parser.parse_args()
log_file = args.log
# We open the connection with the main ddbb
db = create_engine('postgresql://' + args.user + '@' + args.host + ':' +
args.port + '/' + args.database)
Base.metadata.bind = db
DBSession = sessionmaker(bind=db)
session = DBSession()
# We open the file to introduce the data into the ddbb
step = 0
for line in bz2.open(log_file, mode='rt', compresslevel=9):
data = line.split('\t')
new_log = ApacheLog()
new_log.server_name = data[0]
new_log.port = data[1]
deflate = data[2][1:-1].split('/')
if deflate[0] != '-':
new_log.final_deflate = deflate[0]
instream = deflate[1].split('(')
if instream[0] != '-':
new_log.original_deflate = instream[0]
ratio = instream[1][0:-2]
if ratio != '-':
new_log.ratio_deflate = ratio
if valid_ip(data[3]):
#if data[3] != '-' and data[3] != 'unknown':
new_log.remote_address = int(ipaddress.ip_address(data[3]))
new_log.timestamp = data[4][1:-1]
if data[5] != '-':
new_log.request_method = data[5]
if data[6] != '-':
new_log.url_path_requested = data[6]
new_log.query_string = data[7]
if data[8] != '-':
new_log.request_protocol = data[8]
new_log.status = data[9]
new_log.response_size = data[10]
if data[11] != '-':
new_log.header_referer = data[11]
if data[12] != '-':
new_log.header_user_agent = data[12]
if data[13] != '-':
new_log.header_cookie = data[13]
if data[14] != '-':
new_log.header_accept_lang = data[14]
if data[15] != '-':
new_log.reply_content_lang = data[15]
if data[16] != '-':
new_log.header_accept_enc = data[16]
if data[17] != '-':
new_log.reply_content_enc = data[17]
if data[18] != '-':
new_log.reply_content_location = data[18]
if data[19] != '-':
new_log.reply_vary = data[19]
if data[20] != '-':
new_log.reply_content_type = data[20]
if data[21] != '-':
new_log.balancer_session_sticky = data[21]
if data[22] != '-':
new_log.balancer_session_route = data[22]
if data[23] != '-':
new_log.my_cookie = data[23]
if data[24] != '-':
new_log.balancer_worker_route = data[24]
if data[25] != '-':
new_log.balancer_route_changed = data[25]
new_log.request_duration = data[26]
session.add(new_log)
step = step + 1
if step == 10000:
session.commit()
step = 0
# Commit the session for the rest of the log below 10000
session.commit()
La estructura es muy similar al script anterior, pedimos los datos necesarios para trabajar mediante argparser y establecemos la sesión con la base de datos. En este caso necesitamos un par de argumentos obligatorios, el nombre de la base de datos, como en el caso anterior, y el archivo comprimido del que vamos a sacar estos datos. Ya sé que el tratamiento del fichero es un poco tosco pero como iba a trabajar con un formato fijo que no íbamos a cambiar en mucho tiempo me valía. Cualquier mejora en este sentido es bienvenida porque seguro que por ahí hay formatos de logs distintos y un buen parseador más flexible nos vendría bien a todos.
Para abrir el archivo comprimido necesitamos importar la librería bz2 e invocar la apertura del fichero como se hace con el resto de operaciones de entrada salida. Hemos creado un contador para grabar los datos cada 10000 pasos ya que yo utilizaba ficheros de 4 millones de líneas y no era plan de que se interrumpiera el script con todo el trabajo hecho pero sin guardarlo en la base de datos. Con esto también conseguía que el uso de memoria fuera menor puediendo trabajar en la misma máquina que estaba realizando las operaciones. Tampoco había que olvidarse de realizar una grabación final de la sesión ya que los archivos no tienen por qué ser múltiplos de 10000 y se nos quedaban líneas sin almacenar.
El parseo tampoco tiene mucha historia, troceamos cada línea utilizando los tabuladores que separan los campos y los tratamos en orden. Cada campo tiene sus características y en base a su posición y su valor lo convertimos en el tipo python que se ajusta a su definición. El único que es un poco especial es el campo que contiene la ip de origen de la petición, en este caso hemos utilizado la librería ipaddress y una función que nos devuelve la ip en el formato correcto para insertarla en la base de datos o un error cuando no tenemos información en cuyo caso dejaremos este campo vacío en la base de datos.
Como os conté al principio, en el proyecto tenéis un archivo de ejemplo con unas 50 líneas para que veáis que esto no es un farol y que funciona correctamente. También tengo por ahí un script de bash que me trocea el archivo comprimido en tantas partes como yo quiera, utilizando una versión de bzip2 multihilo para después invocar n veces este script, siendo n los hilos que tiene la máquina que voy a utilizar para el procesamiento, así consigo el aprovechamiento eficiente de los recursos y reduzco el tiempo utilizado para el procesado.
Por supuesto hay mucho campo donde mejorar. También hice unos scripts muy simples pero muy resultones utilizando una librería gráfica para dibujar unos análisis con el tiempo de respuesta de las peticiones que igual añado al proyecto en un futuro para que no se pierdan.
Os advierto que cuando tengáis una semana de logs en la base de datos, tanto el procesamiento como las consultas se harán a la velocidad de una tortuga borracha por lo que os aconsejo que creéis índices en los campos de la tabla que utilicéis con mayor asiduidad.
El siguiente paso sería aprovechar el novedoso tipo jsonb introducido en las últimas versiones de PostgreSQL para comprobar si realmente es tan eficiente como nos aseguran y podemos combinar una base de datos relacional con una NoSQL sin salir de casa.
Y creo que no me dejo nada en el tintero, espero que con estas nociones básicas de python se os avive el gusanillo de la programación porque cuando salí de la carrera renegué de esta parte de la informática porque no me gustaba ninguno de los lenguajes que utilicé (miento, bash siempre me ha encantado). Cuando me encontré con python volví a creer en la programación y también me di cuenta de que es muy necesaria en nuestro día a día aunque nos dediquemos a nuestros sistemas y sus pantallas negras en exclusiva.
No es muy ortodoxo, pero no podía despedir este post sin recomendaros una canción de los grandérrimos Monty Python, siendo además un himno al optimismo Always Look On The Bright Side Of Life con el que despiden una de las críticas más mordaces a las religiones en general, su obra maestra Life Of Brian, imprescindible.