Bagaimana kami berburu bug NFS selama dua minggu di kernel Linux

Deskripsi terperinci dari pencarian bug dari tugas GitLab yang mengarah ke patch untuk kernel Linux


Pada 14 September, dukungan GitLab melaporkan masalah kritis yang terjadi pada salah satu pelanggan kami: pertama, GitLab berfungsi dengan baik, dan kemudian pengguna mendapatkan kesalahan. Mereka mencoba mengkloning beberapa repositori melalui Git, dan tiba-tiba sebuah pesan yang tidak dapat dimengerti muncul tentang file yang sudah usang: Stale file error . Kesalahan bertahan untuk waktu yang lama dan tidak berfungsi sampai administrator sistem secara manual memulai ls di direktori itu sendiri.


Saya harus mempelajari mekanisme internal Git dan sistem file jaringan NFS. Hasilnya, kami menemukan bug di klien Linux v4.0 NFS, Trond Myklebust menulis tambalan untuk kernel , dan sejak 26 Oktober tambalan ini telah dimasukkan dalam kernel Linux utama .


Dalam posting ini saya akan memberi tahu Anda bagaimana kami mempelajari masalah, ke arah mana kami berpikir dan alat apa yang kami gunakan untuk melacak bug. Kami terinspirasi oleh karya detektif yang sangat baik dari Oleg Dashevsky yang dijelaskan dalam posting "Bagaimana Saya Memburu Memori yang Kebocoran di Ruby selama Dua Minggu" .



Ini juga contoh yang bagus tentang bagaimana debug sumber terbuka adalah olahraga tim yang melibatkan banyak orang, perusahaan, dan negara. Moto GitLab, “ Semua orang dapat berkontribusi, ” benar tidak hanya untuk GitLab itu sendiri, tetapi juga untuk proyek-proyek sumber terbuka lainnya, seperti kernel Linux.


Reproduksi bug


Kami menyimpan NFS di GitLab.com selama bertahun-tahun, tetapi kemudian berhenti menggunakannya untuk mengakses data repositori pada mesin dengan aplikasi. Kami telah memindahkan semua panggilan Git ke Gitaly . Kami mendukung NFS untuk klien yang mengelola instalasi mereka di GitLab tetapi tidak pernah mengalami masalah yang sama dengan klien yang disebutkan sebelumnya.


Klien memberikan beberapa petunjuk bermanfaat :


  1. Teks kesalahan penuh: fatal: Couldn't read ./packed-refs: Stale file handle .
  2. Tampaknya, masalah muncul ketika klien secara manual memulai pengumpulan sampah di Git dengan perintah git gc .
  3. Kesalahan menghilang ketika administrator sistem memulai utilitas ls di direktori.
  4. Kesalahan menghilang ketika proses git gc .

Jelas bahwa dua titik pertama terhubung. Saat Anda mengirim perubahan ke cabang Git, Git membuat tautan yang lemah - nama file panjang yang menunjukkan nama cabang untuk komit. Misalnya, saat mengirim ke master , file bernama refs/heads/master akan dibuat di repositori:


 $ cat refs/heads/master 2e33a554576d06d9e71bfd6814ee9ba3a7838963 

Perintah git gc melakukan beberapa tugas. Sebagai contoh, ia mengumpulkan tautan-tautan lemah ini (ref) dan mengemasnya menjadi satu file yang disebut packed-refs . Ini sedikit mempercepat pekerjaan, karena membaca satu file besar lebih mudah daripada banyak file kecil. Sebagai contoh, setelah menjalankan perintah git gc , file paket packed-refs mungkin terlihat seperti ini:


 # pack-refs with: peeled fully-peeled sorted 564c3424d6f9175cf5f2d522e10d20d781511bf1 refs/heads/10-8-stable edb037cbc85225261e8ede5455be4aad771ba3bb refs/heads/11-0-stable 94b9323033693af247128c8648023fe5b53e80f9 refs/heads/11-1-stable 2e33a554576d06d9e71bfd6814ee9ba3a7838963 refs/heads/master 

