Day at the Office: Performance

I am working on a ticket where I have to augment data returned from an external system with some local overrides, without adversely affecting performance.  

Running the screen, it seemed a bit tardy to begin with.   So I pulled out one of the tools I love to use: a profiler.

I use the Ants Performance Profiler.  I paid for it with part of my Christmas bonus.  While I am a salaried employee, and my employer provides me with lots of stuff (awesome computer, pop, snacks, coffee, ReSharper, MSDN), there are additional things that I choose to use because I like who I am with them.  These include Ants, TeamViewer, nDepend, Beyond Compare, Fences, and VmWare, and a 3rd monitor.  Not all are paid for yet – two more christmas bonuses should cover it.

image

Well, that’s interesting.   Curiosity strikes:  What are those spikey areas about?  What’s going on?   How long is the initial query taking?  How long are the webservice calls taking?   If I add on to the end of the webservice call, how much would that grow?

Spike #1 – Query + Initial Screen Draw

Action: highlight the area and see where the time was spent.  If you’ve never seen this before, there’s some Windows GUI app running stuff to get out of the way:

image
image

  • The green highlights in the top image are times when the method under the cursor was fired. 
  • The stack trace is not so scary once you understand the internals of a running program a bit.
    • “A” is the part of the program which receives almost any kind of “this work needs to be done asynchronously” call.   This means Execute.OnUIThread(),  drawing events, bindings, etc – almost all get serviced here. 
    • “B” is where Task.Factory.Start() things get serviced.
    • “C” is any point where input needed to be handled, and ended up making the app do something.  Mouse movement, hover, clicks, etc – and part of whatever they ended up triggering.  That is what is highlighted in green
    • “D” we haven’t drilled into yet.
  • Unfortunately, if you Async a call from A to B, they show up in different parts of the performance stack traces (at least as of Ants version 7)

Drilling further into “D”:

image
image

  • Ah, I’ve seen this before.   “Measuring” usually means a grid has been set to “auto fit columns” mode – and as its drawing things, its figuring out how large they want to draw, how much to resize, and then redrawing.  

What about the actual query to get the data?   I found it way down in here (this time in bottom-up mode):

image
image

Wow, that was a lot of blurring.   Point being:  the query is fast, rendering the results in the grid is slow.

There’s another blog post that could be written here.  The stack trace above goes from “Get me stuff” to a IQueryable to a Project to … What, a Stored procedure?   Yep, it does, and it went from 25 seconds down to 2 seconds.  Sometimes, EF does not win.  

Spike #2: The Flat Plains of Update

imageimage

  • This is the result of getting “new information” from the external service, and trying to update the grid. 
  • What you are seeing is the NotifyOfPropertyUpdate() => saying “hey, UI, update yourself”  .. and waiting for the update to happen.   
  • -update- after a day of dinking around in this code, its simply a size issue.  There are 15000 rows of data in the grid – and we are updating every single one, with 4 columns of new data – and each each update “paints” itself on the screen.    This takes a while.   I couldn’t find any way to optimize this other than delaying the entire screen till we have all the data (ie, don’t paint twice).

Lets Try To Remove AutoFit: After Changes

before:

image

after removing AutoFit:

image

Not very different. 

image

Welcome to performance optimization.   Sometimes, you think you have found a smoking gun, but you haven’t.  I might have squeezed a 10% out of that, maybe.

I must now leave this blog post and really fix some things.   And get on with the original task, which was to add some local database overrides to an external web service call without making the system significantly slower.

-update- Its now the end of the day, and I have the additional lookup code written.  Here’s the impact:

image

  • The green highlight is the call to the external web service(s) (async) and the subsequent updating of the columns in the grid.
  • The pink/purple is the additional code that I wrote that patches up values from the local database.

Good enough. 

Tagged with:
Posted in Code

Leave a Reply

Fill in your details below or click an icon to log in:

WordPress.com Logo

You are commenting using your WordPress.com account. Log Out / Change )

Twitter picture

You are commenting using your Twitter account. Log Out / Change )

Facebook photo

You are commenting using your Facebook account. Log Out / Change )

Google+ photo

You are commenting using your Google+ account. Log Out / Change )

Connecting to %s

Categories
Tags
.net 3d 3d-printing 4k abc15 algorithms ames android anonymous types asp.net audio editing aws backup basecamp beatunes biorhythm bittorrent blender blog boston marathon bpm c# caffeine campfire candycrush car carmax charity chiropractor cities-skylines clog clone codelouisville codepalousa coding coffee collaboration color run ComputerElbow ComputerVision configuration consulting cooking crash course crashplan crestwood cycling dabda dan dapper DataSet ddl diabetes dictation dotnetcore dotnetmud downtown e-cycling elite excel exercise expiration facebook feature-branching firefall flipflops Flow FL Studio focus food forecastle fortresscraft franklinplanner gadgets game-design games git github google docs google maps gopro gps grandpa greenshot hack half marathon headless health heart rate hiren ignew integration testing interop inventory ios ipad itunes javascript jobs karma kdf keyboards keys kittens lamont laptop lavalamp lego life lifehack linq linqtotwitter linux los angeles louisville mandelbulber massage therapy mastery-teaching maths merge metformin Minecraft miniature modeling monitor mud muhammad ali institute music mvc mycartracks netfabb nexus10 node nostalgia nutrition nwipe oldham county grand slam opal openjscad openscad owin pacedj paper mockup pepakura performance photoscan politics pomodoro postgresql powershell premiere prius process product-management project-management qa resharper review rmi roman road 5k RSI rubiks running samsung 700t sandals schedule scooter scribblelive selenium service shapeways sleep slic3r sneakersync snot software software-engineering solidoodle soylent spacegame speaking sql sqlite SSDT SSIS standing state-machine stayfocusd stonehearth sunset tablet teaching team teamcity teamtreehouse terraform testing tfs time timelapse torque touch tracks trs80 Tuple tutor twitter ubuntu unit testing utilities video video editing visual studio vscode vsvim warp stabilizer windows 8 windows home server wordpress wpf xml
Archives
%d bloggers like this: