I generally advise to keep the IoC container out of the tests, but sometimes it is a convenient tool to have. Take for example the auto-mocking container concept. It's just too useful so I make an exception to the previous rule sometimes.
Here's another use for a container in a test: a profiler. All IoC containers have some proxying abilities (or rather, they delegate to one of the proxying libraries), which can be leveraged to build a basic profiler. A profiler is especially useful in integration tests where there's something that's taking too much time but you can't put your finger on the culprit simply because there are too many components involved.
A real-world example: an application which uses SolrNet was taking too long when getting lots of documents from Solr. There was nothing weird in Solr's log so it was a client issue. Let's profile it!
Setting up the profiler
We create a ProfilingContainer and add all the components we want to profile:
IWindsorContainer container = new ProfilingContainer();
container.AddComponent<ISolrDocumentResponseParser<Document>, SolrDocumentResponseParser<Document>>();
container.AddComponent<ISolrResponseParser<Document>, ResultsResponseParser<Document>>("resultsParser");
container.AddComponent<IReadOnlyMappingManager, AttributesMappingManager>();
container.Register(Component.For<ISolrQueryResultParser<Document>>().ImplementedBy<SolrQueryResultParser<Document>>()
.ServiceOverrides(ServiceOverride.ForKey("parsers").Eq(new[] { "resultsParser" })));
container.AddComponent<ISolrFieldParser, DefaultFieldParser>();
container.AddComponent<ISolrDocumentPropertyVisitor, DefaultDocumentVisitor>();
Adding code to profile
We add the code that exercises the components:
var parser = container.Resolve<ISolrQueryResultParser<Document>>();
for (int i = 0; i < 1000; i++) {
parser.Parse(responseXMLWithArrays);
}
Getting the actual profile data
Finally, we get the profile data:
Node<KeyValuePair<MethodInfo, TimeSpan>> rawProfile = container.GetProfile();
This returns a tree of method calls, each with its logged duration. We just want a list of aggregated durations, so first we flatten the tree:
IEnumerable<KeyValuePair<MethodInfo, TimeSpan>> profile = Flatten(rawProfile);
And now we can query and write the profile:
var q = from n in profile
group n.Value by n.Key into x
let kv = new { method = x.Key, count = x.Count(), total = x.Sum(t => t.TotalMilliseconds)}
orderby kv.total descending
select kv;
foreach (var i in q)
Console.WriteLine("{0} {1}: {2} executions, {3}ms", i.method.DeclaringType, i.method, i.count, i.total);
Which prints something like this (prettified):
| Method |
Executions |
Total own time |
| AttributesMappingManager.GetFields(Type) |
21000 |
2803.23ms |
| DefaultDocumentVisitor.Visit(Object, String, XmlNode) |
10000 |
432.19ms |
| DefaultFieldParser.Parse(XmlNode, Type) |
10000 |
122.77ms |
| SolrQueryResultParser<Document>.Parse(String) |
1000 |
93.52ms |
| DefaultFieldParser.CanHandleType(Type) |
10000 |
44.71ms |
| SolrDocumentResponseParser<Document>.ParseResults(XmlNode) |
1000 |
43.11ms |
| ResultsResponseParser<Document>.Parse(XmlDocument, SolrQueryResults<Document>) |
1000 |
30.28ms |
| DefaultFieldParser.CanHandleSolrType(String) |
10000 |
23.78ms |
Analyzing the profile
Well, it's obvious that AttributesMappingManager.GetFields() is to be blamed here, it's taking a lot of time... which is only logical since it uses a lot of reflection...
But wait a minute, I already thought about that when I wrote that MemoizingMappingManager (which is a memoizer decorator for the AttributesMappingManager)... only I forgot to add it to the container!
Fixing and re-running the profile
After adding the MemoizingMappingManager, the profile comes out like this:
| Method |
Executions |
Total own time |
| DefaultDocumentVisitor.Visit(Object, String, XmlNode) |
10000 |
358.64ms |
| SolrQueryResultParser<Document>.Parse(String) |
1000 |
166.64ms |
| DefaultFieldParser.Parse(XmlNode, Type) |
10000 |
87.13ms |
| MemoizingMappingManager.GetFields(Type) |
21000 |
50.5ms |
| DefaultFieldParser.CanHandleType(Type) |
10000 |
42.03ms |
| SolrDocumentResponseParser<Document>.ParseResults(XmlNode) |
1000 |
34.93ms |
| ResultsResponseParser<Document>.Parse(XmlDocument, SolrQueryResults<Document>) |
1000 |
30.83ms |
| DefaultFieldParser.CanHandleSolrType(String) |
10000 |
22.22ms |
| AttributesMappingManager.GetFields(Type) |
1 |
19.82ms |
Conclusion
This cheap profiler has a number of caveats:
- Since it works by adding a DynamicProxy interceptor to everything, it can only profile interceptable classes and methods managed by Windsor.
- Times should be taken with a grain of salt. Based on a couple of unscientific tests, it can introduce an error of 10ms (on my machine), rendering a 10ms measured time useless. I'd only use these times for a qualitative comparison. There's a reason why there's a specific .Net profiling API.
- Multithreading: each thread will get its own interceptor, so each thread gets its own profile.
- What I just described is not really a test. There is nothing asserted, it can't pass or fail. The "test" here is just a means to run the profile. It should be [Ignore]d.
All in all, I found this to be quite useful. ProfilingContainer is just a thin wrapper around WindsorContainer that adds a ProfilerFacility, which in turn sets up a ProfilingInterceptor. So you could, for example, add the ProfilingInterceptor to your application container with a per-web-request lifestyle and code a HttpModule to profile an entire http request.
Code is here. Sample profile shown in this post is here.