Bagaimana file packed-refs ? Untuk mengetahuinya, kami menjalankan perintah strace git gc mana kami memiliki tautan yang lemah. Berikut adalah baris yang relevan:


 28705 open("/tmp/libgit2/.git/packed-refs.lock", O_RDWR|O_CREAT|O_EXCL|O_CLOEXEC, 0666) = 3 28705 open(".git/packed-refs", O_RDONLY) = 3 28705 open("/tmp/libgit2/.git/packed-refs.new", O_RDWR|O_CREAT|O_EXCL|O_CLOEXEC, 0666) = 4 28705 rename("/tmp/libgit2/.git/packed-refs.new", "/tmp/libgit2/.git/packed-refs") = 0 28705 unlink("/tmp/libgit2/.git/packed-refs.lock") = 0 

Panggilan sistem menunjukkan bahwa perintah git gc :


  1. Terbuka packed-refs.lock . Ini memberitahu proses lain bahwa file packed-refs terkunci dan tidak dapat diubah.
  2. Dibuka packed-refs.new .
  3. Saya packed-refs.new tautan lemah di packed-refs.new .
  4. Berganti nama packed-refs.new menjadi packed-refs .
  5. Dihapus packed-refs.lock .
  6. Tautan lemah yang dihapus.

Poin kunci di sini adalah yang keempat, yaitu, mengganti nama, di mana Git memperkenalkan file packed-refs . git gc tidak hanya mengumpulkan tautan yang lemah, tetapi juga melakukan tugas yang jauh lebih banyak sumber daya - ia mencari dan menghapus objek yang tidak digunakan. Dalam repositori besar, ini bisa bertahan lebih dari satu jam.


Dan kami bertanya pada diri sendiri: dalam repositori besar, apakah git gc menjaga file tetap terbuka selama pembersihan? Kami mempelajari strace log, meluncurkan utilitas lsof , dan inilah yang kami pelajari tentang proses git gc :


gambar


Seperti yang Anda lihat, file packed-refs ditutup di bagian paling akhir, setelah proses Garbage collect objects berpotensi lama Garbage collect objects .


Jadi pertanyaan berikut muncul: bagaimana NFS berperilaku ketika file packed-refs terbuka pada satu node, dan yang lainnya mengubah nama itu pada waktu itu?


"Untuk tujuan ilmiah," kami meminta klien untuk melakukan satu percobaan pada dua mesin yang berbeda (Alice dan Bob):
1) Dalam volume bersama NFS, buat dua file: test1.txt dan test2.txt dengan konten yang berbeda, sehingga lebih mudah untuk membedakannya:


 alice $ echo "1 - Old file" > /path/to/nfs/test1.txt alice $ echo "2 - New file" > /path/to/nfs/test2.txt 

2) Pada mesin Alice, file test1.txt harus terbuka:


 alice $ irb irb(main):001:0> File.open('/path/to/nfs/test1.txt') 

3) Pada mesin Alice, terus tampilkan konten test1.txt :


 alice $ while true; do cat test1.txt; done 

4) Kemudian, pada mesin Bob, jalankan perintah:


 bob $ mv -f test2.txt test1.txt 

Langkah terakhir mereproduksi apa yang git gc lakukan dengan file packed-refs ketika menimpa file yang sudah ada.
Di mesin klien, hasilnya terlihat seperti ini:


 1 - Old file 1 - Old file 1 - Old file cat: test1.txt: Stale file handle 

Ada! Kami tampaknya telah mengendalikan masalah dengan cara yang terkendali. Tetapi dalam percobaan yang sama pada server Linux NFS, masalah ini tidak terjadi. Hasilnya diharapkan - setelah mengganti nama konten baru diterima:


 1 - Old file 1 - Old file 1 - Old file 2 - New file <--- RENAME HAPPENED 2 - New file 2 - New file 

