Bir Restore neden uzun sürer?

Merhabalar,

Bu aralar işler biraz yoğunlaştı, o nedenle bir şeyler paylaşmaya ara vermek durumunda kaldım. Yine de boşa çıkmış değilim; ama ne kadar ara verdiğimi görünce dayanamadım, daha dün yaşadığım bir olayı sizlerle de paylaşmak istedim.

Dün bir ortamda bazı veritabanlarını Restore etmem gerekti, kritik bir test durumu söz konusu olduğu için işlemi özellikle benim yapmam gerekti. Birkaç veritabanını Restore ettikten sonra, bazı veritabanlarının Restore işleminin ilginç bir şekilde duraksadığını, geciktiğini gözlemledim. Kuşkulandım ve ilk etapta sys.dm_exec_requests DMV'sini kullanarak işlemleri inceledim, birkaç Restore işleminin "percent_complete" alanındaki değer 100 idi, ama yine de işlemler bir türlü tamamlanmıyordu. Belki, herhangi bir garip nedenden dolayı SQL Server Management Studio'nun (SSMS) azizliklerinden biri olabilir diye düşündüm, SSMS'i kapattım açtım, sorun yine devam ediyordu. Sonra SQL Server Database Engine Service'ini kapatıp açtım, sonra sunucuyu komple kapattım açtım (test sunucusu) ve sorunun yine devam ettiğini gözlemledim.

En klasik sorun çözme yöntemlerinden olan kapat aç da işe yaramayınca artık daha derinlemesine bir araştırma şart olmuştu. Bunun için öncelikle 3004 ve 3605 Trace Flag'lerini aşağıdaki komut ile etkinleştirdim.

DBCC TRACEON (3004, 3605, -1)

Bu Trace Flag'ler ile Restore işleminin daha fazla kayıt üretmesini ve bu kayıtların da Error Log'a yazılmasını sağlamış oldum.

Ardından Error Log'ta aşağıdaki gibi kayıtlar gördüm:

SQL Server Error Log

Yukarıdaki ekran görüntüsünden de görüldüğü gibi bekleme anı Transaction Log dosyasının içerisinin sıfırlarla doldurulma anı. Bu anı Performance Monitor kullanarak ilgili sayaçlarla da izledim. Ayrıca Restore komutunu Script ile çalıştırdığım için aşağıdaki mesajı da görebildim ve not ettim:

Processed 857872 pages for database 'veritabanı_adı', file 'dosya_adı' on file 1.

Processed 2 pages for database 'veritabanı_adı', file 'dosya_adı_log' on file 1.

RESTORE DATABASE successfully processed 857874 pages in 528.709 seconds (12.676 MB/sec).

İşlem 529 saniyede ve saniyede sadece 12,6MB veri işleyerek tamamlanabilmişti. Bu gerçekten çok düşük bir değer, hele ki bu sunucudaki disklerden beklenen performans ile karşılaştırıldığında...

Aynı testi halihazırda üretim ortamında çalışan bir makinede denedim ve sonuç aşağıdaki gibi oldu:

Processed 857872 pages for database 'veritabanı_adı', file 'dosya_adı' on file 1.

Processed 2 pages for database 'veritabanı_adı', file 'dosya_adı_log' on file 1.

RESTORE DATABASE successfully processed 857874 pages in 48.744 seconds (137.496 MB/sec).

Gördüğünüz gibi işlenen sayfa sayısı aynı (857874), fakat üretim ortamındaki sunucuda aynı işlem 48,7 saniyede tamamlandı ve saniyede 137,5MB veri işleyerek. Bununla birlikte, bu işlemi üretim ortamındaki sunucuda da Performance Monitor ile izlemiştim ve veri yazma kapasitesi test sunucusundakine göre 6 kat daha hızlıydı.

Anlayacağınız, bu çalışmayla veritabanlarını Restore ederken aslında disk performans testi de yapmış olduk. Restore işlemlerinizi yaparken bir gariplik görürseniz görmezden gelmeyin, geçişten sonra başınız çok ağrıyabilir…

Kolay gelsin,
Ekrem Önsoy