Get best of the week

Historias de bloqueo con Patroni, o Cómo soltar un clúster PostgreSQL

PostgreSQL no tiene alta disponibilidad fuera de la caja. Para lograr HA, debe poner algo, configurarlo, hacer un esfuerzo. Existen varias herramientas que pueden ayudar a aumentar la disponibilidad de PostgreSQL, y una de ellas es Patroni.

A primera vista, al poner a Patroni en un entorno de prueba, puede ver qué gran herramienta es y cómo maneja fácilmente nuestros intentos de romper el clúster. Pero en la práctica, en un entorno de producción, no todo sucede siempre de manera tan bella y elegante. Data Egret comenzó a usar Patroni a fines de 2018 y ganó algo de experiencia: cómo diagnosticarlo, configurarlo y cuándo no confiar en el archivador automático.

En HighLoad ++, Alexei Lesovsky describió en detalle, utilizando ejemplos y análisis de registros, los problemas típicos que surgen al trabajar con Patroni y las mejores prácticas para superarlos.


El artículo no: Instrucciones de instalación de Patroni y ejemplos de configuración; problemas fuera de Patroni y PostgreSQL; historias basadas en las experiencias de otras personas, pero solo aquellos problemas que Data Egret descubrió por sí mismos.

Sobre el orador: Alexey Lesovsky (lesovsky) comenzó como administrador del sistema (administrador del sistema Linux), trabajó en desarrollo web (administrador de bases de datos PostgreSQL). Desde 2014 trabaja en Data Egret. Data Egret se dedica a la consultoría en el campo de PostgreSQL, ayuda a muchas compañías a usar PostgreSQL correctamente y, por supuesto, ha adquirido una amplia experiencia en el funcionamiento de la base de datos.
El informe en el que se basa este artículo se llama "Historias de fallas de Patroni o Cómo bloquear su clúster PostgreSQL", aquí hay un enlace a la presentación .

Antes de que empieces


Déjame recordarte qué es Patroni, para qué está destinado y qué puede hacer.

Patroni es una plantilla para construir HA fuera de la caja. Por lo tanto, está escrito en la documentación y, desde mi punto de vista, esta es una aclaración muy correcta. Es decir, Patroni no es una bala de plata que estableció y resolverá todos los problemas. Es necesario hacer esfuerzos para que comience a funcionar y traer beneficios.

Patroni - servicio de agente. Se instala en cada servidor con una base de datos y es una especie de sistema de inicio para PostgreSQL: se inicia, se detiene, se reinicia, cambia la configuración y la topología del clúster.

Patroni almacena el "estado del clúster" en DCS.Para almacenar el estado del clúster, su vista actual, necesita almacenamiento. Patroni almacena el estado en un sistema externo: un repositorio de configuración distribuido. Esta puede ser una de las opciones: Etcd, Consul, ZooKeeper o Etcd Kubernetes.

Patroni AutoFile está habilitado de forma predeterminada. Obtiene un archivador automático de la caja, inmediatamente después de instalar Patroni.

Además, hay muchas otras cosas, como: mantenimiento de configuraciones, creación de nuevas réplicas, copia de seguridad, etc. Pero esta vez permanecerá fuera del alcance del informe.
El objetivo principal de Patroni es proporcionar un archivador automático confiable.
Patroni no tiene que monitorear el equipo, enviar notificaciones, hacer cosas complicadas sobre la posible prevención de accidentes, etc. Es necesario que el clúster permanezca operativo y que la aplicación pueda continuar trabajando con la base de datos, independientemente de cualquier cambio en la topología del clúster.

Pero cuando comenzamos a usar Patroni con PostgreSQL, nuestro sistema se vuelve un poco más complicado. Ahora, además de la base de datos en sí, cuando falla el maestro o la réplica, Patroni mismo, el almacenamiento distribuido de los estados del clúster o la red pueden fallar. Considere todas las opciones a medida que se vuelven más complicadas en términos de lo difícil que es comprender sus causas.

Problema 1. DBMS y DCS en el mismo clúster


Considere el caso más simple: tomamos un clúster de base de datos e implementamos DCS en el mismo clúster. Este error común no solo está relacionado con los errores de implementación de PostgreSQL y Patroni. Esto es un error en la construcción general de arquitecturas, ya que combina muchos componentes diferentes en un solo lugar.

Entonces, hubo una conmutación por error. Comenzamos a entender lo que pasó. Aquí nos interesa saber cuándo ocurrió el feylover, es decir, el momento en que cambió el estado del clúster.

¿Cuándo ocurrió la conmutación por error?


Un faylover no siempre ocurre instantáneamente; puede llevar mucho tiempo. Por lo tanto, tiene una hora de inicio y una hora de finalización. Todos los eventos se dividen en "antes", "durante" y "después" del feylover.

En primer lugar, cuando ocurrió el feylover, estamos buscando la razón.

pgdb-2 patroni: INFO: promoted self to leader by acquiring session lock
pgdb-2 patroni: WARNING: Loop time exceeded, rescheduling immediately.
pgdb-2 patroni: INFO: Lock owner: pgdb-2; I am pgdb-2
pgdb-2 patroni: INFO: updated leader lock during promote
pgdb-2 patroni: server promoting
pgdb-2 patroni: INFO: cleared rewind state after becoming the leader
pgdb-2 patroni: INFO: Lock owner: pgdb-2; I am pgdb-2

Arriba están los registros estándar de Patroni, donde informa que la función del servidor ha cambiado y la función del asistente se ha movido de otro a este nodo.

¿Por qué ocurrió la conmutación por error?


A continuación, debe comprender qué eventos hicieron que la función del maestro pasara de un nodo a otro, qué sucedió con el maestro anterior.

