Iniciar sesión en una aplicación php distribuida

El artículo discutirá los beneficios de la tala. Diré sobre los registros en PSR. Agregaré algunas recomendaciones personales sobre cómo trabajar con el nivel, el mensaje y el contexto del evento registrado. Se dará un ejemplo sobre cómo organizar el registro y el monitoreo usando ELK en una aplicación escrita en Laravel y lanzada a través de Docker en varias instancias. Firmaré una regla importante del sistema de advertencia. Daré un ejemplo de un script que eleva toda la pila de monitoreo con un comando.

Los beneficios de la tala

El registro bien organizado permite al menos lo siguiente:

• Saber que algo no está yendo según lo previsto (hay errores)
• Conozca los detalles del error, lo que ayudará a decir con quién y dónde ocurrió el error, y evitará que se repita
• Para saber que todo va según lo planeado (acceso.log, depuración, niveles de información)

El registro por sí solo no le dirá todo esto, pero con la ayuda de los registros, será posible conocer de forma independiente los detalles de los eventos o configurar un sistema de monitoreo para los registros que podrán notificar los problemas. Si los mensajes en los registros están acompañados por una cantidad suficiente de contexto, esto simplifica enormemente la depuración, ya que tendrá más datos disponibles sobre la situación en la que ocurrió el evento.

Qué escribir y qué escribir

Parte de la comunidad php ha desarrollado recomendaciones para algunas tareas de escritura de código. Una de esas recomendaciones es la interfaz del registrador PSR-3 . Simplemente describe lo que necesita para iniciar sesión. Para esto, se desarrolla la Psr\Log\LoggerInterface del paquete " Psr\Log\LoggerInterface / log". Al usarlo, debe conocer los tres componentes del evento:

1. Nivel - Importancia del evento
2. Mensaje : texto que describe el evento
3. Contexto : una variedad de información adicional sobre el evento

Niveles de evento PSR-3

Los niveles se toman prestados de RFC 5424 - El Protocolo Syslog, su descripción aproximada es la siguiente:

• depuración: detalles para la depuración
• info - Eventos interesantes
• aviso - Eventos materiales, pero no errores
• advertencia: casos excepcionales, pero no errores
• error: errores de ejecución que no requieren intervención momentánea
• crítico: condiciones críticas (el componente del sistema no está disponible, excepción inesperada)
• alerta - La acción requiere intervención inmediata
• emergencia: el sistema no funciona

Hay una descripción, pero no siempre es fácil de seguir, debido a la dificultad para determinar la importancia de ciertos eventos. Por ejemplo, en el contexto de una sola solicitud, no fue posible acceder al recurso conectado. Al grabar este evento, no sabemos si una de esas solicitudes falló, o tal vez solo un usuario falla. Depende de si se requiere intervención inmediata o si este es un caso raro, puede esperar o incluso ser ignorado. Dichos problemas se resuelven en el marco de los registros de monitoreo. Pero aún necesita determinar el nivel. Por lo tanto, se pueden acordar los niveles de registro en el equipo. Un ejemplo:

• emergencia es el nivel de los sistemas externos que pueden observar su sistema y determinar con seguridad si no funciona por completo o si su autodiagnóstico no funciona.
• alerta : el sistema mismo puede diagnosticar su estado, por ejemplo, con una tarea programada y, como resultado, registrar un evento con este nivel. Pueden ser comprobaciones de recursos conectados o algo específico, por ejemplo, un saldo en la cuenta de un recurso externo utilizado.
• crítico : un evento cuando una falla proporciona un componente del sistema que es muy importante y siempre debe funcionar. Ya depende mucho de lo que haga el sistema. Adecuado para eventos que es importante descubrir rápidamente, incluso si sucedió solo una vez.
• error : se ha producido un evento sobre el cual, cuando se repite pronto, debe informar. No se pudo completar la acción, que debe realizarse, pero esta acción no se incluye en la descripción de crítica. Por ejemplo, no fue posible guardar la imagen de perfil de un usuario a petición suya, pero el sistema no es un servicio de imagen de perfil, sino un sistema de chat.
• advertencia : eventos, para la notificación inmediata de los cuales necesita marcar un número significativo de ellos durante un período de tiempo. No se pudo realizar una acción, cuyo fallo no rompe nada grave. Estos siguen siendo errores, pero la corrección de los cuales puede esperar el horario de trabajo. Por ejemplo, no fue posible guardar el avatar del usuario, y el sistema era una tienda en línea. La notificación sobre ellos es necesaria (a alta frecuencia) para conocer las anomalías repentinas, ya que pueden ser síntomas de problemas más graves.
• aviso : estos son eventos que informan desviaciones proporcionadas por el sistema que forman parte del funcionamiento normal del sistema. Por ejemplo, el usuario especificó una contraseña incorrecta en la entrada, el usuario no completó el segundo nombre, pero no es necesario, el usuario compró el pedido por 0 rublos, pero esto se le proporciona en casos excepcionales. También es necesaria una notificación en una frecuencia alta, ya que un aumento brusco en el número de desviaciones puede ser el resultado de un error que debe corregirse urgentemente.
• info - eventos, cuya ocurrencia informa el funcionamiento normal del sistema. Por ejemplo, un usuario se ha registrado, un usuario ha comprado un producto, un usuario ha dejado comentarios. La notificación para tales eventos debe configurarse de la manera opuesta: si se ha producido un número insuficiente de tales eventos durante un período de tiempo, entonces debe notificarlo, porque su disminución podría deberse a un error.
• depuración : eventos para depurar un proceso en el sistema. Cuando agrega suficientes datos al contexto del evento, puede diagnosticar el problema o concluir que el proceso funciona correctamente en el sistema. Por ejemplo, un usuario abrió una página de producto y recibió una lista de recomendaciones. Aumenta significativamente el número de eventos enviados, por lo que está permitido eliminar el registro de dichos eventos después de un tiempo. Como resultado, el número de tales eventos en la operación normal será variable, luego se puede omitir el monitoreo de notificaciones sobre ellos.

Mensaje de evento

Por PSR-3, un mensaje debe ser una cadena o un objeto con el método __toString() . Además, de acuerdo con PSR-3, la línea de mensaje puede contener marcadores de posición del formulario ”User {username} created” , que puede reemplazarse por valores de la matriz de contexto. Al usar Elasticsearch y Kibana para el monitoreo, recomiendo no usar marcadores de posición, sino escribir líneas fijas, porque esto simplificará el filtrado de eventos y el contexto siempre estará ahí. Además, propongo prestar atención a los requisitos adicionales para el mensaje:

1. El texto debe ser breve pero significativo. Esto es lo que vendrá en las alertas y lo que estará en las listas de eventos que han ocurrido.
2. Es mejor que el texto sea único para diferentes partes del programa. Esto permitirá desde la alerta, sin mirar el contexto, comprender en qué parte ocurrió el evento.

Contexto del evento

El contexto del evento para PSR-3 es una matriz (posiblemente anidada) de valores variables, por ejemplo, ID de entidad. El contexto puede dejarse en blanco si el mensaje es claro sobre el evento. En el caso de registrar una excepción, debe pasar la excepción completa, no solo getMessage() . Al usar Monolog a través de NormalizerFormatter, los datos útiles se extraerán automáticamente de la excepción y se agregarán al contexto del evento, incluido el seguimiento de la pila. Es decir, necesitas en su lugar

 [ 'exception' => $exception->getMessage(), ] 

para usar

 [ 'exception' => $exception, ] 

En Laravel, puede ingresar automáticamente datos para eventos en eventos. Esto se puede hacer a través del contexto de registro global (solo para excepciones fallidas o mediante report() ), o mediante LogFormatter (para todos los eventos). Por lo general, la información se agrega con la identificación del usuario actual, solicitud de URI, IP, solicitud de UUID y similares.

