Thursday 1 May 2014

Logging isn't always free

No matter how fancy the interface / facade on top of it looks, a remote procedure call is still a remote procedure call.

I'm currently working on a performance and maintainability improvement project at work: we have a system that has substantial technical debt and it's going into production in a few months. It has been a hard slog but things are starting to look better!

Earlier in the week we ran into an interesting problem: one of our leads had done a great job of improving performance by caching some entities which were constantly pulling out of the database (sometimes a page load as pulling the same row out of the database tens to hundreds of times). We could see that pages were loading faster when running on our local development machines.

I deployed the web app to a standalone webserver and loaded up the app... and it started chugging along.. really slowly...

It turned out that the extra caching was doing a lot of extra logging. Our logger sends data out to a few sinks and one of them was a remote procedure call based system. This RPC was taking about 100msec to complete, and it was running synchronously! Filtering down the amount of logging sent to that sink resulted in the app picking up its pace again.

Fallacies of Distributed Computing - why do you haunt me so often!

No comments:

Post a Comment