pgdb-2 patroni: patroni.utils.RetryFailedError: 'Exceeded retry deadline'
pgdb-2 patroni: ERROR: Error communicating with DCS
pgdb-2 patroni: INFO: demoted self because DCS is not accessible and i was a leader
pgdb-2 patroni: WARNING: Loop time exceeded, rescheduling immediately.

En este caso, todo es simple: Error communicating with DCS- un error al interactuar con el sistema de almacenamiento de configuración. El maestro se dio cuenta de que no podía trabajar con DCS y dijo que ya no podía ser maestro y renunció. demoted selfhabla sobre esto

¿Qué precedió al feylover?


Si observa los eventos que precedieron al feylover, puede ver las razones que se convirtieron en un problema para que el asistente continúe:

pgdb-2 patroni: ERROR: touch_member
                ... python trace 
pgdb-2 patroni: socket.timeout: timed out 
pgdb-2 patroni: During handling of the above exception, another exception occurred:
                ... python trace 
pgdb-2 patroni:   raise ReadTimeoutError(self, url, "Read timed out. (read timeout=%s)" % timeout_value) 
pgdb-2 patroni: urllib3.exceptions.ReadTimeoutError: HTTPConnectionPool(host='127.0.0.1', port=8500): Read timed out. (read timeout=3.3333333333333335) 
pgdb-2 patroni: During handling of the above exception, another exception occurred:
                ... python trace 
pgdb-2 patroni:     raise MaxRetryError(_pool, url, error or ResponseError(cause)) 
pgdb-2 patroni: urllib3.exceptions.MaxRetryError: HTTPConnectionPool(host='127.0.0.1', port=8500): Max retries exceeded with url: /v1/kv/service/pgdb/members/pgdb-2?acquire=19598b72-c0d5-f066-5d24-09c1a9ad61ee&dc=maindb (Caused by ReadTimeoutError("HTTPConnectionPool(host='127.0.0.1', port=8500): Read timed out. (read timeout=3.3333333333333335)",)) 
pgdb-2 patroni: INFO: no action.  i am the leader with the lock 
pgdb-2 patroni: WARNING: Loop time exceeded, rescheduling immediately.

Los registros de Patroni muestran muchos errores de tiempo de espera diferentes. El Agente Patroni no pudo trabajar con DCS (en este caso, es Consul, puerto = 8500). Patroni y la base de datos se ejecutaban en el mismo host, y los servidores de Consul se ejecutaban en el mismo host. Habiendo creado la carga en el servidor, también creamos problemas para el servidor Consul, por lo que no podían comunicarse normalmente.

Todo ha vuelto como estaba


Después de un tiempo, cuando la carga disminuyó, nuestro Patroni pudo comunicarse nuevamente con los agentes, todo se reanudó:

pgdb-2 patroni: INFO: promoted self to leader by acquiring session lock
pgdb-2 patroni: WARNING: Loop time exceeded, rescheduling immediately.
pgdb-2 patroni: INFO: Lock owner: pgdb-2; I am pgdb-2
pgdb-2 patroni: INFO: updated leader lock during promote
pgdb-2 patroni: server promoting
pgdb-2 patroni: INFO: cleared rewind state after becoming the leader
pgdb-2 patroni: INFO: Lock owner: pgdb-2; I am pgdb-2

El mismo servidor pgdb-2 nuevamente se convirtió en maestro. Hubo un pequeño "tirón": en un tiempo relativamente corto renunció a sí mismo como maestro, y luego volvió a tomarlos sobre sí mismo.

Esto puede considerarse como un falso positivo o como el hecho de que Patroni hizo todo bien.

Decisión


Decidimos por nosotros mismos que el problema es que los servidores de Consul están en el mismo hardware que las bases de datos. En consecuencia, cualquier carga en la CPU y los discos (solicitud de E / S pesada, archivos temporales, aspiradoras automáticas, migraciones, copias de seguridad, etc.) también afecta la interacción con el clúster Consul. Decidimos que esto no debería vivir en el mismo equipo con la base de datos, y asignamos un grupo separado para el Cónsul.

Como alternativa, puede girar los parámetros ttl, loop_wait, retry_timeout, intenta debido a su aumento de sobrevivir a los picos de carga a corto plazo. Pero si la carga es larga, iremos más allá de estos parámetros y el método no funcionará.

Problema 2. Interrupciones


El segundo problema es similar al primero en que nuevamente tenemos problemas para interactuar con el sistema DCS:

maindb-1 patroni: ERROR: get_cluster 
maindb-1 patroni: Traceback (most recent call last):
                ... python trace 
maindb-1 patroni: RetryFailedError: 'Exceeded retry deadline' 
maindb-1 patroni: ERROR: Error communicating with DCS 
maindb-1 patroni: INFO: closed patroni connection to the postgresql cluster 
maindb-1 patroni: INFO: postmaster pid=214121 
... 
... 
maindb-1 patroni: INFO: demoted self because DCS is not accessible and i was a leader 
maindb-1 patroni: WARNING: Loop time exceeded, rescheduling immediately.

Patroni nuevamente dice que no puede interactuar con DCS, por lo que el maestro actual deja de ser un maestro y entra en modo de réplica. El viejo maestro se convierte en una réplica:

maindb-1 patroni: INFO: Lock owner: maindb-2; I am maindb-1 
maindb-1 patroni: INFO: does not have lock 
maindb-1 patroni: INFO: running pg_rewind from maindb-2 
maindb-1 patroni: INFO: running pg_rewind from user=postgres host=192.168.11.18 port=5432 ... 
maindb-1 patroni: servers diverged at WAL location 1FA/A38FF4F8 on timeline 6 
maindb-1 patroni: rewinding from last common checkpoint at 1FA/A38FF450 on timeline 6 
maindb-1 patroni: INFO: Lock owner: maindb-2; I am maindb-1 
maindb-1 patroni: INFO: running pg_rewind from maindb-2 in progress 
maindb-1 patroni: Done!