Dari mana perbedaan perilaku ini berasal? Ternyata klien menggunakan penyimpanan Isilon NFS , yang hanya mendukung NFS v4.0. Ketika kami mengubah pengaturan koneksi ke v4.0 menggunakan parameter vers=4.0 di /etc/fstab , tes menunjukkan hasil yang berbeda untuk server Linux NFS:


 1 - Old file 1 - Old file 1 - Old file 1 - Old file <--- RENAME HAPPENED 1 - Old file 1 - Old file 

Alih-alih Stale file handle usang Stale file handle server Linux NFS v4.0 menampilkan konten usang. Ternyata perbedaan perilaku dapat dijelaskan oleh spesifikasi NFS. Dari RFC 3010 :


Deskriptor file mungkin kedaluwarsa atau kedaluwarsa saat diganti namanya, tetapi tidak selalu. Pelaksana server disarankan untuk mengambil langkah-langkah untuk memastikan bahwa deskriptor file tidak kedaluwarsa dan tidak kedaluwarsa dengan cara ini.

Dengan kata lain, server NFS dapat memilih bagaimana berperilaku ketika file diubah namanya, dan server NFS cukup mengembalikan Stale file error dalam kasus tersebut. Kami menyarankan bahwa penyebab masalahnya adalah sama, walaupun hasilnya berbeda. Kami menduga itu adalah pemeriksaan cache, karena utilitas ls di direktori menghapus kesalahan. Sekarang kami memiliki skenario pengujian yang dapat direproduksi, dan kami beralih ke ahli - pengelola Linux NFS.


Pelacakan Salah: Delegasi pada Server NFS


Ketika kami berhasil mereproduksi kesalahan langkah demi langkah, saya menulis ke kontak NFS Linux tentang apa yang kami pelajari. Saya berkorespondensi dengan Bruce Fields, pengelola server Linux NFS selama seminggu, dan dia menyarankan bahwa bug ada di NFS dan saya perlu mempelajari lalu lintas jaringan. Dia pikir masalahnya adalah mendelegasikan tugas di server NFS.


Apa yang dimaksud dengan delegasi pada server NFS?


Singkatnya, versi NFS v4 memiliki fungsi delegasi untuk mempercepat akses file. Server dapat mendelegasikan akses baca atau tulis ke klien sehingga klien tidak harus terus-menerus bertanya kepada server apakah file telah diubah oleh klien lain. Sederhananya, mendelegasikan catatan seperti meminjamkan buku catatan Anda kepada seseorang dan berkata, "Anda menulis di sini, dan saya akan mengambilnya ketika saya siap." Dan seseorang tidak harus meminta buku catatan setiap kali Anda perlu menulis sesuatu - ia memiliki kebebasan penuh untuk bertindak sampai buku catatan tersebut diambil. Di NFS, permintaan untuk mengembalikan notebook disebut pencabutan delegasi.


Bug dalam pencabutan delegasi NFS dapat menjelaskan masalah Stale file handle . Ingat bagaimana test1.txt dibuka dalam test1.txt Alice, dan kemudian test2.txt menggantinya. Mungkin server tidak dapat mencabut delegasi untuk test1.txt , dan ini menyebabkan status yang tidak valid. Untuk menguji teori ini, kami mencatat lalu lintas NFC dengan utilitas tcpdump dan memvisualisasikannya menggunakan Wireshark.


Wireshark adalah alat open source yang hebat untuk menganalisis lalu lintas jaringan, terutama untuk menjelajahi NFS dalam aksi. Kami merekam jejak menggunakan perintah berikut di server NFS:


 tcpdump -s 0 -w /tmp/nfs.pcap port 2049 

Perintah ini mencatat semua lalu lintas NFS yang biasanya melewati port TCP 2049. Karena percobaan kami berhasil dengan NFS v4.1, tetapi tidak dengan NFS v4.0, kami dapat membandingkan perilaku NFS dalam kasus yang bekerja dan yang tidak bekerja. Dengan Wireshark, kami melihat perilaku berikut:


NFS v4.0 (file usang)


gambar


