Πρόσφατα, σε ένα παραγωγικό περιβάλλον εμφανίστηκε ένα πρόβλημα με μεγάλης διάρκειας PAGEIOLATCH_EX latches, σε έναν μεγάλου μεγέθους πίνακα, τα οποία τελικά προκαλούσαν αδυναμία εκτέλεσης CRUD operations πάνω σε αυτόν.

Ψάχνοντας τα αίτια του προβλήματος, ξεκινήσαμε από την sp_who2 για να βρούμε το session το οποίο προκαλούσε το blocking και στην συνέχεια να βρούμε το προβληματικό transaction.

Αυτό όμως που τελικά διαπιστώσαμε, ήταν ότι δεν υπήρχαν blocked sessions αλλά υπήρχε ένα DB STARTUP command το οποίο εκτελούνταν στην βάση.

Status      Login    BlkBy  DBName    Command          CPUTime DiskIO
-----------------------------------------------------------------------
BACKGROUND  sa       .      NULL      LOG WRITER       31      0
BACKGROUND  sa       .      NULL      RECOVERY WRITER  0       0
BACKGROUND  sa       .      NULL      LAZY WRITER      0       0
BACKGROUND  sa       .      NULL      LOCK MONITOR     0       0
BACKGROUND  sa       .      master    DB STARTUP       46      400
BACKGROUND  sa       .      master    BRKR TASK        0       0
sleeping    sa       .      master    TASK MANAGER     0       0
BACKGROUND  sa       .      master    TRACE QUEUE TASK 0       0
BACKGROUND  sa       .      master    CHECKPOINT       0       0
BACKGROUND  sa       .      NULL      UNKNOWN TOKEN    0       0
BACKGROUND  sa       .      master    BRKR TASK        0       40
BACKGROUND  sa       .      master    BRKR TASK        0       0
BACKGROUND  sa       .      master    BRKR TASK        16      55
BACKGROUND  sa       .      master    BRKR TASK        15      168
BACKGROUND  sa       .      DBXXX     DB STARTUP       3478    55777

Το DB STARTUP command είναι αυτό που εκτελείται από τον SQL Server κατά το recovery μίας database από το log.

Επίσης, εκτελώντας ένα read uncommitted count(*) στον πίνακα που είχε το πρόβλημα, διαπιστώθηκε πως ο αριθμός των εγγραφών του αυξανόταν συνεχώς. Εκεί η αιτία του πρόβληματος, καθώς και η επίλυσή του έγιναν ξεκάθαρες  και το μόνο που χρειάστηκε ήταν η επικοινωνία με τον πελάτη για να επιβεβαιωθεί.

Αυτό που συνέβη ήταν το εξής:

Στα πλαίσια ενός datafix, ανοίχτηκε ένα transaction για το deletion 20 εκατομμυρίων  records από τον πίνακα. Κατά την διάρκεια του transaction υπήρξε power outage και έγινε restart το service του SQL Server. Επειδή το transaction του deletion ΔΕΝ είχε γίνει commit, ο SQL Server μέσω του DB Startup command και του database log έκανε rollback τα deletion των records ώστε να επαναφέρει σε συνεπή μορφή τον πίνακα!

Τελικά, η λύση του προβλήματος ήταν εξίσου απλή με την αιτία που το προκάλεσε. Δόθηκε η οδηγία, να περιμένουν να τελειώσει το recovery του πίνακα. Όντως, μετά από 2 περίπου ώρες η διαδικασία ολοκληρώθηκε και ο πίνακας είχε επανέλθει στην πρότερη μορφή του.

ACID rocks!