Aquí Patroni funciona como debería: se inicia pg_rewindpara rebobinar el registro de transacciones, luego se conecta al nuevo maestro y ya se pone al día con el nuevo maestro.

¿Qué precedió al feylover?


Encontremos lo primero que precedió al feylover: los errores que lo causaron. Los registros de Patroni son convenientes a este respecto: escribe los mismos mensajes con cierto intervalo. Puede desplazarlos rápidamente y ver cuándo han cambiado los registros. En este punto, comenzaron algunos problemas.

En una situación normal, los registros de Patroni se ven así:

maindb-1 patroni: INFO: Lock owner: maindb-1; I am maindb-1
maindb-1 patroni: INFO: no action. i am the leader with the lock
maindb-1 patroni: INFO: Lock owner: maindb-1; I am maindb-1
maindb-1 patroni: INFO: no action. i am the leader with the lock

El propietario del bloqueo se verifica, si cambia, pueden ocurrir eventos a los que Patroni debe responder. En este caso, todo está en orden con nosotros.

Después de desplazarse al lugar donde comenzaron a aparecer los errores, vemos que se produjo un archivador automático. Dado que los errores estaban relacionados con la interacción con DCS, también miramos los registros del Cónsul, lo que sucedió allí. Comparando aproximadamente el tiempo del faylover y el tiempo en los registros del cónsul, vemos que los vecinos del grupo de cónsules comenzaron a dudar de la existencia de otros participantes:

maindb-2 consul[11581]: serf: EventMemberFailed: maindb-1 192.168.11.19
maindb-2 consul[11581]: [INFO] serf: EventMemberFailed: maindb-1 192.168.11.19
maindb-2 consul[11581]: memberlist: Suspect maindb-1 has failed, no acks received
maindb-2 consul[11581]: [INFO] memberlist: Suspect maindb-1 has failed, no acks received

Si observa los registros de otros agentes del Cónsul, también muestra que hay un colapso de la red: todos los miembros del grupo Cónsul dudan entre sí. Este fue el impulso para el feylover.

Si observamos entradas anteriores, veremos que el sistema de Cónsul para el agente PostgreSQL tiene dificultades con la comunicación ( deadline reached, RPC failed):

maindb-1 consul: memberlist: Suspect lbs-4 has failed, no acks received
maindb-1 consul: [ERR] yamux: keepalive failed: i/o deadline reached
maindb-1 consul: yamux: keepalive failed: i/o deadline reached
maindb-1 consul: [ERR] consul: "KVS.List" RPC failed to server 192.168.11.115:8300: rpc error making call: EOF
maindb-1 consul: [ERR] http: Request GET /v1/kv/service/sam_prod/?recurse=1, error: rpc error making call: EOF from=192.168.11.19
maindb-1 consul: [ERR] consul: "KVS.List" RPC failed to server 192.168.11.115:8300: rpc error making call: EOF
maindb-1 consul: [ERR] agent: Coordinate update error: rpc error making call: EOF
maindb-1 consul: [ERR] http: Request GET /v1/kv/service/sam_prod/?recurse=1, error: rpc error making call: EOF from=192.168.11.19


Decisión


La respuesta más simple es reparar la red . Es fácil aconsejar, pero las circunstancias pueden ser diferentes, y esto no siempre es posible. El sistema puede vivir en un centro de datos, donde no podemos influir en el equipo. Necesito otras opciones.

Hay opciones de solución sin trabajar con una red:

  • Consul- — checks: [].
    , . , Consul- . .
  • raft_multiplier.
    Consul-, 5 ( staging-). Consul-. - .
  • renice -n -10 consul.
    . renice . Consul-, .
  • consul?
    Consul- . Patroni Consul- , : - , Patroni . etcd, , etcd . Patroni etcd-. - , , , Consul.
  • ttl, loop_wait, retry_timeout.
    , . Patroni .


Problema 3. Pérdida de nodo


Si está utilizando Patroni, entonces está familiarizado con el comando patronictl list, que muestra el estado actual del clúster:

$ patronictl list

+-----------------+-------------------------+--------------+--------+---------+-----------+
|     Cluster     |          Member         |     Host     |  Role  |  State  | Lag in MB |
+-----------------+-------------------------+--------------+--------+---------+-----------+
| patroni_cluster | pg01.dev.zirconus.local | 10.202.1.101 |        | running |    0.0    |
| patroni_cluster | pg03.dev.zirconus.local | 10.202.1.103 | Leader | running |    0.0    |
+-----------------+-------------------------+--------------+--------+---------+-----------+


A primera vista, tal conclusión puede parecer normal: hay un maestro, réplicas, pero no hay retraso de replicación. Pero esta imagen es normal exactamente hasta que sepamos que en este grupo debería haber 3 nodos, y no 2.

¿Por qué ocurrió la conmutación por error?


Entendemos que se produjo un archivador automático y luego desapareció una réplica. Necesitamos averiguar por qué desapareció y traerla de vuelta.

Estudiamos los registros nuevamente para comprender por qué se produjo el archivador automático:

pg02 patroni[1425]: ERROR: failed to update leader lock
pg02 patroni[1425]: INFO: demoted self because failed to update leader lock in DCS
pg02 patroni[1425]: WARNING: Loop time exceeded, rescheduling immediately.
pg02 patroni[1425]: INFO: Lock owner: None; I am pg02.dev.zirconus.local
pg02 patroni[1425]: INFO: not healthy enough for leader race
pg02 patroni[1425]: INFO: starting after demotion in progress

El maestro pg02 no pudo actualizar la clave maestra ERROR: failed to update leader lock.

