views:

60

answers:

2

I have a query that has appropriate indexes and is shown in the query plan with an estimated subtree cost of circa 1.5. The plan shows an Index Seek, followed by Key Lookup - which is fine for a query expected to return 1 row from a set of between 5 and 20 rows (i.e. the Index Seek should find between 5 and 20 rows, and after 5 - 20 Key Lookups, we should return 1 row).

When run interactively, the query returns almost immediately. However, DB traces this morning show runtimes from live (a web app) that vary wildly; typically the query is taking < 100 DB Reads, and effectively 0 runtime... but we are getting a few runs that consume > 170,000 DB Reads, and runtime up to 60s (greater than our timeout value).

What could explain this variation in disk reads? I have tried comparing queries interactively and using Actual Execution plans from two parallel runs with filter values taken from fast and slow runs, but interactively these show effectively no difference in the plan used.

I also tried to identify other queries that could be locking this one, but I am not sure that would impact the DB Reads so much... and in any event this query tended to be the worst for runtime in my trace logs.

Update: Here's a sample of the plan produced when the query is run interactively:

alt text

Please ignore the 'missing index' text. It is true that changes to the current indexes could allow a faster query with fewer lookups, but that is not the issue here (there are already appropriate indexes). This is an Actual Execution Plan, where we see figures like Actual Number of Rows. For example, on the Index Seek, the Actual number of rows is 16, and the I/O cost is 0.003. The I/O cost is the same on the Key Lookup.

Update 2: The results from the trace for this query are:

exec sp_executesql N'select [...column list removed...] from ApplicationStatus where ApplicationGUID = @ApplicationGUID and ApplicationStatusCode = @ApplicationStatusCode;',N'@ApplicationGUID uniqueidentifier,@ApplicationStatusCode bigint',@ApplicationGUID='ECEC33BC-3984-4DA4-A445-C43639BF7853',@ApplicationStatusCode=10

The query is constructed using the Gentle.Framework SqlBuilder class, which builds parameterised queries like this:

SqlBuilder sb = new SqlBuilder(StatementType.Select, typeof(ApplicationStatus));
sb.AddConstraint(Operator.Equals, "ApplicationGUID", guid);
sb.AddConstraint(Operator.Equals, "ApplicationStatusCode", 10);
SqlStatement stmt = sb.GetStatement(true);
IList apps = ObjectFactory.GetCollection(typeof(ApplicationStatus), stmt.Execute());
+1  A: 

Could the data be being removed from the cache? That may be an explanation why with a hot cache (data already in memory), the reads recorded are very low....and then when the data is no longer in RAM, the reads would increase as it has to read it off disk again.

Just one idea to get things moving.

AdaTheDev
@AdaTheDev: I don't think so; my understanding was that profiling would show logical disk reads even if they were retrieved from the cache. Not something I am certain of, however.
Nij
+1  A: 

Run profiler to see if statistics are being updated around the same time. Or simply to see what else is going.

Also, please add the SQL query as well the client code.

Thoughts:

  • It sounds like your "5-20" rows could be far more than that
  • With a bad plan/parameter sniffing you'd get consistently bad performance
  • How may writes happen on this table: enough to update statistics?
  • Is there some datatype issue? (eg concatenating parameters and introducing a datatype conversion)
gbn
@gbn: Statistics on the indexs involved were updated about 3 days ago as far as I can see (we have a job that forces it). I have added a screenshot of the query plan (when run interactively). I don't believe that there is a datatype issue. This is a table which has records added to it (on an identity PK) frequently... I will need to do some research under what circumstances this could force update statistics and if that would show under a query's reads.
Nij
@Nij: The plan is obviously OK (well, could be covered) and doesn't help here... it's the SQL code and client code that would be useful.
gbn
@gbn: The query is shown on the screen-shot above near the top. I'm not 100% on what you mean when you say client code, but if you mean something like C# source code, I am not sure how that would impact DB reads?
Nij
@Nij: iz's how you parameterise the SQL query that interests me
gbn
@gbn: Another update for you above. I don't think we are doing anything particularly unusual with the code side; however because of the (very old) ORM we use; Gentle.Framework, we have no real choice on how this query gets submitted.
Nij
@Nij: What datatype is @ApplicationStatusCode in the table please?
gbn