2

Maybe this isn't appropriate for here, but I'll post and someone can suggest somewhere else.. sorry for so many characters....

We've had the same database go SUSPECT twice this week, (and I'd really love to go on vacation tomorrow!) It's happened on the SAME process, .. even at approx. the SAME time, and DBCC completes just fine once it's restored. - SQL Server 2008 R2 (SP2) - 700GB db. - SAME Query (MERGE from staging table) - SAME Wait Type timeout of PAGELATCH_EX (buffer latch - exclusive)

I've been looking at this all week - I am not sure where to go. The query is full scanning 2.5 years worth of data to update 3 days. It could use a WHERE clause to limit the content covered, but read you don't want to do that in a MERGE. On a good day, this load typically finishes at 7:30am, but stats weren't being gathered until 7:00pm, so I moved the job to 8:30am.

At the time of the failure, the query was waiting with “PAGELATCH_EX”. It waited for exactly 5:00 minutes (6:35am – 6:40am), then timed out.

After that, SQL Server flagged an inconsistency and attempted to undo. They’re using TF610, which I read is for bulk/minimally logged operation. It couldn’t recover, then experienced logical corruption and we opted to restore for time constraints (vs DBCC rebuild w/loss).

I'm still rather new to role, so I'm looking for a smoking gun and failing to find it. The other DBA here suggested increasing the RAM on the server. I've engaged our Storage Admin, who says he sees nothing unusual. Anyone have suggestions?

What we've done so far:

1. Grew the max memory to 50GB (from 28GB - bringing app inline with Vendor specs)

2. Grew the free space of the datafiles by (30GB) each (to encompass the full 3 year dataset and try to avoid datafile growth on the fly)

3. Patched instance to SP3

Here's a snip of the log:

============================================

At 6:34am: DBCC TRACEON 610, server process ID (SPID) 51. This is an informational message only; no user action is required. (The idea is that when you insert a large amount of data, you don't want to create a lot of transaction log – but can cause issues – thus traceflag notification.)

At 6:40am: A time-out occurred while waiting for buffer latch -- type 4, bp 00000003B2FE9440, page 5:14263304, stat 0xc8800b, database id: 6, allocation unit Id: 72057947483930624, task 0x0000000005C13288 : 0, waittime 300, flags 0x100000001a, owning task 0x0000000005C13288. Not continuing to wait.

At 6:40am: ex_raise2: Exception raised, major=52, minor=43, state=4, severity=22, attempting to create symptom dump

At: 6:40am: An inconsistency was detected during an internal operation. Please contact technical support.

At 6:40am: During undoing of a logged operation in database 'DAX_BI', an error occurred at log record ID (2375509:95987:341). Typically, the specific failure is logged previously as an error in the Windows Event Log service. Restore the database or file from a backup, or repair the database.

At 6:43am: Database DAX_BI was shutdown due to error 5243 in routine 'XdesRMReadWrite::RollbackToLsn'. Restart for non-snapshot databases will be attempted after all connections to the database are aborted.

At 6:43am: The log for database 'DAX_BI' is not available. Check the event log for related error messages. Resolve any errors and restart the database.

At 6:43am: During undoing of a logged operation in database 'DAX_BI', an error occurred at log record ID (2375509:96089:161). Typically, the specific failure is logged previously as an error in the Windows Event Log service. Restore the database or file from a backup, or repair the database.

At 6:43am: The log for database 'DAX_BI' is not available. Check the event log for related error messages. Resolve any errors and restart the database.

At 6:43am: During undoing of a logged operation in database 'DAX_BI', an error occurred at log record ID (2375505:16336:11). Typically, the specific failure is logged previously as an error in the Windows Event Log service. Restore the database or file from a backup, or repair the database.

At 6:43am: Starting up database 'DAX_BI'.

At 6:43am: Recovery of database 'DAX_BI' (6) is 0% complete (approximately 728 seconds remain). Phase 2 of 3. This is an informational message only. No user action is required.

At 6:43am: Recovery of database 'DAX_BI' (6) is 0% complete (approximately 425 seconds remain). Phase 2 of 3. This is an informational message only. No user action is required.

At 6:43am: Recovery of database 'DAX_BI' (6) is 0% complete (approximately 425 seconds remain). Phase 3 of 3. This is an informational message only. No user action is required.

At 6:47am: An error occurred during recovery, preventing the database 'DAX_BI' (database ID 6) from restarting. Diagnose the recovery errors and fix them, or restore from a known good backup. If errors are not corrected or expected, contact Technical Support.

============================================

  • 1
    Out of interest, have you tried the same process without the trace flag to see if you get the same error? – Nic Jun 16 '17 at 18:13
  • No, we haven't. It's vendor code, so I'm limited on what I can test. I can certainly make suggestions though. This is in production, and we're not seeing it in test. – sammieSQL Jun 16 '17 at 18:58
0

Have you checked the windows logs to see if anything else is happening around the samt time? That could possibly lead you in a direction to perform further investigation.

Also check the agent (or any other scheduler which might be involved) if a job is running at the time of the event which may cause some strange behaviour.

Do you have any antivirus software running on the server? (you should then try to exclude database-files).

Also it might actually be a bug in the SP/CU you're running for the SQL Server, is it possible for you to update to latest SP/CU?

  • We did check the Windows logs, and found nothing except for MSSQL related problems. We also have Cylance running on the server, which we didn't realize until this morning. We suspected a bug, and we should be able to update to the last SP. (Only saw 2 fixes listed within it). – sammieSQL Jun 16 '17 at 18:24
  • Try disabling and updating and see if that helps. Would be interesting to know if that solves your problem. – Pontus Jun 17 '17 at 6:12
  • Btw, are you running physical or virtual? If virtual also check if a snapshot might be taken at the time when this happens. (Could of course also be vss snapshot if running physical) – Pontus Jun 17 '17 at 16:30

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service, privacy policy and cookie policy

Not the answer you're looking for? Browse other questions tagged or ask your own question.