Diagram ini menunjukkan bahwa pada langkah 1, Alice membuka test1.txt dan menerima deskriptor file NFS dengan pengenal stateid 0x3000. Ketika Bob mencoba mengubah nama file, server NFS meminta untuk mencoba lagi dengan mengirim pesan NFS4ERR_DELAY , dan ia mengingat delegasi dari Alice melalui pesan CB_RECALL (langkah 3). Alice mengembalikan delegasi (DELEGRETURN pada langkah 4), dan Bob mencoba mengirim pesan RENAME lagi (langkah 5). RENAME dieksekusi dalam kedua kasus, tetapi Alice terus membaca file oleh deskriptor yang sama.


NFS v4.1 (case kerja)


gambar


Di sini perbedaannya terlihat pada langkah 6. Dalam NFS v4.0 (dengan file yang usang) Alice mencoba menggunakan stateid sama stateid . Dalam NFS v4.1 (case kerja), Alice melakukan operasi LOOKUP dan OPEN tambahan, sehingga server mengembalikan stateid berbeda. Di v4.0, itu tidak mengirim pesan tambahan. Ini menjelaskan mengapa Alice melihat konten yang sudah usang - ia menggunakan deskriptor lama.


Mengapa Alice tiba-tiba memutuskan LOOKUP tambahan? Tampaknya, penarikan kembali delegasi berhasil, tetapi beberapa masalah tampaknya tetap ada. Misalnya, langkah cacat dilewati. Untuk memverifikasi ini, kami mengecualikan delegasi NFS di server NFS sendiri dengan perintah ini:


 echo 0 > /proc/sys/fs/leases-enable 

Kami mengulangi percobaan, tetapi masalahnya tidak hilang. Kami memastikan bahwa masalahnya bukan pada server atau delegasi NFS, dan memutuskan untuk melihat klien NFS di kernel.


Menggali lebih dalam: klien Linux NFS


Pertanyaan pertama yang harus kami jawab kepada pengelola NFS adalah:


Apakah masalah ini tetap ada pada versi kernel terbaru?


Masalahnya terjadi pada kernel CentOS 7.2 dan Ubuntu 16.04 dengan versi 3.10.0-862.11.6 dan 4.4.0-130. Namun kedua core tertinggal versi terbaru, yang pada waktu itu adalah 4.19-rc2.


Kami menggunakan mesin virtual Ubuntu 16.04 baru di Google Cloud Platform (GCP), mengkloning kernel Linux terbaru, dan mengatur lingkungan pengembangan kernel. Kami membuat file .config menggunakan menuconfig dan memverifikasi bahwa:


  1. Driver NFS dikompilasi sebagai modul ( CONFIG_NFSD=m ).
  2. Parameter kernel GCP yang benar ditentukan dengan benar.

Genetika melacak evolusi secara real time oleh Drosophila, dan dengan item pertama kita dapat dengan cepat melakukan koreksi pada klien NFS tanpa memulai ulang kernel. Poin kedua menjamin bahwa kernel akan mulai setelah instalasi. Untungnya, kami puas dengan parameter kernel default.


Kami memastikan bahwa masalah file yang usang tidak hilang dalam versi kernel terbaru. Kami bertanya pada diri sendiri:


  1. Di mana tepatnya masalah muncul?
  2. Mengapa ini terjadi di NFS v4.0, tetapi tidak di v4.1?

Untuk menjawab pertanyaan ini, kami mempelajari kode sumber NFS. Kami tidak memiliki debugger kernel, jadi kami mengirim dua jenis panggilan ke kode sumber:


  1. pr_info() ( printk ).
  2. dump_stack() : ini menunjukkan jejak stack untuk panggilan fungsi saat ini.

