Why would an index seek show high scan count in statistics?

Question

Without going into too much detail, i have a query producing an execution plan using all clustered and non-clustered index seeks (sounds promising). Unfortunately the query is performing poorly and i'm struggling to understand why.

I'm using set statistics io on and can see that one of the tables is producing a lot of scans and logical/physical reads:

SET statistics io ON

go

    SELECT order_number,
           audit_id,
           orderadmission_net_paid_delta / 100.00,
           'Admission',
           orderadmission_net_paid_delta / 100.00,
           performance_gl_description1,
           section_data1,
           performance_gl_code,
           price_type_data1,
           year(performance_start_date),
           month(performance_start_date),
           paymentmethod_type,
           paymentmethod_name,
           ''
    FROM   JCRProdReplication.dbo.ts_audit WITH (NOLOCK)
           JOIN JCRProdReplication.dbo.ts_order_admission WITH (NOLOCK)
             ON orderadmission_audit_id = audit_id
           LEFT JOIN JCRProdReplication.dbo.ts_order WITH (NOLOCK)
             ON order_id = orderadmission_order_id
           LEFT JOIN JCRProdReplication.dbo.ts_performance WITH (NOLOCK)
             ON performance_id = orderadmission_performance_id
           LEFT JOIN JCRProdReplication.dbo.ts_seat WITH (NOLOCK)
             ON seat_id = orderadmission_seat_id
           LEFT JOIN JCRProdReplication.dbo.ts_section WITH (NOLOCK)
             ON section_id = seat_section_id
           LEFT JOIN JCRProdReplication.dbo.ts_price_type WITH (NOLOCK)
             ON price_type_id = orderadmission_price_type_id
           LEFT JOIN JCRProdReplication.dbo.ts_order_payment WITH (NOLOCK)
             ON orderpayment_audit_id = audit_id
           LEFT JOIN JCRProdReplication.dbo.ts_payment_method WITH (NOLOCK)
             ON paymentmethod_id = orderpayment_paymentmethod_id
    WHERE  audit_time >= '20140107'
           AND audit_time < '20140108' 

---

(72174 row(s) affected)
Table 'ts_payment_method'. Scan count 0, logical reads 4180, physical reads 1, read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.
Table 'ts_price_type'. Scan count 0, logical reads 4184, physical reads 26, read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.
Table 'ts_section'. Scan count 0, logical reads 4184, physical reads 28, read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.
Table 'ts_seat'. Scan count 0, logical reads 6276, physical reads 2240, read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.
Table 'ts_performance'. Scan count 0, logical reads 4184, physical reads 50, read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.
Table 'ts_order'. Scan count 0, logical reads 8368, physical reads 820, read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.
Table 'ts_order_admission'. Scan count 71877, logical reads 288490, physical reads 44104, read-ahead reads 0, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.
Table 'ts_audit'. Scan count 1, logical reads 252, physical reads 5, read-ahead reads 246, lob logical reads 0, lob physical reads 0, lob read-ahead reads 0.

What would be my next step in understanding why an index seek would actual show lots of scans/reads in statistics? (i've been googling all day and not found an explanation).

Answer 1

The scan count reported by STATISTICS IO may well not be what you think.

Example

USE tempdb;
SET NOCOUNT ON;

CREATE TABLE Num1 (N INT PRIMARY KEY);

CREATE TABLE Num2 (N INT);
CREATE CLUSTERED INDEX IX ON Num2(N);

INSERT INTO Num1
OUTPUT      inserted.N
INTO Num2
SELECT number
FROM   master..spt_values
WHERE  type = 'P'
       AND number BETWEEN 1 AND 1000

SET STATISTICS IO ON;

SELECT *, sys.fn_PhysLocFormatter(N2.%%physloc%%)
FROM   Num1 N1
       INNER LOOP JOIN Num2 N2
         ON N1.N = N2.N

SET STATISTICS IO OFF;

DROP TABLE Num1, Num2

Gives plan

And output

Table 'Num2'. Scan count 1000, logical reads 2002
Table 'Num1'. Scan count 1, logical reads 3

Despite the plan showing a seek 1000 scans are reported.

Because the index is not declared as unique each seek is a partial scan. The index is seeked into the number 1,000 times then on each seek it needs to scan the index until it finds the first row not matching the number.

The Num2.IX index has a single root page and two leaf pages.

The 2,002 logical reads breaks down as follows.

Most of the seeks take two reads (single root page and single leaf page). Two of the seeks (for numbers 622 and 623 in my case) took three logical reads as they read both leaf pages.

These were the last row on the first leaf page and first on the second page respectively.

For number 622 it needs to read the next row on the next page to see if that is a duplicate. For number 623 the explanation is that the index is structured as follows.

The root page has the lowest value that is possibly contained on each lower page. As the index is not declared as unique it needs to check the previous page too in case there are multiple matching rows spanning the page boundary.

The following blog posts have some additional explanation about interpreting STATISTICS IO output.

• Scan Count meaning in SET STATISTICS IO output: Part 1
• Scan Count meaning in SET STATISTICS IO output: Part 2