Get best of the week

Hancurkan cerita dengan Patroni, atau Cara menjatuhkan kluster PostgreSQL

PostgreSQL tidak memiliki Ketersediaan Tinggi di luar kotak. Untuk mencapai HA, Anda perlu memasukkan sesuatu, mengatur - berusaha. Ada beberapa alat yang dapat membantu meningkatkan ketersediaan PostgreSQL, dan salah satunya adalah Patroni.

Pada pandangan pertama, menempatkan Patroni di lingkungan pengujian, Anda dapat melihat apa alat yang hebat itu dan bagaimana itu dengan mudah menangani upaya kami untuk memecah cluster. Namun dalam praktiknya, dalam lingkungan produksi, tidak semuanya selalu terjadi dengan begitu indah dan elegan. Data Egret mulai menggunakan Patroni pada akhir 2018 dan memperoleh beberapa pengalaman: cara mendiagnosisnya, mengonfigurasinya, dan kapan tidak mengandalkan pengarsipan otomatis sama sekali.

Di HighLoad ++, Alexei Lesovsky menjelaskan secara rinci, menggunakan contoh dan analisis log, masalah khas yang muncul saat bekerja dengan Patroni, dan praktik terbaik untuk mengatasinya.


Artikel tidak akan: Instruksi pemasangan Patroni dan contoh konfigurasi; masalah di luar Patroni dan PostgreSQL; cerita berdasarkan pengalaman orang lain, tetapi hanya masalah-masalah yang dipecahkan Egret Data untuk diri mereka sendiri.

Tentang pembicara: Alexey Lesovsky (lesovsky) dimulai sebagai administrator sistem (administrator sistem Linux), bekerja dalam pengembangan web (administrator database PostgreSQL). Sejak 2014 dia telah bekerja di Data Egret. Data Egret bergerak dalam bidang konsultasi di bidang PostgreSQL, membantu banyak, banyak perusahaan untuk menggunakan PostgreSQL dengan benar dan, tentu saja, telah memperoleh pengalaman luas dalam mengoperasikan basis data.
Laporan yang menjadi dasar artikel ini disebut "Patroni Failure Stories atau Cara menabrak cluster PostgreSQL Anda", di sini adalah tautan ke presentasi .

Sebelum kamu memulai


Biarkan saya mengingatkan Anda apa itu Patroni, apa yang dimaksudkan dan apa yang bisa dilakukan.

Patroni adalah templat untuk membuat HA di luar kotak. Jadi itu tertulis dalam dokumentasi dan dari sudut pandang saya - ini adalah klarifikasi yang sangat tepat. Artinya, Patroni bukan peluru perak yang dia atur dan itu akan menyelesaikan semua masalah. Diperlukan upaya agar mulai bekerja dan membawa manfaat.

Patroni - layanan agen. Itu diinstal pada setiap server dengan database dan merupakan semacam init-sistem untuk PostgreSQL: itu dimulai, berhenti, restart, mengubah konfigurasi dan topologi cluster.

Patroni menyimpan "negara cluster" di DCS.Untuk menyimpan status cluster, tampilan saat ini, Anda perlu penyimpanan. Patroni menyimpan status dalam sistem eksternal - repositori konfigurasi terdistribusi. Ini bisa menjadi salah satu opsi: Etcd, Konsul, ZooKeeper atau Etcd Kubernetes.

Patroni AutoFile diaktifkan secara default. Anda mendapatkan filer otomatis dari kotak, segera setelah menginstal Patroni.

Plus ada banyak hal lain, seperti: konfigurasi servis, membuat replika baru, membuat cadangan, dll. Namun kali ini akan tetap berada di luar ruang lingkup laporan.
Tujuan utama Patroni adalah untuk menyediakan pengarsipan otomatis yang andal.
Patroni tidak harus memantau peralatan, mengirim pemberitahuan, melakukan hal-hal rumit tentang potensi pencegahan kecelakaan, dll. Diperlukan bahwa cluster tetap operasional dan aplikasi dapat terus bekerja dengan database, terlepas dari perubahan apa pun dalam topologi cluster.

