4

I have an app that is run as a service in production, but we do some manual testing with a simple GUI - practically nothing going on in it, it's just a wrapper with a textbox for input.

I recently changed my database schema and updated my mappings to match, and then the GUI suddenly worked very slowly on a trivial case. After some logging and running it multiple times, it turned out the new bottleneck was this query:

public void Refresh()
{
  using (var session = _sessionFactory.OpenSession()) 
  {
      _allFields = session.Query<FieldDefinition>().ToList();
  }
}

Repeatedly, it was taking 1:08 minutes for that one method (even though there's only about 300 FieldDefinitions in the database). By this time I was tired of manually re-running the GUI, so I wrote a unit test that exercised the exact same case - but I couldn't reproduce the slowdown.

My test called the same top-level object that the GUI does with the same input. I would expect this to run in nearly identical amounts of time. But when run in Visual Studio with MSTest, that same query was taking less than two seconds. That's 1/30th the time. It was doing the exact same work, just significantly faster.

Things I checked to see if I could make them run the same:

  • Both approaches produced the same number of SQL statements.
  • It doesn't seem to be caused by the JITter (multiple runs of the GUI without restarting it, same time results over and over)
  • Isolating it so that it used a brand new ISessionFactory for each Refresh had no effect
  • Turning off logging (log4net) had no effect

Changing the query to eager-load a child did work... kind of: After applying the fix, the WinForms app is only as fast as the unit test already was. The speed of the unit test did not significantly change (tenths of a second).

The old query was causing a select n+1 issue: but the issue was present in both the Winform and MSTest runs. Only the WinForm app saw a significant slowdown because of it.

How can I explain this? Why would only the WinForm app suffer a massive slowdown during a Select N+1 query?

Paul Phillips
  • 6,093
  • 24
  • 34

1 Answers1

0

I'd say profile it, then you'll know.

Wout
  • 624
  • 5
  • 14
  • Since I actually fixed the slowdown, and this is for work, I don't have a lot of license to spend time investigating this. I was hoping there was some conceptual subtlety I had missed, and that I wouldn't have to dig through the time and details of doing a proper profiling. – Paul Phillips Jun 22 '12 at 15:37