Son muchos los entornos que se han pasado a la programación orientada a eventos. Aunque de forma descafeinada, pues no siempre es lo que entendemos como eventos que se disparan y se ejecutan en segundo plano.

Llevo ya unas semanas intensivas desarrollando sobre Magento para cerrar un proyecto. Al igual que Wordpress, Magento tiene una serie de eventos sobre los que uno puede establecer sus rutinas que se ejecutarán cuando se lancen estos eventos.

Al contrario que en JavaScript, Node, C# y otros, los eventos en PHP se ejecutan de forma secuencial y nos sirven básicamente para ejecutar rutinas de código en mitad del código principal de la aplicación sin necesidad de tocar el core de la misma. Una clase que ejerce de controlador de eventos almacena todas las funciones de callback junto al evento con el que se tienen que ejecutar, y las lanza de forma secuencial cuando este evento es llamado.

A menudo es fácil darse cuenta que este tipo de programación no es la que estamos acostumbrados en PHP y he visto cantidad de código de extensiones que deciden sobreescribir todo el código antes que usar eventos, rompiendo así en ocasiones la funcionalidad de otras extensiones.

Siempre que trabajo con Software Libre y extensiones de terceros compradas, me viene la sensación que, aunque la funcionalidad esté desarrollada, el código a veces, dista de ser bueno, suponiendo auténticos quebraderos de cabeza al resto de desarrolladores.

Recientemente trabajamos sobre un framework desarrollado por el equipo de Emagister y como es normal aunque tiene similitudes en cuanto a características con nuestro framework Creamture, hay otras cosas que son diferentes y no encontramos un rendimiento óptimo.

Una de estas cosas es el tema del log de errores utilizando para ello una tabla en base de datos. El uso de base de datos para escribir en un log es bastante lento comparado con la escritura directamente en un fichero en disco, aunque mantiene algunas esperadas ventajas como la posibilidad de disponer de un visor de log mediante consultas SQL, lo que permite lectura únicamente de las entradas ordenadas por fecha, paginación, sin tener que volcar todo el fichero de log que podría ser muy grande. Aunque la escritura en base de datos es mucho más lenta que la escritura en fichero, el impacto no es muy grande pues únicamente pasan a log los errores o excepciones.

CodeIgniter, y Creamture crea un fichero de log en formato texto por cada día, lo que minimiza que los ficheros crezcan excesivamente, pero al usar el log no solo para volcar errores graves sino como bitácora para cualquier tipo de información que los desarrolladores queremos visualizar, podemos encontrarnos con ficheros diarios de varios megas.

Reciéntemente he mejorado el visor de log que teníamos en Creamture, que permite visualizar los ficheros de logs de CI 1.7 hasta CI 2.2 (Creamture). Disponiendo de un modo para visualizar el log actual en tiempo real, realizando lecturas parciales del fichero en disco. Podéis descargarlo este GIST.

El caso es que pensando en cómo mejorar, esta tarde me dispuse hacer un pequeño test utilizando una instalación base de CodeIgniter 1.7. Se me ocurrió que podría ser más práctico si se usaba un sistema de almacenamiento más organizado y mejor que un fichero, pero que siga siendo más rápido que una base de datos.

El impacto del log normal sobre un controlador

Activando únicamente el log de errores, y no de debug ni info, para minimizar el impacto (CodeIgniter genera log de debug al pasar por casi cualquier librería), y creamos un controlador con un método muy muy simple:

function index()
{
    echo 'OK';
}

Usaremos para probar el funcionamiento normal en nuestro sistema, un pequeño programa para nodejs, llamado webstress-tool con el que podemos lanzar peticiones concurrentes y obtener una media de las mismas, generaremos 10 bloques de peticiones de 50 peticiones concurrentes, cada bloque estará separado por 1 segundo de diferencia.

$ webstress GET http://www.ci17.com 10 50
about to send 500 GET requests to url http://www.ci17.com over 10 seconds
done, took total over: 12034, avg response time: 240.68
done, took total over: 8849, avg response time: 176.98
done, took total over: 7800, avg response time: 156
done, took total over: 7804, avg response time: 156.08
done, took total over: 7686, avg response time: 153.72
done, took total over: 7636, avg response time: 152.72
done, took total over: 7701, avg response time: 154.02
done, took total over: 7713, avg response time: 154.26
done, took total over: 7171, avg response time: 143.42
done, took total over: 7073, avg response time: 141.46

Entonces modifiqué nuestro pequeño método para añadir una llamada a log_message: log_message('ERROR', 'Hola mundo!'); con lo que al probar de nuevo, encontramos cómo afecta el log a la media de las respuestas:

$ webstress GET http://www.ci17.com 10 50
about to send 500 GET requests to url http://www.ci17.com over 10 seconds
done, took total over: 15360, avg response time: 307.2
done, took total over: 10872, avg response time: 217.44
done, took total over: 11044, avg response time: 220.88
done, took total over: 11931, avg response time: 238.62
done, took total over: 11037, avg response time: 220.74
done, took total over: 10955, avg response time: 219.1
done, took total over: 11189, avg response time: 223.78
done, took total over: 12869, avg response time: 257.38
done, took total over: 11121, avg response time: 222.42
done, took total over: 11744, avg response time: 234.88

Podemos ver como una única llamada al log tiene un importante impacto aunque la llamada sea simple. Por lo que no podemos ignorar que aún utilizando ficheros de texto, el impacto es significativo.

Probando con SQLite

La idea es generar un fichero de SQLite por día, y poder guardar la misma información que los ficheros de log, para eso creamos un método log_message alternativo que abrirá una bbdd sqlite nombrada con la fecha actual, intentamos siempre insertar, en caso de error crearemos la tabla ya que el error será por no existir la tabla, pero será más rápido que comprobar siempre si la tabla existe.

El resultado es desalentador:

$ webstress GET http://www.ci17.com 10 50
about to send 500 GET requests to url http://www.ci17.com over 10 seconds
done, took total over: 30964, avg response time: 619.28
done, took total over: 27871, avg response time: 557.42
done, took total over: 30341, avg response time: 606.82
done, took total over: 28935, avg response time: 578.7
done, took total over: 24958, avg response time: 499.16
done, took total over: 27928, avg response time: 558.56
done, took total over: 21769, avg response time: 435.38
done, took total over: 23220, avg response time: 464.4
done, took total over: 26227, avg response time: 524.54
done, took total over: 25003, avg response time: 500.06

Sí sería posible leer el log mediante un visor con consultas SQL, pero la penalización por insertar una simple entrada resulta excesiva.

Usando Redis para guardar el log

Después de leer la velocidad con la que funcionan los sistemas noSQL de almacenamiento key,value probamos Redis, cuyo funcionamiento es muy muy simple, y tenemos una librería muy probada para PHP.