Tetapi ketika kita mulai menggunakan Patroni dengan PostgreSQL, sistem kita menjadi sedikit lebih rumit. Sekarang, di samping database itu sendiri, ketika master atau replika gagal, Patroni sendiri, penyimpanan negara-negara cluster, atau jaringan mungkin rusak. Pertimbangkan semua pilihan karena mereka menjadi lebih rumit dalam hal betapa sulitnya memahami penyebabnya.

Masalah 1. DBMS dan DCS pada cluster yang sama


Pertimbangkan kasus paling sederhana: kami mengambil cluster basis data dan menggunakan DCS pada cluster yang sama. Kesalahan umum ini tidak hanya terkait dengan kesalahan penggunaan PostgreSQL dan Patroni. Ini adalah kesalahan dalam konstruksi umum arsitektur - menggabungkan banyak komponen yang berbeda di satu tempat.

Jadi, ada kegagalan. Kami mulai mengerti apa yang terjadi. Di sini kita tertarik ketika feylover terjadi, yaitu titik waktu ketika negara cluster berubah.

Kapan kegagalan itu terjadi?


Faylover tidak selalu terjadi secara instan, tetapi dapat menghabiskan waktu. Oleh karena itu, ia memiliki waktu mulai dan waktu akhir. Semua acara dibagi menjadi "sebelum", "selama" dan "setelah" feylover.

Pertama-tama, ketika feylover terjadi, kami mencari alasannya.

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

Di atas adalah log Patroni standar, di mana ia melaporkan bahwa peran server telah berubah dan peran wizard telah berpindah dari yang lain ke simpul ini.

Mengapa kegagalan itu terjadi?


Selanjutnya, Anda perlu memahami peristiwa apa yang membuat peran master beralih dari satu node ke node lain, apa yang terjadi pada master lama.

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.

Dalam hal ini, semuanya sederhana: Error communicating with DCS- kesalahan berinteraksi dengan sistem penyimpanan konfigurasi. Sang master menyadari bahwa dia tidak bisa bekerja dengan DCS, dan mengatakan bahwa dia tidak bisa lagi menjadi seorang master dan mengundurkan diri. demoted selfberbicara tentang ini.

Apa yang mendahului feylover?


Jika Anda melihat peristiwa yang mendahului feylover, Anda dapat melihat alasan yang menjadi masalah bagi penyihir untuk melanjutkan:

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.

Log patroni menunjukkan banyak kesalahan batas waktu yang berbeda. Agen Patroni tidak dapat bekerja dengan DCS (dalam hal ini, itu adalah Konsul, port = 8500). Patroni dan database berjalan pada host yang sama, dan server Consul berjalan pada host yang sama. Setelah membuat beban di server, kami juga menciptakan masalah untuk server Konsul, karena itu mereka tidak dapat berkomunikasi secara normal.

Semuanya kembali seperti semula


Setelah beberapa saat, ketika beban mereda, Patroni kami dapat berkomunikasi lagi dengan para agen, semuanya kembali:

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

Server pgdb-2 yang sama kembali menjadi master. Ada "flip" kecil - dalam waktu yang relatif singkat ia mengundurkan diri dari dirinya sendiri sebagai seorang master, kemudian kembali mengambilnya sendiri.

Ini bisa dianggap positif palsu, atau fakta bahwa Patroni melakukan semuanya dengan benar.

Keputusan


Kami memutuskan untuk diri kami sendiri bahwa masalahnya adalah bahwa server Konsul berada pada perangkat keras yang sama dengan database. Karenanya, setiap beban pada CPU dan disk (permintaan IO berat, file sementara, auto-vacuums, migrasi, cadangan, dll.) Juga mempengaruhi interaksi dengan cluster Konsul. Kami memutuskan bahwa ini tidak boleh hidup pada peralatan yang sama dengan database, dan mengalokasikan cluster terpisah untuk Konsul.

