Corrupção de dados: de onde vem? do que se alimenta?

Apresentei esta talk no pgconf.br 2022:
https://www.pgconf.com.br/2022/grade/#event-62

Transcript

1. Corrupçã d dad Sebastian Webber de onde vem? do que se alimenta?
2. Oi Eu sou o Sebastian. Gosto de cozinhar. Gosto de ficar com minha família. Sou Database Engineer na @ongresinc Trabalho no https://stackgres.io
3. To be lazy you need to work hard.
4. O termo Corrupção de dados se refere a erros em dados computacionais que são introduzidos durante a gravação, leitura, armazenamento, transmissão, ou processamento de dados. Em geral, arquivos contendo dados apresentarão resultados inesperados quando seus conteúdos corrompidos sejam acessados pelo sistema ou programa relacionado. Na wikipédia:
5. Plano pra hoje • Como o banco salva os dados? • O que pode dar errado? • Devo me desesperar? • Deu ruim! O que fazer?
6. Como o banco salva os dados?
7. 192.168.0.50:5432 Databases Estrutura lógica de um cluster PostgreSQL sistema_db postgres template0 template1 usuários, tablespaces, etc... pg_toast public pg_catalog information _schema cliente vw_nasc_2000 f_add_cliente_fake(int) cliente_pk cliente_dt_n pg_toast.pg_toast_xxxxx
8. postgres=# show data_directory; data_directory -------------------------- /var/lib/postgresql/data (1 row) postgres=# select oid, datname from pg_database order by oid asc; oid | datname -------+------------ 1 | template1 13756 | template0 13757 | postgres 16384 | sistema_db (4 rows) Estrutura Física de um cluster PostgreSQL
9. root@a0257bff5623:/# ls /var/lib/postgresql/data/base -lh total 48K drwx------ 2 postgres postgres 8.0K Aug 20 04:00 1 drwx------ 2 postgres postgres 8.0K Aug 20 04:00 13756 drwx------ 2 postgres postgres 8.0K Aug 20 04:00 13757 drwx------ 2 postgres postgres 8.0K Aug 20 04:01 16384 root@a0257bff5623:/# ls /var/lib/postgresql/data/pg_tblspc/ -lh total 0 root@a0257bff5623:/# ls /var/lib/postgresql/data/pg_wal/ -lh total 16M -rw------- 1 postgres postgres 16M Aug 20 04:01 000000010000000000000001 drwx------ 2 postgres postgres 6 Aug 20 04:00 archive_status Estrutura Física de um cluster PostgreSQL
10. root@a0257bff5623:/# ls /var/lib/postgresql/data/global -lh total 564K -rw------- 1 postgres postgres 8.0K Aug 20 04:00 1213 -rw------- 1 postgres postgres 24K Aug 20 04:00 1213_fsm -rw------- 1 postgres postgres 8.0K Aug 20 04:00 1213_vm -rw------- 1 postgres postgres 8.0K Aug 20 04:00 1214 -rw------- 1 postgres postgres 24K Aug 20 04:00 1214_fsm -rw------- 1 postgres postgres 8.0K Aug 20 04:00 1214_vm -rw------- 1 postgres postgres 16K Aug 20 04:00 1232 -rw------- 1 postgres postgres 16K Aug 20 04:00 1233 … -rw------- 1 postgres postgres 8.0K Aug 20 04:06 pg_control -rw------- 1 postgres postgres 512 Aug 20 04:00 pg_filenode.map -rw------- 1 postgres postgres 24K Aug 20 04:00 pg_internal.init Estrutura Física de um cluster PostgreSQL objetos usados no cluster, como pg_database e pg_control.
11. sistema_db=# select relid, schemaname, relname, pg_relation_filepath(relid) from pg_stat_user_tables; relid | schemaname | relname | pg_relation_filepath -------+------------+---------+---------------------- 16386 | public | cliente | base/16384/16386 (1 row) sistema_db=# select relid, indexrelid, schemaname, indexrelname, pg_relation_filepath(indexrelid) from pg_stat_user_indexes; relid | indexrelid | schemaname | indexrelname | pg_relation_filepath -------+------------+------------+--------------+---------------------- 16386 | 16392 | public | cliente_pkey | base/16384/16392 16386 | 16394 | public | cliente_dt_n | base/16384/16394 (2 rows) Estrutura Física de um cluster PostgreSQL
12. ## tabela cliente root@a0257bff5623:/var/lib/postgresql/data# ls -lh base/16384/16386* -rw------- 1 postgres postgres 1.0G Aug 20 05:02 base/16384/16386 -rw------- 1 postgres postgres 1.0G Aug 20 05:02 base/16384/16386.1 -rw------- 1 postgres postgres 843M Aug 20 05:14 base/16384/16386.2 -rw------- 1 postgres postgres 744K Aug 20 05:14 base/16384/16386_fsm -rw------- 1 postgres postgres 96K Aug 20 05:14 base/16384/16386_vm ## indice cliente_pkey root@a0257bff5623:/var/lib/postgresql/data# ls -lh base/16384/16392* -rw------- 1 postgres postgres 32K Aug 20 04:36 base/16384/16392 ## indice cliente_dt_n root@a0257bff5623:/var/lib/postgresql/data# ls -lh base/16384/16394* -rw------- 1 postgres postgres 40K Aug 20 04:36 base/16384/16394 Estrutura Física de um cluster PostgreSQL
13. • Funções são armazenadas na tabela pg_catalog.pg_proc • Definição das Views são salvos num lugar misterioso que a pg_catalog.pg_get_viewdef(oid) sabe na tabela pg_catalog.pg_rewrite Estrutura Física de um cluster PostgreSQL
14. O banco usa tabelas para armazenar metadados dos objetos
15. O que pode dar errado?
16. Hardware pode falhar Disco, RAM e até a rede podem falhar. Só precisa inverter 1 bit na hora de salvar os dados. 1 bit. 😱
17. 1. DML 2. disco* (wal) e RAM (shared_buffers) 3. FS grava no disco 4. Controladora grava fisicamente no disco *Dirty pages no cache do SO
18. fsync é ❤ https://blog.httrack.com/blog/2013/11/15/everything-you-always-wanted-to-know-about-fsync/ 1. user: "grava grava grava" 2. banco: atualiza shared_buffers e grava wal 3. user: Commit 4. banco: hey kernel: fsync() a. kernel: borá lá FS quero ver isso salvo! b. Filesystem: deixa pra mim. 5. banco: tudo certo user!
19. https://stackoverflow.com/questions/42434872/writing-programs-to-cope-with-i-o-errors-causing-lost-writes-on-linux https://wiki.postgresql.org/wiki/Fsync_Errors
20. [vagrant@db-node-1 ~]$ cat /etc/redhat-release CentOS Linux release 7.8.2003 (Core) [vagrant@db-node-1 ~]$ rpm -qa | grep kernel kernel-tools-libs-3.10.0-1127.el7.x86_64 kernel-tools-3.10.0-1127.el7.x86_64 kernel-3.10.0-1127.el7.x86_64 melhorado no kernel 4.13
21. Alguém bem intencionado pode cometer um erro. data_sync_retry: on em kernel < 4.13 fsync: off
22. Um bug no banco pode causar corrupção de dados https://www.migops.com/blog/important-postgresql-14-update-to-avoid-silent-corruption-of-indexes/
23. devo me desesperar?
24. 1. respira fundo Agora é o momento de ter paciência e ir com calma. vai ser uma longa jornada. É importante pensar e agir com segurança.
25. 2. isole o problema Qual é o erro? Como faço para forçá-lo? quais partes do sistema ele afeta?
26. 2. isole o problema • Erros do log como: ◦ 2022-08-22 05:07:23.637 UTC [39] ERROR: index "pg_toast_24722_index" contains unexpected zero page at block 0 2022-08-22 05:07:23.637 UTC [39] HINT: Please REINDEX it.limit 10; ◦ 2022-08-22 04:57:16.949 UTC [45] ERROR: unexpected chunk number 8 (expected 0) for toast value 24669 in pg_toast_24661 ◦ Qualquer entrada com PANIC • Toda vez que eu rodo query X, da um erro • Rodei a query Y e fica pendurada e parece não ser causado por um lock
27. 3. restaure o backup A melhor forma de sair dessa é voltando o backup! se ele funciona, planeje o restore em outro host (se possível) e só investigue a causa do problema depois do restore.
28. 4. centralize as ações Se tem mais gente acompanhando, pede ajuda pra ir documentando e notificando a todos. A partir de agora apenas UMA pessoa trabalha no servidor de cada vez.
29. deu ruim! o que fazer?
30. faça uma cópia dos dados ANTES DE QUALQUER coisa. sempre trabalhe na CÓPIA.
31. # dd if=/dev/urandom of=base/16384/16620 bs=8192 count=1 skip=2 conv=notrunc sistema_db=# select id, nome, dt_nasc from cliente; ERROR: invalid page in block 0 of relation base/16384/16620 sistema_db=# select oid,relname,relkind, relfilenode from pg_class where relfilenode = 16620; oid | relname | relkind | relfilenode -------+--------------+---------+------------- 16392 | cliente_pkey | i | 16620 (1 row) sistema_db=# reindex index concurrently cliente_pkey; REINDEX sistema_db=# select id, nome, dt_nasc from cliente; id | nome | dt_nasc ----+-------------+------------------------------ 1 | cliente #1 | 2020-09-24 03:17:35.06859+00 … 10 | cliente #10 | 1894-07-26 03:17:35.06859+00 (10 rows) Reparando um índice com problema Dificuldade: 😎 (1/5)
32. # dd if=/dev/urandom of=base/16384/2662 bs=8192 count=1 skip=2 conv=notrunc 2022-08-25 04:39:57.599 UTC [26910] FATAL: invalid page in block 0 of relation base/16384/2662 -bash-4.2$ /usr/pgsql-14/bin/postgres --single sistema_db -D /var/lib/pgsql/14/data/ 2022-08-25 04:56:37.946 UTC [28310] FATAL: invalid page in block 0 of relation base/16384/2662 -bash-4.2$ /usr/pgsql-14/bin/postgres --single sistema_db -P -D /var/lib/pgsql/14/data/ PostgreSQL stand-alone backend 14.5 backend> REINDEX SYSTEM sistema_db; backend> Reparando um índice do sistema com problema Dificuldade: 😅 (2/5)
33. Reparando um índice do sistema com problema Dificuldade: 😅 (2/5)
34. -bash-4.2$ /usr/pgsql-14/bin/postgres --help postgres is the PostgreSQL server. Usage: postgres [OPTION]... # … Developer options: -P disable system indexes -T send SIGSTOP to all backend processes if one dies Options for single-user mode: --single selects single-user mode (must be first argument) DBNAME database name (defaults to user name) -d 0-5 override debugging level -j do not use newline as interactive query delimiter Reparando um índice do sistema com problema Dificuldade: 😅 (2/5)
35. Daqui pra frente vamos começar a perder alguma coisa. 🥺
36. perdendo os logs de transação ## rm pg_wal/00000001000000000000003* 2022-08-25 06:46:24.426 UTC [3242] LOG: invalid primary checkpoint record 2022-08-25 06:46:24.429 UTC [3242] PANIC: could not locate a valid checkpoint record 2022-08-25 06:46:24.431 UTC [3234] LOG: startup process (PID 3242) was terminated by signal 6: Aborted 2022-08-25 06:46:24.431 UTC [3234] LOG: aborting startup due to startup process failure 2022-08-25 06:46:24.435 UTC [3234] LOG: database system is shut down -bash-4.2$ /usr/pgsql-14/bin/pg_resetwal -D /var/lib/pgsql/14/data/ Write-ahead log reset 2022-08-25 22:52:24.155 UTC [2924] LOG: database system was shut down at 2022-08-25 22:52:04 UTC 2022-08-25 22:52:24.166 UTC [2923] LOG: database system is ready to accept connections Dificuldade: 😱 (3/5)
37. perdendo os logs de transação Dificuldade: 😱 (3/5) * Outros processos também gravam dados no disco, como o checkpointer, o próprio backend, etc.
38. perdendo os logs de transação Dificuldade: 😱 (3/5) * Outros processos também gravam dados no disco, como o checkpointer, o próprio backend, etc.
39. # rm pg_xact/0000 2022-08-26 00:18:36.822 UTC [28754] FATAL: could not access status of transaction 771 2022-08-26 00:18:36.822 UTC [28754] DETAIL: Could not open file "pg_xact/0000": No such file or directory. 2022-08-26 00:18:36.824 UTC [28753] LOG: startup process (PID 28754) exited with exit code 1 2022-08-26 00:18:36.824 UTC [28753] LOG: aborting startup due to startup process failure dd if=/dev/zero of=pg_xact/0000 bs=8k count=1 conv=notrunc 2022-08-26 00:23:23.708 UTC [28776] LOG: database system was shut down at 2022-08-26 00:18:29 UTC 2022-08-26 00:23:23.713 UTC [28775] LOG: database system is ready to accept connections sistema_db=# select * from vw_nasc_2000 ; ERROR: pg_attribute catalog is missing 3 attribute(s) for relation OID 16632 perdendo os dados das transações Dificuldade: 😱 (3/5)
40. perdendo os dados das transações Dificuldade: 😱 (3/5) https://www.interdb.jp/pg/pgsql05.html#_5.4.
41. ## dd if=/dev/zero of=base/16384/16640 bs=1024 seek=10 count=1 conv=notrunc sistema_db=# select id, nome, dt_nasc, pg_size_pretty(length(bio)::numeric) from cliente; ERROR: unexpected chunk number 3 (expected 2) for toast value 16643 in pg_toast_16386 sistema_db=# select * from check_cliente(); NOTICE: failed to work with the toast of id: 1 - (4294967295,0) check_cliente --------------- t (1 row) sistema_db=# vacuum full cliente; ERROR: unexpected chunk number 3 (expected 2) for toast value 16643 in pg_toast_16386 lidando com perda de dados Dificuldade: 🤯 (4/5)
42. ## dd if=/dev/zero of=base/16384/16640 bs=1024 seek=10 count=1 conv=notrunc sistema_db=# update cliente set bio=null where id=1; UPDATE 1 sistema_db=# select * from check_cliente(); check_cliente --------------- f (1 row) sistema_db=# vacuum full cliente; VACUUM lidando com perda de dados Dificuldade: 🤯 (4/5)
43. CREATE OR REPLACE FUNCTION check_cliente() RETURNS bool LANGUAGE plpgsql AS $$ DECLARE v_row record; found_error bool = false; BEGIN FOR v_row IN SELECT * FROM cliente order by 1 asc LOOP BEGIN perform length(v_row.bio); -- usar o toast causa o erro... EXCEPTION WHEN internal_error OR data_corrupted OR index_corrupted THEN RAISE NOTICE 'failed to work with the toast of id: % - %', v_row.id, v_row.ctid; found_error = true; END; END LOOP; RETURN found_error; END $$; lidando com perda de dados Dificuldade: 🤯 (4/5)
44. Agora fica hardcore!
45. ### pg_catalog.pg_type heap: base/16384/1247 # dd if=/dev/urandom of=base/16384/1247 bs=1024 seek=15 count=5 conv=notrunc sistema_db=# \d+ cliente; ERROR: cache lookup failed for type 1042 sistema_db=# select * from vw_nasc_2000; ERROR: cache lookup failed for function 296483811 sistema_db=# select ctid, id, nome, dt_nasc, pg_size_pretty(length(bio)::numeric) from cliente where id > 1; ERROR: cache lookup failed for function 296483811 Reparando o catálogo via engenharia reversa Dificuldade: 😵 (5/5)
46. ainda tem mais?
47. ainda podemos… Ter de recuperar o filesystem… 🔨 Ter de recuperar o disco com empresa terceira… 🤑 Ter de começar tudo de novo! 😭
48. Corrigi tudo, e agora? • pg_dump da base e pg_restore em outro server se possível, se não for, utilize initdb e crie um novo cluster. restore nele. • Aproveite para documentar suas rotinas de backup - já que estamos aqui sofrendo por causa delas • Salve os logs, comandos, tudo que for evidência e faça uma análise de tudo o que aconteceu. • Simule seus backups e tente criar exercícios mensais para simular um restore no ambiente (similar ao) de de produção. • Lembre da máxima: Backup bom é o que restaura. Não confie no seu backup sem ter provas de que ele funciona!
49. Trust, but verify.
50. Obrigado! @_sebastianwebber /sebawebber @sebawebber