Permintaan I / O membutuhkan waktu lebih dari 15 detik

31

Biasanya backup penuh mingguan kami selesai dalam waktu sekitar 35 menit, dengan backup setiap hari selesai dalam ~ 5 menit. Sejak selasa harian telah menghabiskan hampir 4 jam untuk menyelesaikan, jauh lebih banyak dari yang seharusnya diperlukan. Secara kebetulan, ini mulai terjadi tepat setelah kami mendapatkan konfigurasi SAN / disk baru.

Perhatikan bahwa server berjalan dalam produksi dan kami tidak memiliki masalah secara keseluruhan, itu berjalan dengan lancar - kecuali untuk masalah IO yang terutama memanifestasikan dirinya dalam kinerja cadangan.

Melihat dm_exec_requests selama pencadangan, pencadangan selalu menunggu di ASYNC_IO_COMPLETION. Aha, jadi kami memiliki pendapat disk!

Namun, baik MDF (log disimpan di disk lokal) maupun drive cadangan tidak memiliki aktivitas apa pun (IOPS ~ = 0 - kami memiliki banyak memori). Panjang antrian disk ~ = 0 juga. CPU berkisar sekitar 2-3%, tidak ada masalah di sana juga.

SAN adalah Dell MD3220i, LUN yang terdiri dari drive SAS 6x10k. Server terhubung ke SAN melalui dua jalur fisik, masing-masing melalui sakelar terpisah dengan koneksi yang berlebihan ke SAN - total empat jalur, dua di antaranya aktif setiap saat. Saya dapat memverifikasi bahwa kedua koneksi aktif melalui task manager - membagi beban secara merata. Kedua koneksi menjalankan dupleks penuh 1G.

Kami dulu menggunakan bingkai jumbo, tapi saya telah menonaktifkannya untuk menyingkirkan masalah apa pun di sini - tidak ada perubahan. Kami memiliki server lain (konfigurasi OS + yang sama, 2008 R2) yang terhubung ke LUN lain, dan tidak menunjukkan masalah. Namun tidak menjalankan SQL Server, tetapi hanya berbagi CIFS di atas mereka. Namun, salah satu jalur yang dipilih LUN adalah pada pengontrol SAN yang sama dengan LUN yang bermasalah - jadi saya sudah mengesampingkannya juga.

Menjalankan beberapa tes SQLIO (file tes 10G) tampaknya menunjukkan bahwa IO layak, meskipun ada masalah:

sqlio -kR -t8 -o8 -s30 -frandom -b8 -BN -LS -Fparam.txt
IOs/sec:  3582.20
MBs/sec:    27.98
Min_Latency(ms): 0
Avg_Latency(ms): 3
Max_Latency(ms): 98
histogram:
ms: 0  1  2  3  4  5  6  7  8  9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24+
%: 45  9  5  4  4  4  4  4  4  3  2  2  1  1  1  1  1  1  1  0  0  0  0  0  2

sqlio -kW -t8 -o8 -s30 -frandom -b8 -BN -LS -Fparam.txt
IOs/sec:  4742.16
MBs/sec:    37.04
Min_Latency(ms): 0
Avg_Latency(ms): 2
Max_Latency(ms): 880
histogram:
ms: 0  1  2  3  4  5  6  7  8  9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24+
%: 46 33  2  2  2  2  2  2  2  1  1  1  1  0  0  0  0  0  0  0  0  0  0  0  1

sqlio -kR -t8 -o8 -s30 -fsequential -b64 -BN -LS -Fparam.txt
IOs/sec:  1824.60
MBs/sec:   114.03
Min_Latency(ms): 0
Avg_Latency(ms): 8
Max_Latency(ms): 421
histogram:
ms: 0  1  2  3  4  5  6  7  8  9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24+
%:  1  3 14  4 14 43  4  2  1  1  1  1  1  1  0  0  0  0  0  0  0  0  0  0  6

sqlio -kW -t8 -o8 -s30 -fsequential -b64 -BN -LS -Fparam.txt
IOs/sec:  3238.88
MBs/sec:   202.43
Min_Latency(ms): 1
Avg_Latency(ms): 4
Max_Latency(ms): 62
histogram:
ms: 0  1  2  3  4  5  6  7  8  9 10 11 12 13 14 15 16 17 18 19 20 21 22 23 24+
%:  0  0  0  9 51 31  6  1  0  0  0  0  0  0  0  0  0  0  0  0  0  0  0  0  0

Saya menyadari bahwa ini bukanlah tes yang lengkap, tetapi mereka membuat saya nyaman mengetahui bahwa itu bukan sampah lengkap. Perhatikan bahwa kinerja penulisan yang lebih tinggi disebabkan oleh dua jalur MPIO aktif, sedangkan membaca hanya akan menggunakan salah satunya.

Memeriksa log peristiwa Aplikasi mengungkapkan peristiwa seperti ini tersebar di sekitar:

SQL Server has encountered 2 occurrence(s) of I/O requests taking longer than 15 seconds to complete on file [J:\XXX.mdf] in database [XXX] (150).  The OS file handle is 0x0000000000003294.  The offset of the latest long I/O is: 0x00000033da0000

Mereka tidak konstan, tetapi mereka terjadi secara teratur (beberapa per jam, lebih banyak selama pencadangan). Di samping peristiwa itu, log peristiwa Sistem akan memposting ini:

Initiator sent a task management command to reset the target. The target name is given in the dump data.
Target did not respond in time for a SCSI request. The CDB is given in the dump data.

Ini juga terjadi pada server CIFS yang tidak bermasalah berjalan pada SAN / Controller yang sama, dan dari Google saya mereka tampaknya tidak kritis.

Perhatikan bahwa semua server menggunakan NIC yang sama - Broadcom 5709Cs dengan driver terbaru. Server itu sendiri adalah milik Dell R610.

Saya tidak yakin apa yang harus diperiksa selanjutnya. Ada saran?

Perbarui - Menjalankan perfmon
Saya mencoba merekam Rata-rata. Disk detik / Baca & Tulis penghitung perf saat melakukan pencadangan. Cadangan dimulai dengan luar biasa, dan kemudian pada dasarnya berhenti mati di 50%, merangkak perlahan menuju 100%, tetapi mengambil 20x waktu yang seharusnya.

Tugas memantau selama dimulainya pencadangan Memperlihatkan kedua jalur SAN yang digunakan, lalu menurun.

Lakukan selama yang samaPencadangan dimulai sekitar 15:38:50 - perhatikan semua terlihat bagus, dan kemudian ada serangkaian puncak. Saya tidak peduli dengan menulis, hanya membaca yang tampaknya menggantung.

Tugas memantau selama akhir cadangan Catat sedikit aksi on / off, meskipun kinerja menyala di akhir.

Perfmon selama yang sama Perhatikan maksimum 12detik, meskipun rata-rata secara keseluruhan bagus.

Pembaruan - Mencadangkan ke perangkat NUL
Untuk mengisolasi masalah baca dan menyederhanakan berbagai hal, saya menjalankan yang berikut:

BACKUP DATABASE XXX TO DISK = 'NUL'

Hasilnya persis sama - dimulai dengan membaca burst dan kemudian warung, melanjutkan operasi sekarang dan kemudian:

Hasil

Update - IO warung
aku berlari query dm_io_virtual_file_stats dari Jonathan Kehayias dan Ted Kruegers buku (halaman 29), seperti yang direkomendasikan oleh Shawn. Melihat 25 file teratas (masing-masing satu file data - semua hasilnya berupa file data), sepertinya membaca lebih buruk daripada menulis - mungkin karena menulis langsung menuju ke cache SAN sedangkan cold read perlu menekan disk - hanya tebakan saja .

Warung IO

Perbarui - Tunggu statistik
Saya melakukan tiga tes untuk mengumpulkan beberapa statistik menunggu. Statistik tunggu dipertanyakan menggunakan skrip Glenn Berry / Paul Randals . Dan hanya untuk mengonfirmasi - backup tidak dilakukan untuk merekam, tetapi untuk LUN iSCSI. Hasil serupa jika dilakukan ke disk lokal, dengan hasil yang mirip dengan cadangan NUL.

Statistik yang dihapus. Berlari selama 10 menit, beban normal: Tanpa cadangan

Statistik yang dihapus. Berlari selama 10 menit, pemuatan normal + pencadangan normal berjalan (tidak selesai): Cadangan normal

Statistik yang dihapus. Berlari selama 10 menit, beban normal + pencadangan NUL berjalan (tidak selesai): Cadangan NUL

Perbarui - Wtf, Broadcom?
Berdasarkan saran Mark Storey-Smiths dan pengalaman Kyle Brandts sebelumnya dengan Broadcom NICs, saya memutuskan untuk melakukan beberapa eksperimen. Karena kami memiliki beberapa jalur aktif, saya dapat dengan mudah mengubah konfigurasi NIC satu per satu tanpa menyebabkan gangguan.

Menonaktifkan TOE dan Kirim Kirim Besar menghasilkan proses yang hampir sempurna: masukkan deskripsi gambar di sini

Processed 1064672 pages for database 'XXX', file 'XXX' on file 1.
Processed 21 pages for database 'XXX', file 'XXX' on file 1.
BACKUP DATABASE successfully processed 1064693 pages in 58.533 seconds (142.106 MB/sec).

Jadi yang mana pelakunya, TOE atau LSO? TOE diaktifkan, LSO dinonaktifkan: masukkan deskripsi gambar di sini

Didn't finish the backup as it took forever - just as the original problem!

TOE dinonaktifkan, diaktifkan LSO - terlihat bagus: masukkan deskripsi gambar di sini