Atau, Anda dapat memutar parameter ttl, loop_wait, retry_timeout, coba karena peningkatan mereka untuk bertahan hidup beban puncak jangka pendek. Tetapi jika bebannya panjang, kita akan melampaui parameter ini, dan metode ini tidak akan berfungsi.

Masalah 2. Pemadaman


Masalah kedua mirip dengan yang pertama di mana kita lagi memiliki masalah berinteraksi dengan sistem 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 lagi mengatakan bahwa itu tidak dapat berinteraksi dengan DCS, sehingga master saat ini berhenti menjadi master dan memasuki mode replika. Tuan tua menjadi replika:

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!

Di sini Patroni bekerja sebagaimana mestinya - diluncurkan pg_rewinduntuk memundurkan log transaksi, kemudian terhubung ke master baru dan sudah mengejar ketinggalan dengan master baru.

Apa yang mendahului feylover?


Mari kita temukan hal pertama yang mendahului feylover - kesalahan yang menyebabkannya. Log Patroni nyaman dalam hal ini: ia menulis pesan yang sama dengan interval tertentu. Anda dapat dengan cepat menggulirnya dan melihat kapan log telah berubah. Pada titik ini, beberapa masalah dimulai.

Dalam situasi normal, log Patroni terlihat seperti ini:

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

Pemilik kunci diperiksa, jika itu berubah, peristiwa dapat terjadi yang Patroni harus menanggapi. Dalam hal ini, semuanya beres dengan kami.

Setelah menggulir ke tempat di mana kesalahan mulai muncul, kita melihat bahwa pengarsipan otomatis terjadi. Karena kesalahan terkait dengan interaksi dengan DCS, kami juga melihat log Konsul - apa yang terjadi di sana. Kira-kira membandingkan waktu faylover dan waktu di log Konsul, kita melihat bahwa tetangga di cluster Konsul mulai meragukan keberadaan peserta lain:

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

Jika Anda melihat log agen Konsul lain, itu juga menunjukkan bahwa ada keruntuhan jaringan: semua anggota cluster Konsul saling meragukan. Ini adalah dorongan untuk feylover.

