O PostgreSQL não possui alta disponibilidade pronta para uso. Para obter HA, você precisa colocar algo, configurar - fazer um esforço. Existem várias ferramentas que podem ajudar a aumentar a disponibilidade do PostgreSQL, e uma delas é o Patroni.À primeira vista, colocando o Patroni em um ambiente de teste, você pode ver o que é uma ótima ferramenta e como ela lida facilmente com nossas tentativas de quebrar o cluster. Mas, na prática, em um ambiente de produção, nem tudo sempre acontece de maneira tão bonita e elegante. O Data Egret começou a usar o Patroni no final de 2018 e ganhou alguma experiência: como diagnosticá-lo, configurá-lo e quando não confiar no arquivador automático.No HighLoad ++, Alexei Lesovsky descreveu em detalhes, usando exemplos e análise de log, os problemas típicos que surgem ao trabalhar com o Patroni e as melhores práticas para superá-los.O artigo não: Instruções de instalação e exemplos de configuração do Patroni; problemas fora do Patroni e PostgreSQL; histórias baseadas nas experiências de outras pessoas, mas apenas nos problemas que o Data Egret descobriu por si mesmos.Sobre o orador: Alexey Lesovsky (lesovsky) começou como administrador de sistema (administrador de sistema Linux), trabalhou em desenvolvimento web (administrador de banco de dados PostgreSQL). Desde 2014, ela trabalha na Data Egret. O Data Egret está envolvido em consultoria no campo do PostgreSQL, ajuda muitas e muitas empresas a usar o PostgreSQL corretamente e, é claro, adquiriu uma vasta experiência na operação do banco de dados.O relatório em que este artigo se baseia é chamado "Histórias de falhas do Patroni ou Como travar seu cluster do PostgreSQL", aqui está um link para a apresentação .Antes que você comece
Deixe-me lembrá-lo do que é Patroni, para que se destina e o que pode fazer.O Patroni é um modelo para a criação de HA fora da caixa. Portanto, está escrito na documentação e do meu ponto de vista - este é um esclarecimento muito correto. Ou seja, Patroni não é uma bala de prata que ele colocou e resolverá todos os problemas. É necessário fazer esforços para que comece a funcionar e traga benefícios.Patroni - serviço de agente. Ele é instalado em cada servidor com um banco de dados e é uma espécie de sistema init para o PostgreSQL: inicia, para, reinicia, altera a configuração e a topologia do cluster.Patroni armazena "estado do cluster" no DCS.Para armazenar o estado do cluster, sua visualização atual, você precisa de armazenamento. Patroni armazena o estado em um sistema externo - um repositório de configuração distribuído. Essa pode ser uma das opções: Etcd, Consul, ZooKeeper ou Etcd Kubernetes.O AutoFile do Patroni está ativado por padrão. Você obtém um arquivador automático imediatamente após a instalação do Patroni.Além disso, existem muitas outras coisas, como: configurações de manutenção, criação de novas réplicas, backup, etc. Mas desta vez permanecerá fora do escopo do relatório.O principal objetivo da Patroni é fornecer um auto-arquivador confiável.
A Patroni não precisa monitorar equipamentos, enviar notificações, fazer coisas complicadas sobre a prevenção de acidentes em potencial, etc. É necessário que o cluster permaneça operacional e o aplicativo possa continuar trabalhando com o banco de dados, independentemente de quaisquer alterações na topologia do cluster.Mas quando começamos a usar o Patroni com o PostgreSQL, nosso sistema fica um pouco mais complicado. Agora, além do próprio banco de dados, quando o mestre ou a réplica falha, o próprio Patroni, o armazenamento distribuído dos estados do cluster ou a rede podem falhar. Considere todas as opções à medida que se tornam mais complicadas em termos de quão difícil é entender suas causas.Problema 1. DBMS e DCS no mesmo cluster
Considere o caso mais simples: pegamos um cluster de banco de dados e implantamos o DCS no mesmo cluster. Este erro comum não está relacionado apenas aos erros de implantação do PostgreSQL e Patroni. Isso é um erro na construção geral de arquiteturas - combinando muitos componentes diferentes em um só lugar.Portanto, houve um failover. Começamos a entender o que aconteceu. Aqui, estamos interessados em quando o feylover ocorreu, ou seja, no momento em que o estado do cluster mudou.Quando o failover aconteceu?
Um amante da fada nem sempre acontece instantaneamente; pode ser demorado. Portanto, ele tem um horário de início e um horário de término. Todos os eventos são divididos em “antes”, “durante” e “depois” do amante dos feys.Primeiro de tudo, quando o amor de fada aconteceu, estamos procurando o motivo.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
Acima estão os logs padrão do Patroni, nos quais ele relata que a função de servidor foi alterada e a função do assistente mudou de outro para este nó.Por que o failover aconteceu?
Em seguida, você precisa entender quais eventos fizeram a função do mestre passar de um nó para outro, o que aconteceu com o antigo mestre.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.
Nesse caso, tudo é simples: Error communicating with DCS- um erro ao interagir com o sistema de armazenamento de configuração. O mestre percebeu que não poderia trabalhar com a DCS e disse que não podia mais ser mestre e renunciou. demoted selffala sobre isso.O que precedeu o amante dos feylover?
Se você observar os eventos que antecederam o amante dos feylovers, poderá ver os motivos que se tornaram um problema para o assistente continuar: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.
Os logs do Patroni mostram muitos erros de tempo limite diferentes. O Patroni Agent não pôde trabalhar com o DCS (neste caso, é Consul, porta = 8500). Patroni e o banco de dados estavam em execução no mesmo host e os servidores Consul estavam em execução no mesmo host. Após criar a carga no servidor, também criamos problemas para o servidor Consul, por causa dos quais eles não podiam se comunicar normalmente.Tudo está de volta como estava
Depois de um tempo, quando a carga diminuiu, nosso Patroni conseguiu se comunicar novamente com os agentes, tudo continuou: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
O mesmo servidor pgdb-2 tornou-se novamente um mestre. Houve uma pequena reviravolta - em um tempo relativamente curto, ele renunciou a si mesmo como mestre e depois assumiu a responsabilidade.Isso pode ser considerado um falso positivo ou o fato de Patroni ter feito tudo certo.Decisão
Decidimos por nós mesmos que o problema é que os servidores Consul estão no mesmo hardware que os bancos de dados. Consequentemente, qualquer carga na CPU e nos discos (solicitação pesada de E / S, arquivos temporários, aspiradores automáticos, migrações, backups etc.) também afeta a interação com o cluster Consul. Decidimos que isso não deveria residir no mesmo equipamento que o banco de dados e alocamos um cluster separado para o Consul.Alternativamente, você pode girar os parâmetros ttl, loop_wait, retry_timeout, tentar devido ao seu aumento para sobreviver às cargas de pico de curto prazo. Mas se a carga for longa, iremos além desses parâmetros e o método não funcionará.Problema 2. Interrupções
O segundo problema é semelhante ao primeiro, pois novamente temos problemas ao interagir com o 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 novamente diz que não pode interagir com o DCS; portanto, o mestre atual deixa de ser mestre e entra no modo de réplica. O velho mestre se torna uma 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!
Aqui Patroni funciona como deveria - inicia pg_rewindpara rebobinar o log de transações, depois se conecta ao novo mestre e já o alcança.O que precedeu o amante dos feylover?
Vamos encontrar a primeira coisa que precedeu o amante dos feyl - os erros que o causaram. Os registros de Patroni são convenientes nesse sentido: ele escreve as mesmas mensagens com um certo intervalo. Você pode rolar rapidamente eles e ver quando os logs foram alterados. Neste ponto, alguns problemas começaram.Em uma situação normal, os logs do Patroni são mais ou menos assim: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
O proprietário do bloqueio é verificado, se ele mudar, podem ocorrer eventos aos quais o Patroni deve responder. Nesse caso, tudo está em ordem conosco.Depois de rolar para o local onde os erros começaram a aparecer, vemos que ocorreu um arquivador automático. Como os erros estavam relacionados à interação com o DCS, também analisamos os registros do Consul - o que aconteceu lá. Comparando aproximadamente o tempo do faylover e o tempo nos registros do Consul, vemos que os vizinhos do cluster Consul começaram a duvidar da existência de outros 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
Se você observar os logs de outros agentes da Consul, também mostra que há um colapso na rede: todos os membros do cluster da Consul duvidam entre si. Este foi o ímpeto para o amante de fadas.Se olharmos para entradas ainda anteriores, veremos que o sistema Consul do agente PostgreSQL tem dificuldades com a comunicação ( 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
Decisão
A resposta mais simples é reparar a rede . É fácil aconselhar, mas as circunstâncias podem ser diferentes, e isso nem sempre é possível. O sistema pode viver em um data center, onde não podemos influenciar o equipamento. Precisa de outras opções.Existem opções de solução sem trabalhar com uma rede:- 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. Perda de Nó
Se você estiver usando o Patroni, estará familiarizado com o comando patronictl list, que mostra o estado atual do cluster:$ 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 |
+-----------------+-------------------------+--------------+--------+---------+-----------+
À primeira vista, essa conclusão pode parecer normal - há um mestre, réplicas, mas não há atraso na replicação. Mas essa imagem é normal exatamente até que saibamos que nesse cluster deve haver 3 nós, e não 2.Por que o failover aconteceu?
Entendemos que ocorreu um arquivador automático e, depois disso, uma réplica desapareceu. Precisamos descobrir por que ela desapareceu e trazê-la de volta.Estudamos os logs novamente para entender por que o arquivador automático ocorreu: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
O mestre pg02 não pôde atualizar a chave mestre ERROR: failed to update leader lock.Então a segunda réplica do db03 se tornou o mestre, tudo está em ordem aqui: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
E o velho mestre?
A pg02, decidindo se tornar uma réplica, começou rebobinando o log de transações. Aqui, precisamos examinar os logs de réplica, que não estão no cluster. Abra os logs do Patroni e veja que, durante o processo de conexão com o cluster, surgiu um problema no estágio 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 conectar-se ao cluster, o nó deve solicitar o log de transações do assistente e capturar o assistente. Nesse caso, não há log de transações ( No such file or directory) e a réplica não pode ser iniciada. Consequentemente, o PostgreSQL para com um erro. Você precisa entender por que não houve log de transações.Vamos ver o que o novo mestre tem no 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
Acontece que, enquanto estava em execução pg_rewind, ocorreu um ponto de verificação e alguns dos logs de transações antigos foram renomeados . Quando o antigo mestre tentou se conectar ao novo mestre e solicitar esses logs, eles já foram renomeados, simplesmente não existiam.De acordo com o registro de data e hora, o tempo entre esses eventos é 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
Mas isso foi suficiente para tornar a réplica incapaz de se conectar e ganhar.Decisão
Inicialmente, usamos slots de replicação. Essa solução nos pareceu boa, embora na primeira fase da operação tenhamos desligado os slots. Pensamos que, se os slots acumularem muitos segmentos wal, o mestre poderá cair. Tendo sofrido por algum tempo sem slots, percebemos que precisávamos deles e os devolvemos.O problema é que, quando o assistente entra no estado de réplica, o assistente exclui os slots e os segmentos wal junto com eles. Para nivelar este problema, aumentamos o parâmetro wal_keep_segments. Por padrão, é igual a 8 segmentos, aumentamos wal_keep_segmentspara 1000 . Alocamos 16 GB wal_keep_segmentse agora, ao alternar, sempre temos 16 GB de logs de transações em todos os nós.Isso também se aplica a tarefas de manutenção de longo prazo. Digamos que precisamos atualizar uma das réplicas (software, SO, outra coisa) e queremos desativá-la. Quando desligamos a réplica, o slot também é excluído. Se você usar um valor pequeno de parâmetro wal_keep_segments, durante uma longa ausência de uma réplica, ele solicitará os logs de transações que podem nem aparecer no assistente - a réplica não poderá se conectar. Portanto, mantemos uma grande oferta de revistas.Problema 4. Perda de Dados
Houve um failover em uma base de produção. Verificamos o cluster: tudo está em ordem, todas as réplicas estão no lugar, não há atraso na replicação e também não há erros nos logs. Mas a equipe do produto relata que não há dados suficientes no banco de dados - eles estão em uma fonte, mas não no banco de dados. Você precisa entender o que aconteceu com eles.Imediatamente percebemos que essa era pg_rewinda jam deles, mas precisamos descobrir o porquê.Quando o failover aconteceu?
Sempre podemos encontrar nos registros quando ocorreu o amante do feylover, quem se tornou o novo mestre, quem era o mestre antes e quando ele queria se tornar uma 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 dos logs, podemos determinar a quantidade de logs de transações perdidos.Foi assim: o antigo assistente foi reiniciado, depois de reiniciado pela execução automática, foi lançado o Patroni, que lançou o PostgreSQL. O PostgreSQL decidiu se tornar um membro do cluster Patroni e lançou um processo pg_rewindque, por sua vez, apagou parte dos logs de transações, baixou novos e se conectou.Patroni funcionou exatamente como pretendido. O cluster se recuperou: havia três nós, depois dos três nós do feylover e saiu. Mas parte dos dados é perdida e você precisa entender qual é a parte.Encontre nos registros do antigo mestre o momento em que aconteceu 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!
Você precisa encontrar a posição no log de transações, que interrompeu o antigo mestre.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
Nesse caso, é a marca 0 / 5BDA8EB8. A segunda marca - 0 / 5AD1BFD8 - é necessária para encontrar a distância pela qual o antigo mestre difere da nova. Usando a função pg_wal_lsn_diff , comparamos essas duas marcas, obtemos 17 MB.Se há uma grande perda de 17 MB de dados, todo mundo decide por si mesmo. Para alguns, isso é insignificante, mas para alguém é muito inaceitável. Cada um por si determina individualmente de acordo com as necessidades do negócio.Decisão
Primeiro de tudo, você precisa decidir se a inicialização automática do Patroni sempre é necessária após a reinicialização do sistema . Na maioria das vezes, devemos ir para o antigo mestre, ver como é diferente do estado atual, talvez inspecionar os segmentos do log de transações. Você precisa entender se esses dados podem ser perdidos ou executar o assistente antigo no modo autônomo para extrair os dados. Somente depois disso, decida o que fazer com os dados e conecte esse nó como uma réplica ao nosso cluster.Além disso, há um parâmetromaximum_lag_on_failover, por padrão, seu valor é 1 Mb. Funciona assim: se a réplica estiver 1 MB atrás do atraso da replicação, essa réplica não participará das eleições. Se de repente ocorrer um failover, Patroni examinará quais réplicas estão atrasadas e aquelas que estão atrasadas em um grande número de logs de transações não podem se tornar um mestre. Esse é um bom recurso de segurança que evita a perda de muitos dados.Mas há um problema: o atraso da replicação é atualizado em um determinado intervalo, o valor ttlpadrão é 30 s. É bem possível que o valor do atraso de replicação para réplicas no DCS seja um, mas, na verdade, é completamente diferente ou não existe nenhum atraso. Esse não é um valor em tempo real; nem sempre reflete a imagem real e não vale a pena vincular uma lógica complexa a ela.O risco de "perdas" sempre permanece:- No pior dos casos:
maximum_lag_on_failover + ttl. - No caso da média:
maximum_lag_on_failover + (loop_wait / 2).
Ao planejar implementar o Patroni e avaliar a quantidade de dados que você pode perder, considere essas fórmulas para representar aproximadamente possíveis perdas.A boa notícia é que pode haver um WAL de processos em segundo plano nas “perdas”. Esses dados podem ser facilmente ignorados e perdidos, não há problema.É assim que os logs são, se configurados maximum_lag_on_failover, ocorreu um amor de feyl e você precisa selecionar um novo assistente: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
A réplica simplesmente vê que ela not healthy enough for leader raceé e se recusa a participar da corrida de liderança. Portanto, ele simplesmente espera que um novo assistente seja selecionado para se conectar a ele. Essa é uma medida adicional contra a perda de dados.Problema 5. Unidades
A equipe do produto escreveu que o aplicativo tem problemas ao trabalhar com o PostgreSQL. Ao mesmo tempo, você não pode entrar no mestre, porque ele não está disponível via SSH, mas o arquivador automático também não ocorre. Em seguida, o host foi reiniciado à força e, assim, lançou o arquivador automático. Embora fosse possível fazer um feiticeiro manual.Após a reinicialização, vamos ver o que aconteceu com o mestre.
Sabíamos com antecedência sobre os problemas com os discos e, monitorando, sabíamos onde cavar.Nos logs do PostgreSQL, vemos o seguinte:[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
...
No rosto, todos os indicadores de problemas com os discos: confirma que duram um segundo, o vácuo automático executa arquivos muito longos e estranhos e temporários no disco.Examinamos o sistema dmesg - o log de mensagens do kernel e vimos um problema com um dos 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
O subsistema de disco no servidor era um RAID de software de 8 discos, mas um estava ausente. A linha sda3[0] sdc3[2] sdd3[3] sdb3[1] sdh3[7] sdf3[5] sdg3[6]está faltando sde[4]. Relativamente falando, um disco caiu, isso causou problemas no disco e o aplicativo teve problemas ao trabalhar com o cluster do PostgreSQL.Decisão
Nesse caso, o Patroni não poderia ajudar, porque o Patroni não tem tarefa para monitorar o status do servidor e dos discos. Durante os problemas, Patroni continuou a interagir com o cluster DCS e não viu nenhuma dificuldade. Para tais situações, é necessário monitoramento externo.Problema 6. Simulador de Cluster
Esse é um dos problemas mais estranhos. Estudei por muito tempo, reli muitos logs e chamei de “simulador de cluster”.O problema era que o velho mestre não podia se tornar uma sugestão normal. Patroni o executou, mostrou que esse nó está presente como uma réplica, mas, ao mesmo tempo, não era uma réplica normal, agora você verá o porquê.Tudo começou, como no caso anterior, com 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
Houve conexões interrompidas: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
Existiam longas expectativas de resposta e bloqueio de gravidade variável: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.
Em geral, há problemas óbvios com os discos, incluindo arquivos temporários novamente.Mas o mais misterioso para mim - ele apareceu 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
O PostgreSQL possui três modos de desligamento:- Gracioso quando esperamos que todos os clientes se desconectem por conta própria.
- Rápido, quando dizemos aos clientes para desconectar, porque vamos desligar.
- Imediato, que não informa aos clientes que é necessário desconectar, mas simplesmente o desliga e envia uma mensagem RST a todos os clientes (sinal TCP de que a conexão foi interrompida).
Os processos em segundo plano do PostgreSQL não enviam sinais de solicitação de desligamento imediato, mas apenas respondem a eles. Esta é uma reinicialização de emergência, e quem a enviou não é clara. Se fosse kill -9, eu o veria nos logs, mas não estava lá.Compreendendo ainda mais, vi que Patroni não gravou no log por um bom tempo - simplesmente não houve mensagens por 54 segundos. Durante esse período, uma das réplicas fez "promoção" e ocorreu um arquivador 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 voltou a funcionar perfeitamente aqui, o antigo mestre não estava disponível, então a eleição de um novo mestre começou.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
O pgsql01 se tornou o novo líder e houve apenas problemas com a segunda réplica. Ela honestamente tentou 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
Ela tentou alterar o recovery.conf, reiniciar o PostgreSQL, conectar-se ao novo assistente. A cada 10 segundos, há mensagens que ela está tentando, mas não pode.Enquanto isso, o mesmo sinal de desligamento imediato voou para o velho mestre. O assistente iniciou uma reinicialização de emergência, a recuperação também para. A réplica não pode se conectar ao mestre porque está no modo de desligamento.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
Em algum momento, a réplica funcionou, mas a replicação não foi iniciada.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
Eu tenho uma única hipótese: em recovery.conf era o endereço do antigo mestre. Quando um novo mestre já apareceu, a segunda réplica tentou se conectar ao antigo mestre. Quando Patroni iniciou na segunda réplica, o nó iniciou, mas não pôde se conectar via replicação. Um atraso de replicação foi formado, mais ou menos assim:+-----------------+----------+--------------+--------+---------+-----------+
| 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 |
+-----------------+----------+--------------+--------+---------+-----------+
Ou seja, todos os três nós estavam no lugar, mas o segundo nó estava atrás. Não foi possível iniciar a replicação porque os logs de transações eram diferentes. Os logs de transações oferecidos pelo assistente, indicados em recovery.conf, simplesmente não se encaixavam no nó atual. O PostgreSQL relatou um erro a cada 5 segundos14: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
Aqui cometi um erro e não testei minha hipótese de que estamos nos conectando com o mestre errado. Acabei de reiniciar o Patroni na réplica. Honestamente, eu já terminei e pensei que teria que refazê-lo, mas ainda decidi tentar reiniciá-lo.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
A recuperação foi iniciada e, mesmo o banco de dados aberto, estava pronto para aceitar a conexão, a replicação iniciada: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
Mas um minuto depois, ela caiu com um erro terminating walreceiver process due to administrator command- a réplica dizia que os logs de transações não eram adequados para ela.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
E não reiniciei o PostgreSQL, mas foi o Patroni que foi reiniciado na esperança de lançar magicamente o banco de dados. A replicação foi iniciada novamente, mas o banco de dados foi aberto no mesmo local: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
As marcas no log de transações eram diferentes, eram diferentes da tentativa de ativação anterior - a posição do log de transações 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
A replicação parou novamente e a mensagem de erro foi diferente e novamente não muito informativa: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 o experimento, reiniciado novamente, a base foi aberta no mesmo local: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
Então surgiu a idéia: se eu reiniciar o PostgreSQL, neste momento, no assistente atual, farei um ponto de verificação para mover o ponto do log de transações um pouco à frente e a recuperação iniciada em outro momento.Lançou Patroni, fez alguns pontos de verificação no mestre, alguns pontos de reinicialização na réplica quando ela foi aberta: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
Funcionou - a replicação começou em um lugar diferente e não quebrou mais. Mas, para mim, esse é um dos problemas mais misteriosos sobre os quais ainda estou atormentando. Especialmente aquele pedido estranho de desligamento imediato.A partir disso, podemos concluir: Patroni pode funcionar como planejado e sem erros, mas isso não é uma garantia absoluta de que tudo está realmente em ordem. Após o amor de fey, você sempre precisa verificar se tudo está bem com o cluster: o número certo de réplicas, sem atraso na replicação.Sumário
Com base nesses e em muitos outros problemas semelhantes, formulei recomendações gerais que recomendamos que você tenha em mente ao operar o Patroni.- Ao usar o Patroni, você deve ter monitoramento. Você sempre precisa saber quando ocorreu um arquivo automático, porque se não souber que possui um arquivo automático, não controla o cluster.
- Após cada amante de fey sempre verifique um cluster. Você deve se certificar de que: réplicas são sempre o número atual; sem atraso de replicação; não há erros nos logs relacionados à replicação de streaming, com o Patroni, com o sistema DCS.
Patroni é uma ferramenta muito boa, mas não importa como você diga que não é uma bala de prata. A automação pode funcionar com êxito, mas, ao mesmo tempo, os objetos de automação podem estar em um estado de meio trabalho. De qualquer forma, você precisa ter uma idéia de como o PostgreSQL e a replicação funcionam, como o Patroni gerencia o PostgreSQL e como a interação entre os nós é garantida. Isso é necessário para poder reparar os problemas que surgem com as mãos.Etapas de diagnóstico
Aconteceu que trabalhamos com clientes diferentes, na maioria das vezes eles não têm uma pilha ELK, e você precisa classificar os logs abrindo 2 guias e 6 consoles: em uma guia Patroni para cada nó, no outro - logs Consul ou PostgreSQL. Diagnosticar tudo isso é difícil.Eu desenvolvi a seguinte abordagem. Eu sempre assisto quando ocorre um failover. Para mim, é uma espécie de divisor de águas. Eu olho para o que aconteceu antes, durante e depois do amante dos feys. O failover possui dois registros de data e hora - início e fim. Nos logs, procuro o que precedeu o amante dos feiticeiros, ou seja, estou procurando por razões. Isso dá uma compreensão da imagem do que aconteceu e do que pode ser feito no futuro, para que o amante dos fey não ocorra nas mesmas circunstâncias.Para isso, eu olho:- Primeiro de tudo, os logs do Patroni.
- PostgreSQL DCS , Patroni.
- — , .
Existem muitos outros produtos para o arquivador automático: stolon, repmgr, pg_auto_failover, PAF. Eu tentei todas as 4 ferramentas e, na minha opinião, o Patroni é o melhor que existe no mercado hoje.Eu recomendo o Patroni? Definitivamente, sim, porque gosto de Patroni, acho que aprendi a cozinhar.Se você estiver interessado em analisar outros problemas com o Patroni, além dos descritos no artigo, sempre poderá acessar a página https://github.com/zalando/patroni/issues . Existem muitas histórias diferentes. Apesar do fato de que metade deles é de usuários analfabetos que fazem perguntas estúpidas sem se preocupar com uma pesquisa simples, problemas interessantes também são discutidos e, como resultado de discussões, tarefas para corrigir bugs são abertas, se necessário.Agradecemos a Zalando pelo desenvolvimento deste projeto, bem como às duas pessoas que começaram a trabalhar neste produto: Alexander Kukushkin e Alexey Klyukin. Muito obrigado a todos os colaboradores da Patroni.Após esse relatório, gravamos uma curta entrevista na qual Alex tentou encaixar seu relatório em um conselho e dissemos por que participar e falar em conferências. Pegue em armas e venha conferir a abordagem no Saint HighLoad ++.HighLoad++ 6-7 . , . , ( , ). - , , , .
Saint HighLoad++! , , PostgreSQL: , PostgreSQL JSON ; PostgreSQL 13, ; .