Así que después de bajarnos una versión de Redis para Windows (existe versión para cualquier Unix, OSX y una compilación para Windows que ocupa algo menos de 2 megas.

El nuevo método que construimos es muy simple:

function log_message2($level = 'error', $message, $php_error = FALSE)
{
    $redis = new Redis();
    $redis->connect('127.0.0.1', 6379);
    $redis->lpush('ci17-'.(date('Y-M-d')), (date('Y-M-d H:i:s')).' - '.$level.' --> '.$message);
}

El resultado es casi tan bueno que el impacto sobre la versión sin log es mínimo, y además podemos recuperar las entradas rápidamente ordenadas por fecha y pudiendo paginar. Vemos que efectívamente Redis es muy útil si queremos guardar una bitácora para proyectos web de uso intensivo.

$ webstress GET http://www.ci17.com 10 50
about to send 500 GET requests to url http://www.ci17.com over 10 seconds
done, took total over: 10579, avg response time: 211.58
done, took total over: 8524, avg response time: 170.48
done, took total over: 8419, avg response time: 168.38
done, took total over: 8616, avg response time: 172.32
done, took total over: 8254, avg response time: 165.08
done, took total over: 8351, avg response time: 167.02
done, took total over: 8383, avg response time: 167.66
done, took total over: 8320, avg response time: 166.4
done, took total over: 8017, avg response time: 160.34
done, took total over: 7932, avg response time: 158.64

Lo próximo será actualizar nuestro framework y el visor de logs para usar Redis y establecer un fallback para utilizar ficheros en caso de no detectar un servidor Redis funcionando.

A menudo mantenemos la relación (incluso en el mundillo de la informática) de Software Libre igual a GRATIS, oigo multitud de clientes que me comentan "Usa software libre que es gratis y así abaratamos".

Por lo general la forma de discutir esto siempre comienza por Libre es distinto de GRATIS, y que viene de una mala traducción de la palabra FREE en Free Software, la denominación en inglés. Pero aún así, cuando pensamos en Software Libre, pensamos en gratis.

Ahora bien, este planteamiento, no es del todo inválido, pues efectivamente, el Software Libre por lo general no implica un deselvolso de dinero inicial o pago por uso (digo por lo general, lo que no es en todos los casos). Pero esto no quita que, primero, no haya costado tiempo y esfuerzo de alguien el producirlo (y por lo tanto dinero), y segundo, que si en algún momento detectamos un problema y como programadores decidimos resolverlo pues lo usamos en algún proyecto propio, es responsabilidad nuestra también comunicar estos cambios a los creadores originales para que puedan añadir nuestras mejoras.

A menudo en DIGIO hemos mejorado multitud de herramientas de Software Libre y en muchas ocasiones por falta de tiempo, no caemos en la cuenta que comunicar y pasar las mejoras al proyecto original es una responsabilidad, sino que además repercute en mejoras futuras que pueden hacer otros sobre nuestros cambios que de otra manera, no obtendríamos, por lo que es una apuesta por ahorrarnos esfuerzo y trabajo en el futuro.

El coste de comunicar estos cambios a los proyectos de Software Libre suele ser siempre mucho menor que el coste de las mejoras futuras que obtendremos. Y en caso contrario aunque solo sea porque nuestro esfuerzo y dedicación no desaparezca con nuestro proyecto, sino que otros puedan aprovechar nuestro trabajo para mejorarlo y continuarlo.

Todo el que me conoce sabe que no soy un completo fanático del Software Libre, lo uso y he colaborado y aportado muchos cambios en muchos proyectos, pero eso no quita que no pueda ver puntos flacos en el planteamiento como excesiva fragmentación en proyectos derivados, mayor carga de correos (no os podéis imaginar la cantidad de correos que pueden llegar de Github, en cuanto uno hace grandes colaboraciones en proyectos de Software Libre, pero creo que es importante que el trabajo que hacemos tenga más vida fuera de lo poco que podamos desarrollar de forma interna y es el precio que debemos de pagar por desarrollar con Software Libre.

Aunque hace bastante tiempo de esto, aún tiene mucha utilidad. Se ha convertido en una costumbre que las aplicaciones webs estén pobladas de consultas o peticiones AJAX, cargando inicialmente una plantilla, y actualizando los contenidos mediante consultas o peticiones asíncronas.

Cuando queremos subir ficheros en segundo plano sin realizar la carga, en cambio no podemos usar AJAX, teniendo que remitirnos al File API de HTML5 o bien buscar una técnica alternativa que permita enviar un formulario con un formulario en multipart en segundo plano. Esto se puede conseguir mediante iframes, la técnica se basa en crear un iframe no visible (que no oculto, si está display:hidden no funcionará), de un tamaño de 0 pixeles y sin bordes conseguiremos un iframe funcional pero que no es visible por el usuario. Si indicamos como target de un formulario multipart este iframe, podremos subir un fichero sin recargar la página.

El problema será entonces conocer el momento en que el archivo se ha terminado de subir, para esto la respuesta cargada en el iframe debe ejecutar una llamada JavaScript definida en la ventana padre, que como si fuese una función de Callback se ejecutará cuando tengamos subido el fichero.

Poder obtener datos en JavaScript entre diferentes dominios permitirá crear fácilmente servicios web en formato JSON, a esta técnica se le denomina JSONP, consiste en devolver no un objeto JavaScript sino la llamada a una función con el nombre que escojamos (función callback) pasando como parámetro este objeto. Cuando cargamos una url con la llamada al servicio lanzaremos la ejecución de la función de callback con los datos que esperamos de respuesta. Esto ya lo hace jQuery por detrás cuando ejecutamos el método $.getScript generando una función con un nombre aleatorio.

Para todo esto tenemos una librería que nos ayudará para generar respuestas en formato JSON, JSONP, XML y respuestas a través de iframes, si usamos CodeIgniter 2 o superior, mediante Spark/ajax disponemos de una serie de funciones helpers y métodos útiles para generar respuestas válidas en JSONP, envío de respuestas dentro de un iframe o respuestas en XML.

Con un método $this->ajax->response() podremos generar respuestas para enviar como JSON, JSONP, extender un objeto JS con jQuery, asignar datos generados a una variable, o generar respuestas en XML a partir de un objeto PHP.

Por ejemplo queremos cargar las cadenas de traducción de un array PHP a una variable JavaScript, podríamos añadir una carga de script en HTML

<code>< script type="text/javascript" src="http://url/controller/method">
</code>

y que este método PHP devuelva los datos en una variable:

<code>$this->ajax->response($array_traduccion, null, TRUE, "varjs");
</code>

Esto cargará los datos en varjs para poder usarlo en JavaScript. Esto funcionaría también en cualquier dominio, por lo que sería cross-domain.