Jika kita melihat entri yang lebih awal, kita akan melihat bahwa sistem Konsul untuk agen PostgreSQL memiliki kesulitan dengan komunikasi ( 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


Keputusan


Jawaban paling sederhana adalah memperbaiki jaringan . Mudah untuk dinasihati, tetapi keadaannya bisa berbeda, dan ini tidak selalu memungkinkan. Sistem dapat hidup di pusat data, di mana kita tidak dapat memengaruhi peralatan. Perlu opsi lain.

Ada opsi solusi tanpa bekerja dengan jaringan:

  • 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 .


Masalah 3. Kehilangan simpul


Jika Anda menggunakan Patroni, maka Anda terbiasa dengan perintah daftar patronictl, yang menunjukkan keadaan cluster saat ini:

$ 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    |
+-----------------+-------------------------+--------------+--------+---------+-----------+


Sekilas, kesimpulan seperti itu mungkin tampak normal - ada master, replika, tetapi tidak ada lag replikasi. Tapi gambar ini normal sampai kita tahu bahwa di cluster ini harus ada 3 node, dan bukan 2.

Mengapa kegagalan itu terjadi?


Kami memahami bahwa pengarsipan otomatis terjadi dan setelah itu satu replika menghilang. Kita perlu mencari tahu mengapa dia menghilang, dan membawanya kembali.

Kami mempelajari kembali log untuk memahami mengapa filer otomatis terjadi:

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

Master pg02 tidak dapat memperbarui kunci master ERROR: failed to update leader lock.

Kemudian replika db03 kedua menjadi master, semuanya tertata di sini:

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

Bagaimana dengan tuan tua?


pg02, memutuskan untuk menjadi replika, mulai dengan memutar ulang log transaksi. Di sini kita perlu melihat log replika, yang tidak ada di cluster. Buka log Patroni dan lihat bahwa selama proses menghubungkan ke cluster, muncul masalah di panggung 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.

Untuk terhubung ke gugus, simpul harus meminta log transaksi dari penyihir dan menangkap penyihir darinya. Dalam hal ini, tidak ada log transaksi ( No such file or directory), dan replika tidak dapat dimulai. Dengan demikian, PostgreSQL berhenti dengan kesalahan. Anda perlu memahami mengapa tidak ada log transaksi.

Mari kita lihat apa yang dimiliki master baru di 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

Ternyata ketika sedang berjalan pg_rewind, sebuah pos pemeriksaan terjadi, dan beberapa log transaksi lama diganti namanya . Ketika master lama mencoba untuk terhubung ke master baru dan meminta log ini, mereka sudah berganti nama, mereka tidak ada.

Menurut stempel waktu, waktu antara peristiwa ini adalah 150 ms.

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

Tapi ini sudah cukup untuk membuat replika tidak dapat terhubung dan menghasilkan.

Keputusan


Awalnya, kami menggunakan slot replikasi. Solusi ini tampak baik bagi kami, meskipun pada tahap pertama operasi kami mematikan slot. Kami berpikir bahwa jika slot akan mengakumulasi banyak segmen, master bisa jatuh. Setelah beberapa saat menderita tanpa slot, kami menyadari bahwa kami membutuhkannya dan mengembalikannya.

Masalahnya adalah bahwa ketika wizard memasuki keadaan replika, wizard menghapus slot dan wal-segmen bersama dengannya. Untuk meratakan masalah ini, kami meningkatkan parameter wal_keep_segments. Secara default, itu sama dengan 8 segmen, kami naik wal_keep_segmentsmenjadi 1000 . Kami mengalokasikan 16 GB pada wal_keep_segments, dan sekarang, ketika beralih, kami selalu memiliki 16 GB log transaksi di semua node.

Ini juga berlaku untuk tugas pemeliharaan jangka panjang. Katakanlah kita perlu memperbarui salah satu replika (perangkat lunak, OS, sesuatu yang lain), dan kami ingin mematikannya. Ketika kami mematikan replika, slot juga dihapus untuk itu. Jika Anda menggunakan nilai parameter kecil wal_keep_segments, maka dengan tidak adanya replika yang lama, itu akan meminta log transaksi yang bahkan mungkin tidak muncul di wizard - maka replika tidak akan dapat terhubung. Karena itu, kami menyimpan banyak majalah.

Masalah 4. Kehilangan Data


Terjadi kegagalan pada basis produksi. Kami memeriksa cluster: semuanya dalam urutan, semua replika sudah ada, tidak ada lag replikasi, dan tidak ada kesalahan dalam log juga. Tetapi tim produk melaporkan bahwa tidak ada cukup data dalam database - mereka berada dalam satu sumber, tetapi tidak dalam database. Anda perlu memahami apa yang terjadi pada mereka.

Kami segera menyadari bahwa ini adalah pg_rewindselai mereka, tetapi kami perlu mencari tahu alasannya.

Kapan kegagalan itu terjadi?


Kita selalu dapat menemukan di log ketika feylover terjadi, yang menjadi master baru, yang adalah master sebelum dan ketika dia ingin menjadi replika.

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

Dari log, kita dapat menentukan berapa banyak log transaksi telah hilang.

Seperti ini: wizard lama di-reboot, setelah di-restart oleh autorun, Patroni diluncurkan, yang kemudian meluncurkan PostgreSQL. PostgreSQL memutuskan untuk menjadi anggota cluster Patroni dan meluncurkan proses pg_rewindyang pada gilirannya menghapus bagian dari log transaksi, mengunduh yang baru, dan terhubung.

Patroni bekerja persis seperti yang dimaksudkan. Cluster pulih: ada 3 node, setelah feylover 3 node dan kiri. Tetapi sebagian data hilang, dan Anda perlu memahami bagian apa itu.

Temukan di log master lama saat itu terjadi 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!

Anda perlu menemukan posisi dalam log transaksi, yang menghentikan master lama.

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

Dalam hal ini, itu adalah tanda 0 / 5BDA8EB8. Tanda kedua - 0 / 5AD1BFD8 - diperlukan untuk menemukan jarak dengan mana master lama berbeda dari yang baru. Dengan menggunakan fungsi ini pg_wal_lsn_diff , kami membandingkan dua tanda ini, kami mendapatkan 17 MB.

Apakah ada kehilangan data sebesar 17 MB, semua orang memutuskan sendiri. Bagi sebagian orang, ini tidak signifikan, tetapi bagi seseorang itu tidak bisa diterima. Masing-masing untuk dirinya sendiri menentukan sesuai dengan kebutuhan bisnis.

Keputusan


Pertama-tama, Anda perlu memutuskan apakah Patroni autostart selalu diperlukan setelah mem-boot ulang sistem . Paling sering, kita harus pergi ke master lama, melihat betapa berbedanya itu dari keadaan saat ini, mungkin memeriksa segmen log transaksi. Anda perlu memahami apakah data ini bisa hilang, atau Anda perlu menjalankan wizard lama dalam mode mandiri untuk menarik data. Hanya setelah itu membuat keputusan apa yang harus dilakukan dengan data dan menghubungkan simpul ini sebagai replika ke cluster kami.

Selain itu, ada parametermaximum_lag_on_failover, secara default nilainya 1 Mb. Kerjanya seperti ini: jika replika adalah 1 MB di belakang lag replikasi, maka replika ini tidak mengambil bagian dalam pemilihan. Jika tiba-tiba terjadi failover, Patroni melihat di mana replika berada di belakang, dan replika yang berada di belakang sejumlah besar log transaksi tidak dapat menjadi master. Ini adalah fitur keamanan yang baik yang mencegah Anda kehilangan terlalu banyak data.

Tetapi ada masalah: lag replikasi diperbarui pada interval tertentu, nilai ttlstandarnya adalah 30 detik. Sangat mungkin bahwa nilai lag replikasi untuk replika di DCS adalah satu, tetapi sebenarnya itu sama sekali berbeda atau tidak ada lag sama sekali. Ini bukan nilai waktu nyata, itu tidak selalu mencerminkan gambaran nyata dan tidak layak mengikat logika yang rumit untuk itu.

Risiko "kerugian" selalu tetap:

  • Dalam kasus terburuk: maximum_lag_on_failover + ttl.
  • Dalam kasus rata-rata: maximum_lag_on_failover + (loop_wait / 2).

Ketika Anda berencana untuk menerapkan Patroni dan mengevaluasi berapa banyak data yang Anda bisa kehilangan, pertimbangkan formula ini untuk secara kasar mewakili kemungkinan kerugian.

Kabar baiknya adalah bahwa mungkin ada WAL dari proses latar belakang dalam "kerugian". Data ini dapat dengan mudah diabaikan dan hilang, tidak ada masalah.

Seperti inilah tampilan log jika diatur maximum_lag_on_failover, terjadi feylover dan Anda perlu memilih wizard baru:

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

Replika hanya melihat bahwa dia not healthy enough for leader racedan menolak untuk berpartisipasi dalam perlombaan kepemimpinan. Oleh karena itu, ia hanya menunggu wizard baru untuk dipilih untuk terhubung dengannya. Ini adalah tindakan tambahan terhadap kehilangan data.

Masalah 5. Drive


Tim produk menulis bahwa aplikasi tersebut memiliki masalah dalam bekerja dengan PostgreSQL. Pada saat yang sama, Anda tidak dapat memasukkan master, karena tidak tersedia melalui SSH, tetapi pengarsipan otomatis tidak terjadi juga. Kemudian tuan rumah secara paksa reboot dan dengan demikian meluncurkan auto-filer. Meskipun dimungkinkan untuk membuat feylover manual.

Setelah reboot, kita pergi untuk melihat apa yang terjadi pada master.



Kami tahu sebelumnya tentang masalah dengan disk, dengan memantau kami tahu di mana harus menggali.

Dalam log PostgreSQL, kita melihat yang berikut:

[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
...

Di muka adalah semua indikator masalah dengan disk: melakukan yang berlangsung selama satu detik, autovacuum berjalan sangat lama dan aneh, dan file sementara pada disk.

Kami melihat ke dalam sistem dmesg - log pesan kernel, dan melihat masalah dengan salah satu disk:

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

Subsistem disk pada server adalah perangkat lunak Raid 8 disk, tetapi satu hilang. Garis sda3[0] sdc3[2] sdd3[3] sdb3[1] sdh3[7] sdf3[5] sdg3[6]tidak ada sde[4]. Secara relatif, satu disk terjatuh, ini menyebabkan masalah disk, dan aplikasi mengalami masalah bekerja dengan cluster PostgreSQL.

Keputusan


Dalam hal ini, Patroni tidak akan dapat membantu, karena Patroni tidak memiliki tugas untuk memantau status server dan disk. Selama masalah, Patroni terus berinteraksi dengan gugus DCS dan tidak melihat kesulitan. Untuk situasi seperti itu, pemantauan eksternal diperlukan.

Masalah 6. Simulator klaster


Ini adalah salah satu masalah aneh. Saya mempelajarinya untuk waktu yang sangat lama, membaca kembali banyak log dan menyebutnya "Cluster simulator".

Masalahnya adalah bahwa tuan tua itu tidak bisa menjadi isyarat normal. Patroni menjalankannya, menunjukkan bahwa simpul ini hadir sebagai replika, tetapi pada saat yang sama itu bukan replika normal, sekarang Anda akan melihat alasannya.

Semuanya dimulai, seperti pada kasus sebelumnya, dengan masalah disk:

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

Ada koneksi yang terputus:

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

Ada harapan yang panjang akan respons dan pemblokiran dari berbagai tingkat keparahan:

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.

Secara umum, ada masalah yang jelas dengan disk, termasuk file sementara lagi.

Tapi yang paling misterius bagi saya - terbang 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 memiliki tiga mode mematikan:

  • Anggun ketika kita menunggu semua klien untuk memutuskan sendiri.
  • Cepat, ketika kami memberitahu pelanggan untuk memutuskan sambungan, karena kami akan mematikan.
  • Segera, yang tidak memberi tahu klien bahwa perlu memutus sambungan, tetapi cukup mematikannya dan mengirim pesan RST ke semua klien (sinyal TCP bahwa koneksi terputus).

Proses latar belakang PostgreSQL tidak saling mengirim sinyal permintaan shutdown, tetapi hanya meresponsnya. Ini restart darurat, dan siapa yang mengirimnya tidak jelas. Jika ya kill -9, maka saya akan melihatnya di log, tetapi tidak ada di sana.

Memahami lebih jauh, saya melihat bahwa Patroni tidak menulis ke log untuk beberapa waktu - tidak ada pesan selama 54 detik. Selama waktu ini, salah satu replika yang dibuat "mempromosikan" dan pengarsipan otomatis terjadi:

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 bekerja dengan sempurna lagi di sini, master lama tidak tersedia, jadi pemilihan master baru dimulai.

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 menjadi pemimpin baru, dan hanya ada masalah dengan replika kedua. Dia dengan jujur ​​mencoba mengkonfigurasi ulang:

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

Dia mencoba mengubah recovery.conf, restart PostgreSQL, sambungkan ke wizard baru. Setiap 10 detik ada pesan yang dia coba, tetapi tidak bisa.

Sementara itu, sinyal langsung-shutdown yang sama terbang ke master lama. Wizard memulai reboot darurat, pemulihan juga berhenti. Replika tidak dapat terhubung ke master karena berada dalam mode shutdown.

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

Pada titik tertentu, replika berhasil, tetapi replikasi tidak dimulai.

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

Saya punya satu hipotesis: dalam recovery.conf adalah alamat master lama. Ketika master baru sudah muncul, replika kedua mencoba untuk terhubung ke master lama. Ketika Patroni mulai pada replika kedua, simpul dimulai, tetapi tidak dapat terhubung melalui replikasi. Jeda replikasi terbentuk yang terlihat seperti ini:

+-----------------+----------+--------------+--------+---------+-----------+
|     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 |
+-----------------+----------+--------------+--------+---------+-----------+

Yaitu, ketiga node berada di tempatnya, tetapi node kedua ada di belakang. Replikasi tidak dapat dimulai karena log transaksi berbeda. Log transaksi yang ditawarkan oleh wizard, ditunjukkan dalam recovery.conf, tidak cocok dengan simpul saat ini. PostgreSQL melaporkan kesalahan setiap 5 detik

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

Di sini saya membuat kesalahan dan tidak menguji hipotesis saya bahwa kami terhubung ke master yang salah. Saya baru saja memulai kembali Patroni pada replika. Jujur, saya sudah mengakhiri itu dan berpikir bahwa saya harus mengulanginya, tetapi masih memutuskan untuk mencoba memulai kembali.

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

Pemulihan dimulai, dan bahkan basis data dibuka, ia siap menerima koneksi, replikasi dimulai:

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

Tapi semenit kemudian dia jatuh dengan kesalahan terminating walreceiver process due to administrator command- replika mengatakan bahwa log transaksi tidak cocok untuknya.

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

Dan saya tidak me-restart PostgreSQL, tetapi Patroni-lah yang di-restart dengan harapan akan meluncurkan database secara ajaib. Replikasi dimulai lagi, tetapi database dibuka di tempat yang sama:

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

Marka dalam log transaksi berbeda, mereka berbeda dari pada percobaan peluncuran sebelumnya - posisi log transaksi lebih awal:

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

Replikasi berhenti lagi, dan pesan kesalahannya berbeda dan sekali lagi tidak terlalu informatif:

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

Untuk percobaan, dimulai lagi, pangkalan dibuka di tempat yang sama:

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

Kemudian muncul ide bagi saya: bahwa jika saya me-restart PostgreSQL, pada titik ini pada wizard saat ini saya akan melakukan pos pemeriksaan untuk memindahkan titik dalam log transaksi sedikit ke depan dan pemulihan dimulai dari saat lain.

Meluncurkan Patroni, membuat beberapa pos pemeriksaan pada master, beberapa titik restart pada replika ketika dibuka:

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

Ini berhasil - replikasi dimulai dari tempat yang berbeda dan tidak lagi rusak. Tetapi bagi saya ini adalah salah satu masalah paling misterius yang masih saya pikirkan. Terutama permintaan penutupan langsung yang aneh itu.

Dari sini kita dapat menyimpulkan: Patroni dapat bekerja sesuai rencana dan tanpa kesalahan, tetapi ini bukan jaminan mutlak bahwa semuanya benar-benar teratur. Setelah feylover, Anda selalu perlu mengecek apakah semuanya baik-baik saja dengan cluster: jumlah replika yang tepat, tidak ada jeda replikasi.

Ringkasan


Berdasarkan ini dan banyak masalah serupa lainnya, saya merumuskan rekomendasi umum yang saya sarankan agar Anda ingat ketika mengoperasikan Patroni.

  • Ketika Anda menggunakan Patroni, Anda harus memiliki pemantauan. Anda selalu perlu tahu kapan file otomatis terjadi, karena jika Anda tidak tahu bahwa Anda memiliki file otomatis, Anda tidak mengontrol cluster.
  •  Setelah setiap feylover selalu periksa cluster. Anda harus memastikan bahwa: replika selalu nomor saat ini; tidak ada penundaan replikasi; tidak ada kesalahan dalam log yang terkait dengan replikasi streaming, dengan Patroni, dengan sistem DCS.

Patroni adalah alat yang sangat bagus, tetapi tidak peduli bagaimana Anda mengatakan itu bukan peluru perak. Otomasi dapat berhasil dengan sukses, tetapi pada saat yang sama objek otomasi dapat dalam kondisi setengah bekerja. Bagaimanapun, Anda perlu memiliki ide tentang bagaimana PostgreSQL dan replikasi bekerja, bagaimana Patroni mengelola PostgreSQL, dan bagaimana interaksi antar node dipastikan. Ini diperlukan untuk dapat memperbaiki masalah yang timbul dengan tangan Anda.

Langkah diagnostik


Kebetulan kami bekerja dengan klien yang berbeda, sebagian besar mereka tidak memiliki tumpukan ELK, dan Anda harus memilah log dengan membuka 2 tab dan 6 konsol: di satu tab Patroni untuk setiap node, di yang lain - log Konsul atau PostgreSQL. Mendiagnosis semua ini sulit.

Saya telah mengembangkan pendekatan berikut. Saya selalu menonton ketika kegagalan terjadi. Bagi saya itu semacam daerah aliran sungai. Saya melihat apa yang terjadi sebelum, selama dan setelah feylover. Failover memiliki dua cap waktu - mulai dan berakhir. Dalam log, saya melihat apa yang mendahului feylover, yaitu, saya mencari alasan. Ini memberikan pemahaman tentang gambar apa yang terjadi dan apa yang bisa dilakukan di masa depan sehingga feylover tidak terjadi dalam keadaan yang sama.

Untuk ini, saya melihat:

  • Pertama-tama, log Patroni.
  • PostgreSQL DCS , Patroni.
  • — , .


Ada banyak produk lain untuk pengarsipan otomatis: stolon, repmgr, pg_auto_failover, PAF. Saya mencoba semua 4 alat dan menurut saya Patroni adalah yang terbaik yang ada di pasaran saat ini.

Apakah saya merekomendasikan Patroni? Jelas, ya, karena saya suka Patroni, saya pikir saya belajar cara memasaknya.

Jika Anda tertarik untuk melihat masalah lain apa yang ada dengan Patroni, selain yang dijelaskan dalam artikel, Anda selalu dapat membuka halaman https://github.com/zalando/patroni/issues . Ada banyak kisah berbeda. Terlepas dari kenyataan bahwa setengah dari mereka berasal dari pengguna yang buta huruf yang mengajukan pertanyaan bodoh tanpa repot-repot dengan pencarian sederhana, masalah menarik juga dibahas di sana dan, sebagai hasil dari diskusi, tugas untuk memperbaiki bug dibuka jika perlu.

Terima kasih kepada Zalando untuk mengembangkan proyek ini, dan juga kepada dua orang yang mulai mengerjakan produk ini: Alexander Kukushkin dan Alexey Klyukin. Terima kasih banyak untuk semua kontributor Patroni.

Setelah laporan ini, kami mencatat wawancara singkat di mana Alex mencoba menyesuaikan laporannya ke dalam satu dewan dan memberi tahu mengapa harus berpartisipasi dan berbicara di konferensi. Ambil senjata dan datang untuk memeriksa pendekatan di Saint HighLoad ++.


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

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

More articles:


All Articles