Cuando use Elasticsearch como repositorio de registros, recuerde que usa tipos de datos fijos. Es decir, si pasó customer_id en el contexto de un número, cuando intenta guardar un evento con un tipo diferente, por ejemplo, una cadena (uuid), dicho mensaje no se escribirá. Los tipos en el índice son fijos cuando el valor se recibe por primera vez. Si se crean índices todos los días, el nuevo tipo se registrará solo al día siguiente. Pero incluso esto no resolverá todos los problemas, porque para Kibana los tipos se mezclarán y algunas de las operaciones asociadas con el tipo no estarán disponibles hasta que haya índices mixtos.

Para evitar este problema, le recomiendo que siga las reglas:

• No utilice nombres de clave demasiado genéricos, que pueden ser de diferentes tipos.
• Realice una conversión explícita a un tipo de valor si no está seguro de su tipo

Ejemplo: en cambio

 [ 'response' => $response->all(), 'customer_id' => $id, 'value' => $someValue, ] 

para usar

 [ 'smsc_response_data' => json_encode($response->all()), 'customer_id' => (string) $customer_id, 'smsc_request_some_value' => (string) $someValue, ] 

Llamar a un registrador desde el código

Para grabar rápidamente un evento en el registro, puede encontrar varias opciones. Consideremos algunos de ellos.

1. Declare la función global log() y llámela desde diferentes partes del programa. Este enfoque tiene muchas desventajas. Por ejemplo, en las clases donde accedemos a esta función, se forma una dependencia implícita. Esto debe ser evitado. Además, dicho registrador es difícil de configurar cuando el sistema necesita tener varios diferentes. Otro inconveniente, si estamos hablando de trabajar con Laravel, es que no usamos las funciones proporcionadas por el marco para resolver este problema.
2. Utilice la fachada de Laravel \ Log. Con este enfoque, las partes del sistema que acceden a esta fachada comienzan a depender del marco. En partes del sistema que no vamos a eliminar del marco, esta solución es bastante adecuada. Por ejemplo, escriba desde algunas instancias de un comando de consola, tarea en segundo plano, controlador. O cuando ya existe una estructura compleja de servicios, y lanzar una instancia de un registrador en ellos no es tan simple.
3. Resuelva la dependencia del registrador a través de los ayudantes de la app() y el marco de trabajo resolve() . El enfoque tiene las mismas desventajas que usar la fachada, pero necesita escribir un poco más de código.
4. Especifique la dependencia del registrador en el constructor de la clase que utilizará este registrador. Al mismo tiempo, se debe especificar el mismo LoggerInterface como tipo para cumplir con DIP . Gracias a los marcos de cableado automático, las dependencias se resolverán automáticamente en la implementación de sus abstracciones declaradas. En Laravel, algunas clases de dependencia pueden especificarse en un método separado, en lugar de especificarse en el constructor de toda la clase.

En qué parte del código llamar al registrador

Al organizar el código en el proyecto, puede surgir la pregunta en qué clase debo escribir en el registro. ¿Debería ser un servicio? ¿O debería hacerse desde donde se llama al servicio: controlador, tarea en segundo plano, comando de consola? ¿O debería cada excepción decidir qué escribir en el registro utilizando su método de report (Laravel)? No hay una respuesta simple a todas las preguntas a la vez.

Considere la oportunidad que le brinda Laravel para delegar en la clase de excepción la tarea de iniciar sesión. Una excepción no puede saber cuán crítico es para el sistema determinar el nivel de un evento. Además, una excepción no tiene acceso al contexto a menos que se agregue específicamente cuando se llama a esta excepción. Para llamar al método de render en una excepción, no debe capturar la excepción (se usará el ErrorHandler global) o capturar y usar el ayudante global report() . Este método nos permite no llamar al registrador PSR-3 cada vez que podamos detectar esta excepción. Pero no creo que valga la pena dar a la excepción tal responsabilidad.

Puede parecer que siempre podemos iniciar sesión solo en los servicios. De hecho, en algunos servicios puedes hacer logging. Pero considere un servicio que no depende del proyecto y, en general, planeamos ponerlo en un paquete separado. Entonces, este servicio no conoce su importancia en el proyecto y, por lo tanto, no podrá determinar el nivel de registro. Por ejemplo, un servicio de integración con una puerta de enlace SMS específica. Si recibimos un error de red, esto no significa que sea bastante grave. Quizás el sistema tenga un servicio de integración con otra puerta de enlace de SMS a través de la cual habrá un segundo intento de envío, luego el error del primero se puede informar como advertencia, y el error del segundo como error. Solo que ahora todas estas integraciones deberían llamarse desde otro servicio, que iniciará sesión exactamente. Resulta que el error está en un servicio e iniciamos sesión en otro. Pero a veces no tenemos un contenedor de servicios sobre otro servicio, lo llamamos directamente desde el controlador. En este caso, considero permisible escribir en el registro en el controlador en lugar de escribir un decorador de servicios para el registro.

Un ejemplo que muestra el uso de la dependencia y el contexto de paso:

 <?php namespace App\Console\Commands; use App\Services\ExampleService; use Illuminate\Console\Command; use Psr\Log\LoggerInterface; class Example extends Command { protected $signature = 'example'; public function handle(ExampleService $service, LoggerInterface $logger) { try { $service->example(); } catch (\Exception $exception) { $logger->critical('Example error', [ 'exception' => $exception, ]); } } } 

Donde escribir

Considere las siguientes opciones.

1. De acuerdo con la aplicación de 12 factores y algunas otras recomendaciones, debe escribir stdout, stderr del tiempo de ejecución de la aplicación. Para hacer esto, puede especificar en el registrador de configuración php://stdout *.
2. Ignora el factor 12, la ventana acoplable y escribe en los archivos. Laravel (Monolog) incluso le permite configurar la rotación de registros. Se pueden recopilar más mensajes de archivos usando Filebeat y enviarlos a Logstash para su análisis.
3. Envíe registros desde la aplicación directamente más lejos, por ejemplo, a través de UDP para aumentar el rendimiento.
4. Combina soluciones. Escriba en los archivos que utilizando Filebeat se recopilarán y enviarán a Logstash. Escriba en el contenedor stderr para poder utilizar los comandos de docker logs la docker logs y estar listo para recopilar registros del entorno de orquestación del contenedor. En este caso, puede escribir algunos canales solo localmente, algunos envían a través de la red.

* En php-fpm 7.2, cuando escribimos registros en stdout, obtenemos "ADVERTENCIA: [pool www] child X dijo en stdout ...", y los mensajes largos se truncan. Una solución a este problema está aquí . No hay tal problema en php-fpm 7.3.

Opciones de formato de grabación:

• Legible por humanos (saltos de línea, sangrías, etc.)
• Legible por máquina (generalmente json)
• Ambos formatos a la vez: legible por máquina en stdout para enrutamiento adicional, legible por humanos en caso de problemas repentinos de enrutamiento y depuración rápida

Cualquiera de las opciones supone que los registros se enrutan; al menos, se envían a un único sistema de procesamiento (almacenamiento) de registros por los siguientes motivos:

1. Almacenamiento y archivo a largo plazo
2. Tendencias a gran escala
3. Sistema flexible de notificación de eventos.

Docker tiene la capacidad de especificar un administrador de registros. El valor predeterminado es json-file , es decir, la ventana acoplable agrega la salida del contenedor al archivo json en el host. Si seleccionamos un administrador de registros que enviará registros a alguna parte de la red, ya no podremos usar el docker logs . Si se eligió stdout / stderr del contenedor como el único lugar para grabar registros de aplicaciones, entonces, en caso de problemas de red o problemas con un único repositorio, puede que no sea posible extraer rápidamente las entradas para la depuración.

Podemos usar json-file docker y Filebeat. Recibiremos registros locales y más rutas. Vale la pena señalar que aquí hay otra característica de la ventana acoplable. Al grabar un evento de más de 16 KB, la ventana acoplable rompe el registro con el símbolo \n , lo que confunde a muchos recolectores de registros. Hay un problema al respecto. El problema por parte de la ventana acoplable no se pudo resolver, por lo que fue resuelto por los recolectores. Con alguna versión, Filebeat admite este comportamiento de acoplador y combina correctamente los eventos.

Qué combinación de todas las posibilidades de destinos y formatos de grabación puede elegir para su proyecto usted mismo.

Usando Filebeat + ELK + Elastalert

