how to tell how long it took a query to run?

jamesmanning

in both LINQPad 4 and 5, I will often run a query (C# Expression) and see while it's running the timer going to show how long it's taking so far. Even when the query takes well over 30 seconds, once it completes the status bar says something like "Query successful (00:00.073)". I'm not sure which part of the process the 73 milliseconds is from, but outside of adding my own Stopwatch at the top and bottom, is there a way to tell how long the query took to run?

Is this a LINQPad bug and the time shown after 'Query successful' should have been the full runtime?

Thanks!

JoeAlbahari

Does the query have a database connection?

jamesmanning

yeah, this was querying against a large table with millions of rows and a table scan required, using the LINQPad-generated context like normal.

I've got a query that does 3 levels of sort and then a Take(100) and takes between 16 to 20 seconds to run consistently (even if re-running it just after running it)

What I'm seeing is:

- if the query only writes to the Output window (doing doing the 16 second query but adding .Count() instead of writing out the rows), then the time listed in the status bar is accurate
- if the query writes to the html / rich text output, then the time list is accurate
- if the query writes to the data grid output, even though the query still takes the same 16 to 20 seconds to run, the status bar lists a time well below one second

version v5.02.03(AnyCPU)

kingkeith

I have also experienced this, but without a DataContext, so I don't think that is the problem. In fact, I have noticed that the timer is correct until the query finishes, then it reports the wrong "total" time... As per James' findings, it only seems to occur when writing results to data grids.

Edit: I can reproduce with the following C# statements query, although it takes a couple of seconds to complete, it shows "Query successful (00:00.000)" for me:

DateTime since = DateTime.Now.AddDays(-7);

EventLog.GetEventLogs().Single(el => el.Log == "Application").Entries.OfType()
.Where(e => e.TimeGenerated > since)
//.Take(1000)
.Dump();

nescafe

Isn't this related to this previous comment from Joe:
http://forum.linqpad.net/discussion/comment/1819/#Comment_1819

In other words, the enumeration of the datagrid is deferred to another thread / process and therefore the query has finished earlier.

Can be omitted by adding a .ToArray() to force data retrieval in the query process:

DateTime since = DateTime.Now.AddDays(-7);

EventLog.GetEventLogs().Single(el => el.Log == "Application").Entries.OfType<EventLogEntry>()
.Where(e => e.TimeGenerated > since)
//.Take(2000)
.ToArray() // <-- This
.Dump();

kingkeith

@nescafe, you're absolutely right - well spotted