Processed 1064680 pages for database 'XXX', file 'XXX' on file 1.
Processed 29 pages for database 'XXX', file 'XXX' on file 1.
BACKUP DATABASE successfully processed 1064709 pages in 59.073 seconds (140.809 MB/sec).

Dan sebagai kontrol, saya menonaktifkan TOE dan LSO untuk mengonfirmasi bahwa masalah telah hilang: masukkan deskripsi gambar di sini

Processed 1064720 pages for database 'XXX', file 'XXX' on file 1.
Processed 13 pages for database 'XXX', file 'XXX' on file 1.
BACKUP DATABASE successfully processed 1064733 pages in 60.675 seconds (137.094 MB/sec).

Kesimpulannya tampaknya Broadcom NICs TCP Offload Engine menyebabkan masalah. Begitu TOE dinonaktifkan, semuanya bekerja seperti pesona. Kira saya tidak akan memesan lagi NIC Broadcom ke depan.

Pembaruan - Down the CIFS server
Hari ini server CIFS yang identik dan berfungsi mulai menunjukkan permintaan IO yang menggantung. Server ini tidak menjalankan SQL Server, hanya Windows Web Server 2008 R2 yang melayani pembagian lebih dari CIFS. Segera setelah saya menonaktifkan TOE, semuanya kembali berjalan dengan lancar.

Hanya mengonfirmasi bahwa saya tidak akan pernah menggunakan TOE di Broadcom NIC lagi, jika saya tidak bisa menghindari NIC Broadcom sama sekali, itu.

Mark S. Rasmussen
sumber
File data menggunakan RAID10 LUN 6 disk khusus. File cadangan disimpan pada LUN yang terpisah. Sejauh ini saya tidak melihat indikasi bahwa drive / file cadangan terpengaruh, sepertinya hanya drive data.
Mark S. Rasmussen
Cache tulis diaktifkan untuk semua LUN, pengaturan default di seluruh papan. Saya tidak berpikir itu terkait dengan cache karena bahkan NUL backup menunjukkan masalah - sehingga menghilangkan masalah penulisan. Untuk membaca, setiap pengontrol memiliki cache baca 2GB, plus memori pada host (yang memiliki PLE tak terbatas dengan banyak memori).
Mark S. Rasmussen

Jawaban:

14

Perhatikan bahwa semua server menggunakan NIC yang sama - Broadcom 5709Cs dengan driver terbaru. Server itu sendiri adalah milik Dell R610.

Kyle Brandt memiliki pendapat tentang kartu jaringan Broadcom yang menggemakan pengalaman saya sendiri (berulang).

Broadcom, Die Mutha

Masalah saya selalu dikaitkan dengan fitur TCP Offload dan dalam 99% kasus menonaktifkan atau beralih ke kartu jaringan lain telah menyelesaikan gejalanya. Satu klien yang (seperti dalam kasus Anda) menggunakan server Dell, selalu memesan Intel NIC terpisah dan menonaktifkan kartu Broadcom on-board yang sedang dibangun.

Seperti yang dijelaskan dalam posting blog MSDN ini , saya akan mulai dengan menonaktifkan di OS dengan:

netsh int ip set chimney DISABLED

IIRC mungkin perlu menonaktifkan fitur di tingkat driver kartu dalam beberapa keadaan, tentu tidak ada salahnya untuk melakukannya.

Mark Storey-Smith
sumber
4

Bukan berarti saya seorang ahli SAN / disk (ada orang-orang di sini yang tahu lebih banyak dari saya) ... Saya hanya membagikan apa yang telah saya lakukan sedikit dan kebanyakan membaca :)

Jonathan Kehayias dan Ted Krueger menulis sebuah buku "Mengatasi Masalah SQL Server" yang memiliki beberapa info bagus tentang kinerja disk. Anda bisa mendapatkan PDF gratis dari sini . (Saya mungkin membeli edisi cetak ini juga untuk meja saya.)

Lagi pula mereka memiliki permintaan yang baik yang dapat digunakan untuk memeriksa sys.dm_io_virtual_file_stats dan memeriksa latensi rata-rata pada file data Anda. Anda mungkin menemukan bahwa RAID10 bukan konfigurasi ideal untuk file data untuk tinggal.

Shawn Melton
sumber
Bahkan jika RAID10 bukan konfigurasi optimal, saya tidak bisa melihat itu menjadi masalah di sini. Praktis tidak ada aktivitas pada disk selama penggunaan normal, dan tingkat RAID yang salah tidak akan dapat menjelaskan permintaan IO lambat seperti ini. Seperti yang ditunjukkan oleh SQLIO, saya dapat menulis dengan 200MB / s + dan membaca dengan 100MB / s + dengan 2-4k IOPS - jadi ada banyak kapasitas. Saya telah memperbarui posting dengan hasil hasil permintaan dm_io_virtual_file_stats. Perhatikan bahwa gambar lebih besar jika Anda membukanya secara langsung.
Mark S. Rasmussen