Brevemente, el papel de cada servicio se puede describir de la siguiente manera:

• Filebeat: recopila eventos de archivos y los envía
• Logstash: analiza eventos y envía
• Elasticsearch - almacena eventos estructurados
• Kibana: muestra eventos (gráficos, agregaciones, etc.)
• Elastalert: envía alertas basadas en solicitudes

Además, puedes: zabbix, metricbeat, grafana y más.

Ahora más sobre cada uno.

Filebeat

Puede ejecutarse como un servicio separado en el host, puede usar un contenedor docker separado. Para trabajar con la secuencia de eventos desde Docker, utiliza la ruta del host /var/lib/docker/containers/*/*.log . Filebeat tiene una amplia gama de opciones con las que puede establecer el comportamiento en diversas situaciones (se cambia el nombre del archivo, se elimina el archivo y similares). Filebeat en sí puede analizar json dentro del evento, pero no json también puede entrar en eventos, lo que provocará un error. Todo el procesamiento de eventos se realiza mejor en un solo lugar.

 filebeat.inputs: - type: docker containers: ids: - "*" processors: - add_docker_metadata: ~ 

Logstash

Capaz de aceptar eventos de muchas fuentes, pero aquí estamos considerando Filebeat.
En cada evento, además del evento en sí de stdout / stderr, hay metadatos (host, contenedor, etc.). Hay muchos filtros de procesamiento integrados: analizar por intervalos regulares, analizar json, modificar, agregar, eliminar campos, etc. Adecuado para analizar tanto los registros de aplicaciones como nginx access.log en cualquier formato. Capaz de transferir datos a diferentes repositorios, pero aquí consideramos Elasticsearch.

 if [status] { date { match => ["timestamp_nginx_access", "dd/MMM/yyyy:HH:mm:ss Z"] target => "timestamp_nginx" remove_field => ["timestamp_nginx_access"] } mutate { convert => { "bytes_sent" => "integer" "body_bytes_sent" => "integer" "request_length" => "integer" "request_time" => "float" "upstream_response_time" => "float" "upstream_connect_time" => "float" "upstream_header_time" => "float" "status" => "integer" "upstream_status" => "integer" } remove_field => [ "message" ] rename => { "@timestamp" => "event_timestamp" "timestamp_nginx" => "@timestamp" } } } 

Búsqueda elástica

Elasticsearch es una herramienta muy poderosa para una amplia gama de tareas, pero con el propósito de monitorear los registros se puede usar conociendo solo un cierto mínimo.
Los eventos guardados son un documento, los documentos se almacenan en índices.
Cada índice es un esquema en el que se define un tipo para cada campo del documento. No puede guardar un evento en el índice si al menos un campo tiene el tipo incorrecto.
Los diferentes tipos le permiten realizar diferentes operaciones en un grupo de documentos (para números: suma, mínimo, máximo, promedio, etc., para cadenas: búsqueda difusa, etc.).
Para los registros, la administración generalmente recomienda usar índices diarios, un nuevo índice todos los días.

Asegurar el funcionamiento estable de Elasticsearch con el crecimiento del volumen de datos es una tarea que requiere un conocimiento más profundo sobre esta herramienta. Pero una solución rápida al problema de estabilidad, puede optar por eliminar automáticamente los datos obsoletos. Para hacer esto, sugiero dividir los niveles de eventos en logstash en diferentes índices. Esto permitirá más tiempo para almacenar eventos raros, pero más importantes.

 output { if [fields][log_type] == "app_log" { if [level] in ["DEBUG", "INFO", "NOTICE"] { elasticsearch { hosts => "${ES_HOST}" index => "logstash-app-log-debug-%{+YYYY.MM.dd}" } } else { elasticsearch { hosts => "${ES_HOST}" index => "logstash-app-log-error-%{+YYYY.MM.dd}" } } } } 

Para eliminar automáticamente los índices obsoletos, sugiero usar un programa de Elastic Curator . El lanzamiento del programa se agrega a la programación de Cron, la configuración en sí misma se puede almacenar en un archivo separado.

 action: delete_indices description: logstash-app-log-error options: ignore_empty_list: True filters: - filtertype: pattern kind: prefix value: logstash-app-log-error- - filtertype: age source: name direction: older timestring: '%Y.%m.%d' unit: months unit_count: 6 

, Filebeat Logstash, . Elasticsearch -- , , .

Kibana

Kibana . -, Elasticsearch. .

Kibana — Discovery . , Discovery app warning , time, message, exception class, host, client_id.

, Discovery nginx, 404 time, message, request, status.
Kibana , : , , . , ( ).

Elastalert

Elastalert Elasticsearch . , . , .
, (), .

:

• ALERT, EMERGENCY. — 10
• CRITICAL. — 30
• , N X M
• 10 INFO 3
• nginx 200, 201, 304 75% , 50

 name: Blacklist ALERT, EMERGENCY type: blacklist index: logstash-app-* compare_key: "level" blacklist: - "ALERT" - "EMERGENCY" realert: minutes: 5 alert: - "slack" 

— . , , . Kibana.

, , http- 75% , , , , . - , , , .

, , , , Kibana, .

5 . , , , , , .

, . .

Kibana . .

docker-. , , staging- production-, .

, Elastalert, . Elastalert ,
envsubst < /opt/elastalert/config.dist.yaml > /opt/elastalert/config.yaml entrypoint- , .

, , , .

 build: docker build -t some-registry/elasticsearch elasticsearch docker build -t some-registry/logstash logstash docker build -t some-registry/kibana kibana docker build -t some-registry/nginx nginx docker build -t some-registry/curator curator docker build -t some-registry/elastalert elastalert push: docker push some-registry/elasticsearch docker push some-registry/logstash docker push some-registry/kibana docker push some-registry/nginx docker push some-registry/curator docker push some-registry/elastalert pull: docker pull some-registry/elasticsearch docker pull some-registry/logstash docker pull some-registry/kibana docker pull some-registry/nginx docker pull some-registry/curator docker pull some-registry/elastalert prepare: docker network create -d bridge elk-network || echo "ok" stop: docker rm -f kibana || true docker rm -f logstash || true docker rm -f elasticsearch || true docker rm -f nginx || true docker rm -f elastalert || true run-logstash: docker rm -f logstash || echo "ok" docker run -d --restart=always --network=elk-network --name=logstash -p 127.0.0.1:5001:5001 -e "LS_JAVA_OPTS=-Xms256m -Xmx256m" -e "ES_HOST=elasticsearch:9200" some-registry/logstash run-kibana: docker rm -f kibana || echo "ok" docker run -d --restart=always --network=elk-network --name=kibana -p 127.0.0.1:5601:5601 --mount source=elk-kibana,target=/usr/share/kibana/optimize some-registry/kibana run-elasticsearch: docker rm -f elasticsearch || echo "ok" docker run -d --restart=always --network=elk-network --name=elasticsearch -e "ES_JAVA_OPTS=-Xms1g -Xmx1g" --mount source=elk-esdata,target=/usr/share/elasticsearch/data some-registry/elasticsearch run-nginx: docker rm -f nginx || echo "ok" docker run -d --restart=always --network=elk-network --name=nginx -p 80:80 -v /root/elk/.htpasswd:/etc/nginx/.htpasswd some-registry/nginx run-elastalert: docker rm -f elastalert || echo "ok" docker run -d --restart=always --network=elk-network --name=elastalert --env-file=./elastalert/.env some-registry/elastalert run: prepare run-elasticsearch run-kibana run-logstash run-elastalert delete-old-indices: docker run --rm --network=elk-network -e "ES_HOST=elasticsearch:9200" some-registry/curator curator --config /curator/curator.yml /curator/actions.yml 

:

• 80 nginx, basic auth Kibana
• Logstash . ssh-
• nginx
• , docker-
• , .env- nginx-
• *_JAVA_OPTS , 4GB RAM ( ES).

, xpack-.

docker-compose. , , Dockerfile-, Filebeat, Logstash, , , , , VCS.

. . , ( Laravel scheduler), , 5 . ALERT. , . , , .

Conclusión

, , , . . , - . . , , .