Sebagai contoh, hal pertama yang kami lakukan adalah terhubung ke fungsi nfs4_file_open() di fs/nfs/nfs4file.c :


 static int nfs4_file_open(struct inode *inode, struct file *filp) { ... pr_info("nfs4_file_open start\n"); dump_stack(); 

Tentu saja, kami dapat dprintk dengan debugging dinamis Linux atau menggunakan rpcdebug , tetapi kami ingin menambahkan pesan kami sendiri untuk memeriksa perubahan.


Setelah setiap perubahan, kami mengkompilasi ulang modul dan menginstalnya kembali di kernel menggunakan perintah:


 make modules sudo umount /mnt/nfs-test sudo rmmod nfsv4 sudo rmmod nfs sudo insmod fs/nfs/nfs.ko sudo mount -a 

Dengan modul NFS, kami dapat mengulangi eksperimen dan menerima pesan untuk memahami kode NFS. Misalnya, Anda dapat langsung melihat apa yang terjadi ketika panggilan aplikasi open() :


 Sep 24 20:20:38 test-kernel kernel: [ 1145.233460] Call Trace: Sep 24 20:20:38 test-kernel kernel: [ 1145.233462] dump_stack+0x8e/0xd5 Sep 24 20:20:38 test-kernel kernel: [ 1145.233480] nfs4_file_open+0x56/0x2a0 [nfsv4] Sep 24 20:20:38 test-kernel kernel: [ 1145.233488] ? nfs42_clone_file_range+0x1c0/0x1c0 [nfsv4] Sep 24 20:20:38 test-kernel kernel: [ 1145.233490] do_dentry_open+0x1f6/0x360 Sep 24 20:20:38 test-kernel kernel: [ 1145.233492] vfs_open+0x2f/0x40 Sep 24 20:20:38 test-kernel kernel: [ 1145.233493] path_openat+0x2e8/0x1690 Sep 24 20:20:38 test-kernel kernel: [ 1145.233496] ? mem_cgroup_try_charge+0x8b/0x190 Sep 24 20:20:38 test-kernel kernel: [ 1145.233497] do_filp_open+0x9b/0x110 Sep 24 20:20:38 test-kernel kernel: [ 1145.233499] ? __check_object_size+0xb8/0x1b0 Sep 24 20:20:38 test-kernel kernel: [ 1145.233501] ? __alloc_fd+0x46/0x170 Sep 24 20:20:38 test-kernel kernel: [ 1145.233503] do_sys_open+0x1ba/0x250 Sep 24 20:20:38 test-kernel kernel: [ 1145.233505] ? do_sys_open+0x1ba/0x250 Sep 24 20:20:38 test-kernel kernel: [ 1145.233507] __x64_sys_openat+0x20/0x30 Sep 24 20:20:38 test-kernel kernel: [ 1145.233508] do_syscall_64+0x65/0x130 

Apa vfs_open dan vfs_open ? Linux memiliki sistem file virtual ( VFS ), lapisan abstraksi yang menyediakan antarmuka umum untuk semua sistem file. Dokumentasi VFS mengatakan:


VFS mengimplementasikan open (2), stat (2), chmod (2) dan panggilan sistem lainnya. Sistem VFS menggunakan argumen nama jalur yang diteruskan ke mereka untuk mencari cache untuk entri direktori (cache gigi palsu, atau dcache). Ini menyediakan mesin pencari yang sangat cepat yang mengubah nama jalur (atau nama file) menjadi gigi palsu tertentu. Dentry berada dalam RAM dan tidak pernah disimpan ke disk - mereka hanya ada untuk kinerja.

Dan saya sadar - bagaimana jika masalahnya ada dalam cache dentry?


Kami memperhatikan bahwa cache dentry biasanya diperiksa di fs/nfs/dir.c Kami terutama tertarik pada fungsi nfs4_lookup_revalidate() , dan sebagai percobaan, kami membuatnya berfungsi lebih awal:


 diff --git a/fs/nfs/dir.cb/fs/nfs/dir.c index 8bfaa658b2c1..ad479bfeb669 100644 --- a/fs/nfs/dir.c +++ b/fs/nfs/dir.c @@ -1159,6 +1159,7 @@ static int nfs_lookup_revalidate(struct dentry *dentry, unsigned int flags) trace_nfs_lookup_revalidate_enter(dir, dentry, flags); error = NFS_PROTO(dir)->lookup(dir, &dentry->d_name, fhandle, fattr, label); trace_nfs_lookup_revalidate_exit(dir, dentry, flags, error); + goto out_bad; if (error == -ESTALE || error == -ENOENT) goto out_bad; if (error) 

Dan dalam percobaan ini, masalah file yang usang tidak terjadi! Akhirnya, kami menyerang jalan.


Untuk mengetahui mengapa masalah tidak terjadi pada NFS v4.1, kami menambahkan panggilan pr_info() untuk masing-masing if blok dalam fungsi ini. Kami bereksperimen dengan NFS v4.0 dan v4.1 dan menemukan kondisi khusus di versi v4.1:


 if (NFS_SB(dentry->d_sb)->caps & NFS_CAP_ATOMIC_OPEN_V1) { goto no_open; } 

Apa itu NFS_CAP_ATOMIC_OPEN_V1 ? Patch kernel ini mengatakan bahwa ini adalah fitur NFS v4.1, dan kode di fs/nfs/nfs4proc.c mengkonfirmasi bahwa parameter ini di v4.1 tetapi tidak di v4.0:


 static const struct nfs4_minor_version_ops nfs_v4_1_minor_ops = { .minor_version = 1, .init_caps = NFS_CAP_READDIRPLUS | NFS_CAP_ATOMIC_OPEN | NFS_CAP_POSIX_LOCK | NFS_CAP_STATEID_NFSV41 | NFS_CAP_ATOMIC_OPEN_V1 

Oleh karena itu, versi berperilaku berbeda - di v4.1, goto no_open memanggil lebih banyak pemeriksaan di fungsi nfs_lookup_revalidate() , dan di v4.0 fungsi nfs4_lookup_revalidate() kembali lebih awal. Dan bagaimana kita memecahkan masalah?


Solusi


Saya berbicara tentang temuan kami di milis NFS dan menyarankan patch primitif . Seminggu kemudian, Trond Myklebust mengirim serangkaian tambalan dengan perbaikan bug ke milis dan menemukan masalah terkait lainnya di NFS v4.1 .


Ternyata perbaikan untuk bug NFS v4.0 lebih dalam di basis kode daripada yang kita duga. Trond menggambarkannya dengan baik di tambalan :


Penting untuk memastikan bahwa inode dan dentry diperiksa ulang dengan benar ketika file yang sudah dibuka dibuka. Saat ini kami tidak mengecek NFSv4.0, karena file yang terbuka di-cache. Mari kita perbaiki ini dan cache file yang terbuka hanya dalam kasus khusus - untuk mengembalikan file yang terbuka dan mengembalikan delegasi.

Kami memastikan bahwa perbaikan ini menyelesaikan masalah file yang usang dan mengirim laporan bug ke tim Ubuntu dan RedHat .


Kami sangat memahami bahwa perubahan tersebut belum dalam versi kernel yang stabil, jadi kami menambahkan solusi sementara untuk masalah ini di Gitaly . Kami bereksperimen dan memverifikasi bahwa stat() panggilan stat() dalam file packed-refs menyebabkan kernel memeriksa ulang file yang diubah namanya di cache dentry. Untuk mempermudah, kami menerapkan ini di Gitaly untuk sistem file apa pun, bukan hanya NFS. Validasi dilakukan hanya sekali sebelum Gitaly membuka repositori, dan untuk file lain sudah ada panggilan stat() .


Apa yang telah kita pelajari


Bug dapat bersembunyi di sudut mana pun dari tumpukan perangkat lunak, dan kadang-kadang Anda harus mencarinya di luar aplikasi. Jika Anda memiliki koneksi yang bermanfaat di dunia open source, ini akan membuat pekerjaan Anda lebih mudah.


Banyak terima kasih kepada Trond Myuklebust untuk memperbaiki masalah, dan kepada Bruce Fields untuk menjawab pertanyaan kami dan membantu mencari tahu NFS. Karena responsif dan profesionalisme kami menghargai komunitas pengembang open source.

Source: https://habr.com/ru/post/id432922/


All Articles