{"id":4575,"date":"2015-12-03T12:20:10","date_gmt":"2015-12-03T20:20:10","guid":{"rendered":"http:\/\/3.209.169.194\/blogs\/paul\/?p=4575"},"modified":"2015-12-03T12:20:10","modified_gmt":"2015-12-03T20:20:10","slug":"data-recovery-investigating-weird-select-failures-around-corruption","status":"publish","type":"post","link":"https:\/\/www.sqlskills.com\/blogs\/paul\/data-recovery-investigating-weird-select-failures-around-corruption\/","title":{"rendered":"Data recovery: investigating weird SELECT failures around corruption"},"content":{"rendered":"

An interesting corruption problem cropped up on the MCM distribution list yesterday and after I figured it out, I thought it would make a good blog post in case anyone hits a similar problem.<\/p>\n

In a nutshell, the problem was corruption such that a simple SELECT *<\/em> query failed, but a SELECT *<\/em> query with an ORDER BY<\/em> clause worked.<\/p>\n

Let’s investigate!<\/p>\n

Creating the scenario<\/h2>\n

First I’ll create the specific corruption. I’m going to create a simple table with a clustered index, and sizing the rows so there’s only one per page.<\/p>\n

\r\nCREATE DATABASE [Company];\r\nGO\r\n\r\nUSE [Company];\r\nGO\r\n\r\nCREATE TABLE [test] (\r\n\t[c1] INT IDENTITY,\r\n\t[c2] UNIQUEIDENTIFIER DEFAULT NEWID (),\r\n\t[c3] CHAR (4100) DEFAULT 'a');\r\nGO\r\nCREATE CLUSTERED INDEX [test_cl] ON [test] ([c1], [c2]);\r\nGO\r\n\r\nSET NOCOUNT ON;\r\nGO\r\n\r\nINSERT INTO [test] DEFAULT VALUES;\r\nGO 10000\r\n<\/pre>\n
Now I’ll delete one of the rows, creating a page with a single ghost record on it, which I can see using DBCC PAGE<\/em> on the first PFS page in the database.<\/p>\n
\r\nDELETE FROM [test] WHERE [c1] = 150;\r\nGO\r\n\r\nDBCC TRACEON (3604);\r\nDBCC PAGE ([Company], 1, 1, 3);\r\nGO\r\n<\/pre>\n
\r\n<snip output for brevity>\r\n(1:289)      - (1:295)      =     ALLOCATED   0_PCT_FULL                     Mixed Ext\r\n(1:296)      - (1:437)      =     ALLOCATED   0_PCT_FULL                              \r\n(1:438)      -              =     ALLOCATED   0_PCT_FULL Has Ghost                    \r\n(1:439)      - (1:8087)     =     ALLOCATED   0_PCT_FULL                              \r\n<\/pre>\n
So page (1:438) is the one that had the row with key value 150 on it. It’s still allocated and linked into the clustered index structure though, so I’ll force the Access Methods code to ‘see’ it by doing a scan that’ll include it, and that will queue the page up for cleaning by the Ghost Cleanup Task.<\/p>\n
\r\nSELECT COUNT (*) FROM [test] WHERE [c1] &amp;lt; 200;\r\nGO\r\n<\/pre>\n
And now if I wait 10 seconds and look at the PFS page again, I can see it’s been cleaned and deallocated – it’s no longer part of the clustered index. (You’ll notice that the PFS byte still says that the page has a ghost record; that’s because when a page is deallocated, the only PFS bits that are changed are the allocation status.)<\/p>\n
\r\nDBCC PAGE ([Company], 1, 1, 3);\r\nGO\r\n<\/pre>\n
\r\n<snip output for brevity>\r\n(1:289)      - (1:295)      =     ALLOCATED   0_PCT_FULL                     Mixed Ext\r\n(1:296)      - (1:437)      =     ALLOCATED   0_PCT_FULL                              \r\n(1:438)      -              = NOT ALLOCATED   0_PCT_FULL Has Ghost                    \r\n(1:439)      - (1:8087)     =     ALLOCATED   0_PCT_FULL                              \r\n<\/pre>\n
Nothing’s corrupt at this point, so let’s cause some problems.<\/p>\n
Creating the corruption<\/h2>\n
First off I’m going to zero out page (1:438) using DBCC WRITEPAGE<\/em>:<\/p>\n
\r\nALTER DATABASE [Company] SET SINGLE_USER;\r\nGO\r\n\r\nDECLARE @offset INT;\r\nSELECT @offset = 0;\r\n\r\nWHILE (@offset < 8185)\r\nBEGIN\r\n\tDBCC WRITEPAGE (N'Company', 1, 438, @offset, 8, 0x0000000000000000, 1);\r\n\tSELECT @offset = @offset + 8;\r\nEND;\r\nGO\r\n\r\nALTER DATABASE [Company] SET MULTI_USER;\r\nGO\r\n<\/pre>\n
And there’s still no corruption here, because page (1:438) is a deallocated page.<\/p>\n
So now I’ll corrupt it by forcing it to be allocated again. For this I need to find the offset of the PFS byte for page (1:438) using a hex dump of the PFS page and looking for a page that has the PFS bits matching the PFS output for page (1:438) above. The page only has the ‘Has Ghost’ bit set, which is 0x08.<\/p>\n
\r\nDBCC PAGE ([Company], 1, 1, 2);\r\nGO\r\n<\/pre>\n
\r\n<snip>\r\nMemory Dump @0x00000000185EA000\r\n\r\n00000000185EA000:   010b0000 00000000 00000000 00000000 00000000  ....................\r\n00000000185EA014:   00000100 63000000 0200fc1f 01000000 01000000  ....c.....\u00fc.........\r\n00000000185EA028:   12010000 fd000000 01000000 00000000 00000000  ....\u00fd...............\r\n00000000185EA03C:   7944876a 01000000 00000000 00000000 00000000  yD\u0087j................\r\n00000000185EA050:   00000000 00000000 00000000 00000000 00009c1f  ..................\u009c.\r\n00000000185EA064:   44444444 00004444 60647060 74706070 60607060  DDDD..DD`dp`tp`p``p`\r\n00000000185EA078:   60707060 40404040 40404040 61706070 60606070  `pp`@@@@@@@@ap`p```p\r\n00000000185EA08C:   60706060 60706060 60706060 60606070 40404040  `p```p```p`````p@@@@\r\n00000000185EA0A0:   40404040 40404040 40404030 60706060 70607060  @@@@@@@@@@@0`p``p`p`\r\n00000000185EA0B4:   70706070 70606060 70607060 70607060 70607060  pp`pp```p`p`p`p`p`p`\r\n00000000185EA0C8:   70607060 70607060 70606060 60607060 60706070  p`p`p`p`p`````p``p`p\r\n00000000185EA0DC:   60706070 60706070 60707070 60607060 60706060  `p`p`p`p`ppp``p``p``\r\n00000000185EA0F0:   60706060 70606060 60606060 70607060 60706060  `p``p```````p`p``p``\r\n00000000185EA104:   60606060 60606060 40000000 00000000 60606060  ````````@.......````\r\n00000000185EA118:   60606060 60606060 60606060 60606060 60606060  ````````````````````\r\n00000000185EA12C:   40404040 40404040 40404040 40404040 40404040  @@@@@@@@@@@@@@@@@@@@\r\n00000000185EA140:   40404040 40404040 40404040 40404040 40404040  @@@@@@@@@@@@@@@@@@@@\r\n00000000185EA154:   60606060 64646260 40404040 40404040 40404040  ````ddb`@@@@@@@@@@@@\r\n00000000185EA168:   40404040 40400000 00000000 40400000 00000000  @@@@@@......@@......\r\n00000000185EA17C:   40404040 00000000 70606060 60606060 40404040  @@@@....p```````@@@@\r\n00000000185EA190:   40404040 40404040 40404040 40404040 40404040  @@@@@@@@@@@@@@@@@@@@\r\n00000000185EA1A4:   40404040 40404040 40404040 40404040 40404040  @@@@@@@@@@@@@@@@@@@@\r\n00000000185EA1B8:   40404040 40404040 40404040 40404040 40404040  @@@@@@@@@@@@@@@@@@@@\r\n00000000185EA1CC:   40404040 40404040 40404040 40404040 40404040  @@@@@@@@@@@@@@@@@@@@\r\n00000000185EA1E0:   40404040 40404040 40404040 40404040 40404040  @@@@@@@@@@@@@@@@@@@@\r\n00000000185EA1F4:   40404040 40404040 40404040 40404040 40404040  @@@@@@@@@@@@@@@@@@@@\r\n00000000185EA208:   40404040 40404040 40404040 40404040 40400840  @@@@@@@@@@@@@@@@@@.@\r\n00000000185EA21C:   40404040 40404040 40404040 40404040 40404040  @@@@@@@@@@@@@@@@@@@@\r\n00000000185EA230:   40404040 40404040 40404040 40404040 40404040  @@@@@@@@@@@@@@@@@@@@\r\n<snip>\r\n<\/pre>\n
Can you spot the 0x08 byte? It’s at offset 0x21a on the page.<\/p>\n
I can force page (1:438) to become allocated again by setting that byte offset in the PFS page to 0x40, again using DBCC WRITEPAGE<\/em>.<\/p>\n
\r\nDBCC WRITEPAGE (N'Company', 1, 1, 538, 1, 0x40);\r\nGO\r\n<\/pre>\n
And now if I run DBCC CHECKDB<\/em>, I can see some corruption:<\/p>\n
\r\nDBCC CHECKDB (N'Company') WITH NO_INFOMSGS;\r\nGO\r\n<\/pre>\n
\r\nMsg 8909, Level 16, State 1, Line 68\r\nTable error: Object ID 0, index ID -1, partition ID 0, alloc unit ID 0 (type Unknown), page ID (1:438) contains an incorrect page ID in its page header. The PageId in the page header = (0:0).\r\nCHECKDB found 0 allocation errors and 1 consistency errors not associated with any single object.\r\nMsg 8928, Level 16, State 1, Line 68\r\nObject ID 245575913, index ID 1, partition ID 72057594040614912, alloc unit ID 72057594045857792 (type In-row data): Page (1:438) could not be processed.  See other errors for details.\r\nCHECKDB found 0 allocation errors and 1 consistency errors in table 'test' (object ID 245575913).\r\nCHECKDB found 0 allocation errors and 2 consistency errors in database 'Company'.\r\nrepair_allow_data_loss is the minimum repair level for the errors found by DBCC CHECKDB (Company).\r\n<\/pre>\n
And the final step is to make the database read-only:<\/p>\n
\r\nALTER DATABASE [Company] SET READ_ONLY;\r\nGO\r\n<\/pre>\n
Investigating the corruption<\/h2>\n
In the case described in the DL, there was no backup and so the client wanted to extract as much data as possible.<\/p>\n
Running a simple SELECT *<\/em> didn’t work, like so:<\/p>\n
\r\nSELECT * FROM [test];\r\nGO\r\n<\/pre>\n
The query will start to give results and then fail with:<\/p>\n
\r\nMsg 824, Level 24, State 2, Line 74\r\nSQL Server detected a logical consistency-based I\/O error: incorrect pageid (expected 1:438; actual 0:0). It occurred during a read of page (1:438) in database ID 10 at offset 0x0000000036c000 in file 'C:\\Program Files\\Microsoft SQL Server\\MSSQL12.SQL2014\\MSSQL\\DATA\\Company.mdf'.  Additional messages in the SQL Server error log or system event log may provide more detail. This is a severe error condition that threatens database integrity and must be corrected immediately. Complete a full database consistency check (DBCC CHECKDB). This error can be caused by many factors; for more information, see SQL Server Books Online.\r\n<\/pre>\n
But if I run a SELECT * that has ordering, it works fine:<\/p>\n
\r\nSELECT * FROM [test] ORDER BY [c1];\r\nGO\r\n<\/pre>\n
What’s going on?<\/p>\n
Explanation<\/h2>\n
The explanation is to do with how the two scans work for the SELECT<\/em> statements.<\/p>\n
The first scan\u00a0is doing what’s called an allocation order scan<\/em>. This is where the Access Methods decides not to use the index structure to give back the records. An allocation order scan has three requirements:<\/p>\n