Luego, la segunda réplica de db03 se convirtió en el maestro, todo está en orden aquí:

pg03 patroni[9648]: INFO: promoted self to leader by acquiring session lock
pg03 patroni[9648]: server promoting
pg03 patroni[9648]: INFO: cleared rewind state after becoming the leader

¿Qué hay del viejo maestro?


pg02, decidiendo convertirse en una réplica, comenzó rebobinando el registro de transacciones. Aquí tenemos que mirar los registros de réplica, que no está en el clúster. Abra los registros de Patroni y vea que durante el proceso de conexión al clúster, surgió un problema en la etapa pg_rewind.

pg02 patroni[1425]: INFO: running pg_rewind from pg03
pg02 patroni[1425]: INFO: running pg_rewind from user=postgres host=10.202.1.103 port=5432 ...
pg02 patroni[1425]: servers diverged at WAL location 33F/68E6AD10 on timeline 28
pg02 patroni[1425]: could not open file "/data/pgdb/11/pg_wal/0000001C0000033F00000059": No such file or directory
pg02 patroni[1425]: could not find previous WAL record at 33F/59FFE368 pg02 patroni[1425]: Failure, exiting
pg02 patroni[1425]: ERROR: Failed to rewind from healty master: pg03
pg02 patroni[1425]: WARNING: Postgresql is not running.

Para conectarse al clúster, el nodo debe solicitar el registro de transacciones del asistente y capturarlo. En este caso, no hay registro de transacciones ( No such file or directory) y la réplica no puede iniciarse. En consecuencia, PostgreSQL se detiene con un error. Debe comprender por qué no había registro de transacciones.

Veamos qué tiene el nuevo maestro en WAL:

LOG: checkpoint complete:
wrote 62928 buffers (16.0%); 0 WAL file(s) added, 0 removed, 23 recycled;
write=12.872 s, sync=0.020 s, total=13.001 s;
sync files=16, longest=0.009 s, average=0.001 s;
distance=520220 kB, estimate=520220 kB

Resulta que mientras se estaba ejecutando pg_rewind, se produjo un punto de control y se cambió el nombre de algunos de los registros de transacciones anteriores . Cuando el viejo maestro intentó conectarse al nuevo maestro y solicitar estos registros, ya se les cambió el nombre, simplemente no existían.

Según la marca de tiempo, el tiempo entre estos eventos es literalmente de 150 ms.

2019-08-26 00:06:11,369 LOG: checkpoint complete
2019-08-26 00:06:11,517 INFO: running pg_rewind

Pero esto fue suficiente para que la réplica no pueda conectarse y ganar.

Decisión


Inicialmente, utilizamos ranuras de replicación. Esta solución nos pareció buena, aunque en la primera etapa de la operación apagamos las ranuras. Pensamos que si las ranuras acumularan muchos segmentos de pared, el maestro podría caerse. Habiendo sufrido durante un tiempo sin espacios, nos dimos cuenta de que los necesitábamos y los devolvimos.

El problema es que cuando el asistente ingresa al estado de réplica, el asistente elimina las ranuras y los segmentos wal junto con ellos. Para nivelar este problema, aumentamos el parámetro wal_keep_segments. Por defecto, es igual a 8 segmentos, nos planteamos wal_keep_segmentsa 1.000 . Asignamos 16 GB wal_keep_segmentsy ahora, al cambiar, siempre tenemos 16 GB de registros de transacciones en todos los nodos.

Esto también es cierto para las tareas de mantenimiento a largo plazo. Supongamos que necesitamos actualizar una de las réplicas (software, sistema operativo, algo más) y queremos desactivarla. Cuando apagamos la réplica, la ranura también se elimina. Si utiliza un valor de parámetro pequeño wal_keep_segments, durante una larga ausencia de una réplica, solicitará los registros de transacciones que ni siquiera aparezcan en el asistente; entonces la réplica no podrá conectarse. Por lo tanto, mantenemos una gran oferta de revistas.

Problema 4. Pérdida de datos


Hubo una conmutación por error en una base de producción. Verificamos el clúster: todo está en orden, todas las réplicas están en su lugar, no hay retraso de replicación y tampoco hay errores en los registros. Pero el equipo del producto informa que no hay suficientes datos en la base de datos : están en una fuente, pero no en la base de datos. Necesitas entender lo que les pasó.

Inmediatamente nos dimos cuenta de que era pg_rewindsu mermelada, pero tenemos que averiguar por qué.

¿Cuándo ocurrió la conmutación por error?


Siempre podemos encontrar en los registros cuándo ocurrió el feylover, quién se convirtió en el nuevo maestro, quién era el maestro antes y cuándo quería convertirse en una réplica.

pgdb-1 patroni[17836]: INFO: promoted self to leader by acquiring session lock
pgdb-1 patroni[17836]: server promoting
pgdb-1 patroni[17836]: INFO: cleared rewind state after becoming the leader
pgdb-1 patroni[17836]: INFO: Lock owner: pgdb-1; I am pgdb-1

A partir de los registros, podemos determinar cuántos registros de transacciones se han perdido.

Fue así: el viejo asistente se reinició, después de que se reiniciara con la ejecución automática, se lanzó Patroni, que luego lanzó PostgreSQL. PostgreSQL decidió convertirse en miembro del clúster Patroni y lanzó un proceso pg_rewindque a su vez borró parte de los registros de transacciones, descargó nuevos y se conectó.

Patroni trabajó exactamente como estaba previsto. El grupo se recuperó: había 3 nodos, después del feylover, 3 nodos y se fueron. Pero parte de los datos se pierden y debe comprender de qué parte se trata.

Encuentra en los registros del viejo maestro el momento en que sucedió pg_rewind:

pgdb-2 patroni[4149]: INFO: running pg_rewind from pgdb-1
pgdb-2 patroni[4149]: Lock owner: pgdb-1; I am pgdb-2
pgdb-2 patroni[4149]: Deregister service pgdb/pgdb-2
pgdb-2 patroni[4149]: running pg_rewind from pgdb-1 in progress
pgdb-2 patroni[4149]: running pg_rewind from user=replica host=10.10.1.31 port=5432 ...
pgdb-2 patroni[4149]: servers diverged at WAL location 0/5AD1BFD8 on timeline 66
pgdb-2 patroni[4149]: rewinding from last common checkpoint at 0/59DD1070 on timeline 66
pgdb-2 patroni[4149]: Done!

Debe encontrar la posición en el registro de transacciones, que detuvo al antiguo maestro.

pgdb-2 patroni[4149]: INFO: Local timeline=66 lsn=0/5BDA8EB8
pgdb-2 patroni[4149]: INFO: master_timeline=67
...
pgdb-2 patroni[4149]: servers diverged at WAL location 0/5AD1BFD8 on timeline 66
postgres=# select pg_wal_lsn_diff('0/5BDA8EB8','0/5AD1BFD8');
pg_wal_lsn_diff
----------------
17354464

En este caso, es la marca 0 / 5BDA8EB8. La segunda marca, 0 / 5AD1BFD8, es necesaria para encontrar la distancia en la que el antiguo maestro difiere del nuevo. Usando la función pg_wal_lsn_diff , comparamos estas dos marcas, obtenemos 17 MB.

Ya sea que haya una gran pérdida de 17 MB de datos, todos deciden por sí mismos. Para algunos, esto es insignificante, pero para alguien es inaceptable. Cada uno por sí mismo determina individualmente de acuerdo con las necesidades del negocio.

Decisión


En primer lugar, debe decidir si el inicio automático de Patroni siempre es necesario después de reiniciar el sistema . Muy a menudo, deberíamos ir al antiguo maestro, ver qué tan diferente es del estado actual, quizás inspeccionar los segmentos del registro de transacciones. Debe comprender si estos datos se pueden perder o si necesita ejecutar el asistente anterior en modo independiente para extraer los datos. Solo después de eso, decida qué hacer con los datos y conecte este nodo como una réplica a nuestro clúster.

Además, hay un parámetromaximum_lag_on_failover, su valor predeterminado es 1 Mb. Funciona así: si la réplica está 1 MB detrás del retraso de replicación, entonces esta réplica no participa en las elecciones. Si de repente ocurre una conmutación por error, Patroni observa qué réplicas están rezagadas, y aquellas que están rezagadas detrás de una gran cantidad de registros de transacciones no pueden convertirse en maestros. Esta es una buena característica de seguridad que le impide perder demasiados datos.

Pero hay un problema: el retraso de replicación se actualiza en un intervalo determinado, el valor ttlpredeterminado es 30 s. Es muy posible que el valor del retraso de replicación para las réplicas en DCS sea uno, pero de hecho es completamente diferente o no hay ningún retraso. Este no es un valor en tiempo real; no siempre refleja la imagen real y no vale la pena vincularle una lógica compleja.

El riesgo de "pérdidas" siempre permanece:

  • En el peor de los casos: maximum_lag_on_failover + ttl.
  • En el caso promedio: maximum_lag_on_failover + (loop_wait / 2).

Cuando planea implementar Patroni y evaluar la cantidad de datos que puede perder, considere estas fórmulas para representar aproximadamente posibles pérdidas.

La buena noticia es que puede haber una WAL de procesos en segundo plano en las "pérdidas". Estos datos se pueden ignorar y perder fácilmente, no hay problema.

Así es como se ven los registros si están configurados maximum_lag_on_failover, se produjo un feylover y debe seleccionar un nuevo asistente:

pgdb-1 patroni[6202]: INFO: Lock owner: None; I am pgdb-1
pgdb-1 patroni[6202]: INFO: not healthy enough for leader race
pgdb-1 patroni[6202]: INFO: changing primary_conninfo and restarting in progress
...
pgdb-1 patroni[6202]: INFO: following a different leader because i am not the healthiest node
pgdb-1 patroni[6202]: INFO: following a different leader because i am not the healthiest node

La réplica simplemente ve que ella not healthy enough for leader racees y se niega a participar en la carrera de liderazgo. Por lo tanto, simplemente espera a que se seleccione un nuevo asistente para conectarse a él. Esta es una medida adicional contra la pérdida de datos.

Problema 5. Unidades


El equipo del producto escribió que la aplicación tiene problemas para trabajar con PostgreSQL. Al mismo tiempo, no puede ingresar al maestro, porque no está disponible a través de SSH, pero el archivador automático tampoco ocurre. Luego, el host se reinició por la fuerza y, por lo tanto, lanzó el archivador automático. Aunque fue posible hacer un feylover manual.

Después del reinicio, vamos a ver qué pasó con el maestro.



Sabíamos de antemano los problemas con los discos; al monitorear sabíamos dónde cavar.

En los registros de PostgreSQL, vemos lo siguiente:

[COMMIT] LOG: duration: 1138.868 ms statement: COMMIT
...
[] WARNING: autovacuum worker started without a worker entry
...
[SELECT] LOG: temporary file: path "base/pgsql_tmp/pgsql_tmp11247.983", size 532996096
...

En la cara están todos los indicadores de problemas con los discos: confirmaciones que duran un segundo, el vacío automático se ejecuta muy largo y extraño, y los archivos temporales en el disco.

Examinamos el sistema dmesg, el registro de mensajes del núcleo, y vimos un problema con uno de los discos:

md/raid10:md2: sde3: rescheduling sector 351273392
blk_update_request: I/O error, dev sde, sector 64404728
md/raid10:md2: sde3: rescheduling sector 63161592
blk_update_request: I/O error, dev sde, sector 64404760
...
md2 : active raid10 sda3[0] sdc3[2] sdd3[3] sdb3[1] sdh3[7] sdf3[5] sdg3[6]
      15623340032 blocks super 1.2 512K chunks 2 near-copies [8/7] [UUUUUUU_]
      bitmap: 58/59 pages [232KB], 131072KB chunk

El subsistema de disco en el servidor era un Raid de software de 8 discos, pero faltaba uno. sda3[0] sdc3[2] sdd3[3] sdb3[1] sdh3[7] sdf3[5] sdg3[6]Falta la línea sde[4]. Relativamente hablando, un disco se cayó, esto causó problemas de disco, y la aplicación tuvo problemas para trabajar con el clúster PostgreSQL.

Decisión


En este caso, Patroni no podría ayudar, porque Patroni no tiene la tarea de monitorear el estado del servidor y los discos. Durante los problemas, Patroni continuó interactuando con el clúster DCS y no vio ninguna dificultad. Para tales situaciones, se necesita monitoreo externo.

Problema 6. Simulador de clúster


Este es uno de los problemas más extraños. Lo estudié durante mucho tiempo, releí muchos registros y lo llamé "Simulador de clúster".

El problema era que el viejo maestro no podía convertirse en una señal normal. Patroni lo ejecutó, mostró que este nodo está presente como una réplica, pero al mismo tiempo no era una réplica normal, ahora verá por qué.

Todo comenzó, como en el caso anterior, con problemas de disco:

14:48:55.601 [COMMIT] LOG: duration: 1478.118 ms statement: COMMIT
14:48:56.287 [COMMIT] LOG: duration: 1290.203 ms statement: COMMIT
14:48:56.287 [COMMIT] LOG: duration: 1778.465 ms statement: COMMIT
14:48:56.287 [COMMIT] LOG: duration: 1778.449 ms statement: COMMIT

Hubo conexiones rotas:

14:48:58.078 [idle in transaction] LOG: could not send data to client: Broken pipe
14:48:58.078 [idle] LOG: could not send data to client: Broken pipe
14:48:58.078 [idle] FATAL: connection to client lost
14:48:58.107 [idle in transaction] FATAL: connection to client lost

Había largas expectativas de una respuesta y bloqueo de diversa gravedad:

14:49:26.929 [UPDATE waiting] LOG: process 4298 acquired ExclusiveLock on tuple (2,10) of relation 52082 of database 50587 after 52487.463 ms
14:49:26.929 [UPDATE waiting] STATEMENT: UPDATE sessions SET lastaccess='1565005714' WHERE sessionid=...
14:49:27.929 [UPDATE waiting] LOG: process 4298 still waiting for ShareLock on transaction 364118337 after 1000.088 ms
14:49:27.929 [UPDATE waiting] DETAIL: Process holding the lock: 4294. Wait queue: 4298.

En general, hay problemas obvios con los discos, incluidos los archivos temporales nuevamente.

Pero lo más misterioso para mí: voló immediate shutdown request:

14:49:34.102 MSK 5335 @ from [] LOG: received immediate shutdown request
14:49:34.689 [authentication] WARNING: terminating connection because of crash of another server process
14:49:34.689 [authentication] DETAIL: The postmaster has commanded this server process to roll back the current transaction and exit, because another server process exited abnormally and possibly corrupted shared memory

PostgreSQL tiene tres modos de apagado:

  • Agraciado cuando esperamos que todos los clientes se desconecten solos.
  • Rápido, cuando les decimos a los clientes que se desconecten, porque vamos a cerrar.
  • Inmediato, que no le dice a los clientes que es necesario desconectarse, sino que simplemente lo apaga y envía un mensaje RST a todos los clientes (señal TCP de que la conexión se interrumpió).

Los procesos en segundo plano de PostgreSQL no se envían señales de solicitud de apagado inmediato, sino que solo responden a ellos. Este es un reinicio de emergencia, y quién lo envió no está claro. Si lo fuera kill -9, lo vería en los registros, pero no estaba allí.

Comprendiendo más, vi que Patroni no escribió en el registro durante bastante tiempo, simplemente no hubo mensajes durante 54 segundos. Durante este tiempo, una de las réplicas se hizo "promocionar" y se produjo un archivador automático:

pgsql03 patroni: 14:48:25,000 INFO: Lock owner: pgsql03; I am pgsql03 
pgsql03 patroni: 14:48:25,013 INFO: no action.  i am the leader with the lock 
pgsql03 patroni: 14:48:37,159 INFO: Lock owner: pgsql03; I am pgsql03 
pgsql03 patroni: 14:49:31,155 WARNING: Exception hened during processing of request from 10.1.0.12 
pgsql03 patroni: 14:49:31,297 WARNING: Exception hened during processing of request from 10.1.0.11 
pgsql03 patroni: 14:49:31,298 WARNING: Exception hened during processing of request from 10.1.0.11

Patroni volvió a funcionar perfectamente aquí, el viejo maestro no estaba disponible, por lo que comenzó la elección de un nuevo maestro.

pgsql01 patroni: 14:48:57,136 INFO: promoted self to leader by acquiring session lock
pgsql01 patroni: server promoting
pgsql01 patroni: 14:48:57,214 INFO: cleared rewind state after becoming the leader
pgsql01 patroni: 14:49:05,013 INFO: Lock owner: pgsql01; I am pgsql01
pgsql01 patroni: 14:49:05,023 INFO: updated leader lock during promote

pgsql01 se convirtió en el nuevo líder, y solo hubo problemas con la segunda réplica. Honestamente trató de reconfigurar:

pgsql02 patroni: 14:48:57,124 INFO: Could not take out TTL lock 
pgsql02 patroni: 14:48:57,137 INFO: following new leader after trying and failing to obtain lock 
pgsql02 patroni: 14:49:05,014 INFO: Lock owner: pgsql01; I am pgsql02 
pgsql02 patroni: 14:49:05,025 INFO: changing primary_conninfo and restarting in progress 
pgsql02 patroni: 14:49:15,011 INFO: Lock owner: pgsql01; I am pgsql02
pgsql02 patroni: 14:49:15,014 INFO: changing primary_conninfo and restarting in progress 
pgsql02 patroni: 14:49:25,011 INFO: Lock owner: pgsql01; I am pgsql02 
pgsql02 patroni: 14:49:25,014 INFO: changing primary_conninfo and restarting in progress 
pgsql02 patroni: 14:49:35,011 INFO: Lock owner: pgsql01; I am pgsql02 
pgsql02 patroni: 14:49:35,014 INFO: changing primary_conninfo and restarting in progress

Intentó cambiar recovery.conf, reiniciar PostgreSQL, conectarse al nuevo asistente. Cada 10 segundos hay mensajes que está intentando, pero no puede.

Mientras tanto, la misma señal de apagado inmediato voló hacia el viejo maestro. El asistente inició un reinicio de emergencia, la recuperación también se detiene. La réplica no se puede conectar al maestro porque está en modo de apagado.

14:49:34.293 [idle] LOG:  received replication command: IDENTIFY_SYSTEM 
WARNING:  terminating connection because of crash of another server process 
DETAIL:  The postmaster has commanded this server process to roll back the current transaction and exit, because another server process exited abnormally and possibly corrupted shared memory. 
14:49:35.232 FATAL:  could not receive data from WAL stream: server closed the connection unexpectedly             
        This probably means the server terminated abnormally 
        before or while processing the request. 
14:49:35.232 LOG:  record with incorrect prev-link 142D46/315602C at 14CF/CF38C160 
14:49:35.305 FATAL: could not connect to the primary server: FATAL: the database system is shutting down 
14:49:40.241 FATAL: could not connect to the primary server: FATAL: the database system is shutting down

En algún momento, la réplica funcionó, pero la réplica no comenzó.

14:50:14.024 [] LOG:  record with incorrect prev-link 142D46/315602C at 14CF/CF38C160 
14:50:14.028 [] LOG:  fetching timeline history file for timeline 72 from primary server 
14:50:14.104 [] FATAL:  could not start WAL streaming: ERROR:  requested starting point 14CF/CF000000 on timeline 71 is not in this server's history        
DETAIL:  This server's history forked from timeline 71 at 14CF/CEC32E40. 
14:50:14.104 [] LOG:  new timeline 72 forked off current database system timeline 71 before current recovery point 14CF/CF38C160

Tengo una sola hipótesis: en recovery.conf era la dirección del viejo maestro. Cuando ya apareció un nuevo maestro, la segunda réplica intentó conectarse al viejo maestro. Cuando Patroni comenzó en la segunda réplica, el nodo se inició, pero no pudo conectarse a través de la replicación. Se formó un retraso de replicación que se parecía a esto:

+-----------------+----------+--------------+--------+---------+-----------+
|     Cluster     |  Member  |     Host     |  Role  |  State  | Lag in MB |
+-----------------+----------+--------------+--------+---------+-----------+
| patroni_cluster |  pgsql01 | 10.2.200.151 | Leader | running |       0.0 |
| patroni_cluster |  pgsql02 | 10.2.200.152 |        | running |    9153.0 |
| patroni_cluster |  pgsql03 | 10.2.200.153 |        | running |       0.0 |
+-----------------+----------+--------------+--------+---------+-----------+

Es decir, los tres nodos estaban en su lugar, pero el segundo nodo estaba detrás. La replicación no pudo comenzar porque los registros de transacciones eran diferentes. Los registros de transacciones ofrecidos por el asistente, indicados en recovery.conf, simplemente no se ajustaban al nodo actual. PostgreSQL reportó un error cada 5 segundos

14:50:44.143 FATAL:  could not start WAL streaming: ERROR:  requested starting point 14CF/CF000000 on timeline 71 is not in this server's history        
         DETAIL:  This server's history forked from timeline 71 at 14CF/CEC32E40. 
14:50:44.143 LOG:  new timeline 72 forked off current database system timeline 71 before current recovery point 14CF/ CF38C160

Aquí cometí un error y no probé mi hipótesis de que nos estamos conectando con el maestro equivocado. Acabo de reiniciar Patroni en la réplica. Honestamente, ya le puse fin y pensé que tendría que rehacerlo, pero aun así decidí intentar reiniciarlo.

15:14:13.511 LOG: consistent recovery state reached at 14CF/A3F657B0
15:14:13.511 LOG: database system is ready to accept read only connections

La recuperación comenzó, e incluso la base de datos abierta, estaba lista para aceptar la conexión, comenzó la replicación:

15:14:17.072 LOG: record with incorrect prev-link 142D46/315602C at 14CF/CF38C160
15:14:17.077 LOG: started streaming WAL from primary at 14CF/CF000000 on timeline 72
15:14:17.536 LOG: invalid record length at 14CF/CF38C160: wanted 24, got 1

Pero un minuto después se cayó con un error terminating walreceiver process due to administrator command: la réplica decía que los registros de transacciones no eran adecuados para ella.

15:15:27.823 FATAL: terminating walreceiver process due to administrator command
15:15:27.895 LOG: invalid record length at 14CF/CF38C160: wanted 24, got 1
15:15:27.895 LOG: invalid record length at 14CF/CF38C160: wanted 24, got 1

Y no reinicié PostgreSQL, pero fue Patroni el que se reinició con la esperanza de que lanzara mágicamente la base de datos. La replicación comenzó nuevamente, pero la base de datos se abrió en el mismo lugar:

15:17:33.553 LOG: consistent recovery state reached at 14CF/A3F657B0
15:17:33.554 LOG: database system is ready to accept read only connections

Las marcas en el registro de transacciones eran diferentes, eran diferentes que en el intento de lanzamiento anterior; la posición del registro de transacciones era anterior:

15:17:37.299 LOG: invalid contrecord length 5913 at 14CF/CEFFF7B0
15:17:37.304 LOG: started streaming WAL from primary at 14CF/CE000000 on timeline 72

La replicación se detuvo nuevamente, y el mensaje de error fue diferente y nuevamente no muy informativo:

15:18:12.208 FATAL: terminating walreceiver process due to administrator command
15:18:12.240 LOG: record with incorrect prev-link 60995000/589DF000 at 14CF/CEFFF7B0
15:18:12.240 LOG: record with incorrect prev-link 60995000/589DF000 at 14CF/CEFFF7B0

Para el experimento, reiniciado nuevamente, la base se abrió en el mismo lugar:

15:21:25.135 LOG: consistent recovery state reached at 14CF/A3F657B0
15:21:25.135 LOG: database system is ready to accept read only connections

Entonces se me ocurrió la idea: que si reinicio PostgreSQL, en este punto del asistente actual, haré un punto de control para mover el punto en el registro de transacciones un poco más adelante y la recuperación comenzará en otro momento.

Lanzó Patroni, hizo un par de puntos de control en el maestro, un par de puntos de reinicio en la réplica cuando se abrió:

15:22:43.727 LOG: invalid record length at 14D1/BCF3610: wanted 24, got 0
15:22:43.731 LOG: started streaming WAL from primary at 14D1/B000000 on timeline 72

Funcionó: la replicación comenzó desde un lugar diferente y ya no se rompió. Pero para mí este es uno de los problemas más misteriosos sobre los que todavía me estoy estrujando el cerebro. Especialmente esa extraña solicitud de cierre inmediato.

De esto podemos concluir: Patroni puede funcionar según lo planeado y sin errores, pero esto no es una garantía absoluta de que todo esté realmente en orden. Después del feylover, siempre debe verificar que todo esté bien con el clúster: la cantidad correcta de réplicas, sin retraso de replicación.

Resumen


En base a estos y muchos otros problemas similares, formulé recomendaciones generales que le aconsejo que tenga en cuenta al operar Patroni.

  • Cuando usa Patroni, debe tener monitoreo. Siempre necesita saber cuándo se produjo un archivo automático, porque si no sabe que tiene un archivo automático, no controla el clúster.
  •  Después de cada feylover siempre verifique un clúster. Debe asegurarse de que: las réplicas sean siempre el número actual; sin retraso de replicación; no hay errores en los registros relacionados con la replicación de transmisión, con Patroni, con el sistema DCS.

Patroni es una muy buena herramienta, pero no importa cómo diga que no es una bala de plata. La automatización puede funcionar con éxito, pero al mismo tiempo, los objetos de automatización pueden estar en un estado de trabajo medio. De todos modos, debe tener una idea de cómo funcionan PostgreSQL y la replicación, cómo Patroni administra PostgreSQL y cómo se garantiza la interacción entre los nodos. Esto es necesario para poder reparar los problemas que surgen con sus manos.

Pasos de diagnóstico


Dio la casualidad de que trabajamos con diferentes clientes, en su mayor parte no tienen una pila ELK, y debe ordenar los registros abriendo 2 pestañas y 6 consolas: en una pestaña Patroni para cada nodo, en el otro: registros Consul o PostgreSQL. Diagnosticar todo esto es difícil.

He desarrollado el siguiente enfoque. Siempre miro cuando se produce una conmutación por error. Para mí es una especie de cuenca hidrográfica. Miro lo que sucedió antes, durante y después de la fiebre. La conmutación por error tiene dos marcas de tiempo: inicio y fin. En los registros, miro lo que precedió al feylover, es decir, estoy buscando razones. Esto proporciona una comprensión de la imagen de lo que sucedió y lo que se puede hacer en el futuro para que el feylover no ocurra en las mismas circunstancias.

Para esto, miro:

  • En primer lugar, los registros de Patroni.
  • PostgreSQL DCS , Patroni.
  • — , .


Hay muchos otros productos para el archivador automático: stolon, repmgr, pg_auto_failover, PAF. Probé las 4 herramientas y, en mi opinión, Patroni es la mejor que hay en el mercado hoy.

¿Recomiendo Patroni? Definitivamente, sí, porque me gusta Patroni, creo que aprendí a cocinarlo.

Si está interesado en ver qué otros problemas hay con Patroni, además de los descritos en el artículo, siempre puede ir a la página https://github.com/zalando/patroni/issues . Hay muchas historias diferentes. A pesar de que la mitad de ellos son de usuarios analfabetos que hacen preguntas estúpidas sin molestarse en molestarse con una simple búsqueda, también se discuten problemas interesantes allí y, como resultado de las discusiones, se abren tareas para corregir errores si es necesario.

Gracias a Zalando por desarrollar este proyecto, así como a las dos personas que comenzaron a trabajar en este producto: Alexander Kukushkin y Alexey Klyukin. Muchas gracias a todos los contribuyentes de Patroni.

Después de este informe, grabamos una breve entrevista en la que Alex intentó incluir su informe en un consejo y le dijimos por qué participar y hablar en las conferencias. Toma las armas y ven a comprobar el enfoque en Saint HighLoad ++.


HighLoad++ 6-7 . , . , ( , ). - , , , .

Saint HighLoad++! , , PostgreSQL: , PostgreSQL JSON ; PostgreSQL 13, ; .

More articles:


All Articles