Ayende @ Rahien

Hi!
My name is Oren Eini
Founder of Hibernating Rhinos LTD and RavenDB.
You can reach me by email or phone:

ayende@ayende.com

+972 52-548-6969

, @ Q j

Posts: 6,665 | Comments: 48,507

filter by tags archive

Optimizing Windsor

time to read 3 min | 431 words

Recently we got a bug report about the performance of Windsor when registering large number of components (thousands). I decided to sit down and investigate this, and found out something that was troublesome.

Internally, registering a component would trigger a check for all registered components that are waiting for a dependency. If you had a lot of components that were waiting for dependency, registering a new component degenerated to an O(N^2) operation, where N was the number of components with waiting dependencies.

Luckily, there was no real requirement for an O(N^2) operation, and I was able to change that to an O(N) operation.

Huge optimization win, right?

In numbers, we are talking about 9.2 seconds to register 500 components with no matching dependencies. After the optimization, we dropped that to 500 milliseconds. And when we are talking about larger number of components, this is still a problem.

After optimization, registering 5,000 components with no matching dependencies took 44.5 seconds. That is better than before (where no one has the patience to try and figure out the number), but I think we can improve up it.

The problem is that we are still paying that O(N) cost for each registration. Now, to suppose systems that already uses Windsor, we can’t really change the way Windsor handle registrations by default, so I came up with the following syntax, that safely change the way Windsor handles registration:

var kernel = new DefaultKernel();
using (kernel.OptimizeDependencyResolution())
{
for (int i = 0; i < 500; i++)
{
kernel.AddComponent("key" + i, typeof(string), typeof(string));
}
}

Using this method, registering 5,000 components drops down to 2.5 seconds.

I then spent additional time finding all the other nooks and crannies where optimizations hid, dropping the performance down to 1.4 seconds.

Now, I have to say that this is not linear performance improvement. Registering 20,000 components will take about 25 seconds. This is not a scenario that we worry over much about.

The best thing about the non linear curve is that for a 1,000 components, which is what we do care about, registration takes 240 milliseconds. Most applications don’t get to have a thousand components, anyway.

There are also other improvements made in the overall runtime performance of Windsor, but those would be very hard to notice outside of a tight loop.

Castle Windsor 2.0 RTM Released

time to read 2 min | 293 words

imageSome would say that it is about time, I would agree. Windsor might not be the OSS project in pre release state for the longest time (I think that the honor belong to Hurd), but it spent enough time at that state to at least deserve a honorary mention.

That was mostly because, although Windsor was production ready for the last three or four years or so, most of the people making use of it were happy to make use of the trunk version.

If you will look, you won’t find Windsor 1.0, only release candidates for 1.0. As I believe I mentioned, Windsor has been production ready for a long time, and for the full release we decided to skip the 1.0 designator, which doesn’t really fit, and go directly to 2.0

The last Windsor release (RC3) was almost a year and a half ago, and in the meantime, much has improved in Windsor land. Adding upon the already superb engine and facilities, we have fitted Windsor to the 3.5 release of the .Net framework, created a full fledged fluent API to support easy configuration, allowed more granular control over the behavior of the container when selecting components and handlers and improved overall performance.

All in all, pretty good stuff, even if I say so myself. Just to give you an idea, the list of changes from the previous release goes for quite a while, so I am going to let the short listing above to stand in its place.

You can get the new release from the source forge site.

Logging - the AOP way

time to read 3 min | 544 words

Logging is probably the most mentioned sweet spot of AOP. Probably because it is the simplest and most straightforward example most people can think of. I remember going over a piece of code that handles billions of transactions a day(that is for you, Jdn), and seeing something like this:

public void DoSomethingInteresting(string arg1, int arg2)
{
	LogGateway.Enter("DoSomethingInteresting", arg1, arg2);
	try
	{
		// actual method code 
		LogGateway.Success("DoSomethingInteresting", arg1, arg2);
	}
	catch(Exception e)
	{
		LogGateway.Error(e, "DoSomethingInteresting", arg1, arg2);
		throw e;
	}
	finally
	{
		LogGateway.Exit("DoSomethingInteresting", arg1, arg2);
	}
}

That was repeated for each and every method in the system. It was horrible.

I don't care how you do it, but there are at least 7 AOP approaches in the CLR, at least three of them are applicable in your environment.

I am going to show how to handle that with Windsor's AOP, but the same thing is applicable using other approaches. First, our service:

public interface ISmsSender
{
	int Send(string to, string msg);
}

public class SmsSender : ISmsSender
{
	public int Send(string to, string msg)
	{
		if(msg.Length>160)
			throw new ArgumentException("too long","msg");
		return to.Length;
	}
}

And now we need to define the interceptor:

public class LoggingInterceptor : IInterceptor
{
	public void Intercept(IInvocation invocation)
	{
		var logger = LogManager.GetLogger(invocation.TargetType);
		try
		{
			StringBuilder sb = null;
			if (logger.IsDebugEnabled)
			{
				sb = new StringBuilder(invocation.TargetType.FullName)
					.Append(".")
					.Append(invocation.Method)
					.Append("(");
				for (int i = 0; i < invocation.Arguments.Length; i++)
				{
					if (i > 0)
						sb.Append(", ");
					sb.Append(invocation.Arguments[i]);
				}
				sb.Append(")");
				logger.Debug(sb);
			}

			invocation.Proceed();
			if(logger.IsDebugEnabled)
			{
				
				logger.Debug("Result of " + sb + " is: " + invocation.ReturnValue);
			}
		}
		catch (Exception e)
		{
			logger.Error(e);
			throw;
		}
	}
}

The code is really simple, we get the logger instance ( in this case, from log4net ), check if logging is enabled and if so, write the method and parameters to the log. We then execute the code and log the return value as well.

If there was an error, we log that as well.

Here is my test code:

var container = new WindsorContainer()
	.Register(
		Component.For<LoggingInterceptor>(),
		Component.For<ISmsSender>().ImplementedBy<SmsSender>()
			.Interceptors(new InterceptorReference(typeof(LoggingInterceptor))).First
	);
BasicConfigurator.Configure(); // configure log4net
var sender = container.Resolve<ISmsSender>();
try
{
	sender.Send("ayende", "short");
	sender.Send("rahien", new string('q', 161));
}
catch (Exception)
{
	
}

And the output for that is:

241 [1] DEBUG ConsoleApplication9.SmsSender (null) - ConsoleApplication9.SmsSender.Int32 Send(System.String, System.String)(ayende, short)
272 [1] DEBUG ConsoleApplication9.SmsSender (null) - Result of ConsoleApplication9.SmsSender.Int32 Send(System.String, System.String)(ayende, short) is: 6
272 [1] DEBUG ConsoleApplication9.SmsSender (null) - ConsoleApplication9.SmsSender.Int32 Send(System.String, System.String)(rahien,
    qqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqq
    qqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqq
    qqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqqq)
273 [1] ERROR ConsoleApplication9.SmsSender (null) - System.ArgumentException: too long
Parameter name: msg
   at ConsoleApplication9.SmsSender.Send(String to, String msg) in C:\Users\ayende\Documents\Visual Studio 2008\Projects\ConsoleApplication9\ConsoleApplication9\ISmsSender.cs:line 15
   at ISmsSenderProxyb24fc36182fb434fa7f466d148259c48.InvocationSend_1.InvokeMethodOnTarget()
   at Castle.DynamicProxy.AbstractInvocation.Proceed() in e:\OSS\Castle\Tools\Castle.DynamicProxy2\Castle.DynamicProxy\AbstractInvocation.cs:line 140
   at ConsoleApplication9.LoggingInterceptor.Intercept(IInvocation invocation) in C:\Users\ayende\Documents\Visual Studio 2008\Projects\ConsoleApplication9\ConsoleApplication9\Program.cs:line 65

Simple, elegant, and doesn't clutter my code.

Integrating NHibernate and Active Record

time to read 1 min | 182 words

On the face of it, this is a nonsense post. What do I mean, integrating NHibernate and Active Record? Active Record is based on NHibernate, after all. What kind of integration you need? Well, sometimes you want to be able to use NHibernate entities in an Active Record project. And that tended to be very hard. (The other way was extremely easy, just tell Active Record to generate the mapping and move from there.)

A week or so ago I added support for doing it the other way around, of adding POCO NHibernate entities into the ActiveRecord model.

Here is the test:

[Test]
public void CanIntegrateNHibernateAndActiveRecord()
{
	ActiveRecordStarter.ModelsValidated += delegate
	{
		new ActiveRecordModelBuilder().CreateDummyModelFor(typeof(NHibernateClass));
	};
	ActiveRecordStarter.Initialize(
		GetConfigSource(),
		typeof(ActiveRecordClass),
		typeof(NHibernateClass));

	Recreate();

	using (TransactionScope tx = new TransactionScope())
	{
		ActiveRecordClass ar = new ActiveRecordClass();
		ar.Friend = new NHibernateClass();
		ActiveRecordMediator.Save(ar.Friend);
		ActiveRecordMediator.Save(ar);
		tx.VoteCommit();
	}

	using (TransactionScope tx = new TransactionScope())
	{
		ActiveRecordClass first = ActiveRecordMediator<ActiveRecordClass>.FindFirst();
		Assert.IsNotNull(first);
		Assert.IsNotNull(first.Friend);
	}
}

Note that I would reserve this to advance scenarios only, in most cases, it is recommended to only use a consistent approach.

Pain reduction: creating ductile tests

time to read 2 min | 310 words

Take a look at this test:

[Test]
public void When_asking_for_latest_webcast_will_not_consider_webcasts_published_in_the_future()
{
	var webcast = new Webcast { Name = "test", PublishDate = DateTime.Now.AddDays(-2) };
	With.Transaction(() => webcastRepository.Save(webcast));
	var webcast2 = new Webcast { Name = "test", PublishDate = DateTime.Now.AddDays(2) };
	With.Transaction(() => webcastRepository.Save(webcast2));
	Assert.AreEqual(webcast.Id, webcastRepository.GetLatest().Id);
}

It looks like a valid test, doesn't it? It has a huge problem. It is brittle.

I just added a new non null property, and all the tests broke. I started to add the new property value to the test, before I realize what I was doing. I run into a friction point, and I was trying to cover it with code. Next time I would add such a property, I would run into the same problem.

This is unacceptable.

The standard solution for this is to create a factory for this, or use an Object Mother. This was never something that I was fond of. I always need more flexibility than I can usually get from it, and I hate building builders, that is so boring.

Turn out, I can eat the cake and keep it.

I created the following test class:

[ActiveRecord("Webcasts")]
public class TestableWebcast : Webcast
{
	public TestabbleWebcast()
	{
		Name = "Test name";
		Description = "Test description";
	}
}

And now the test change to:

[Test]
public void When_asking_for_latest_webcast_will_not_consider_webcasts_published_in_the_future()
{
	var webcast = new TestableWebcast { PublishDate = DateTime.Now.AddDays(-2) };
	With.Transaction(() => webcastRepository.Save(webcast));
	var webcast2 = new TestableWebcast { PublishDate = DateTime.Now.AddDays(2) };
	With.Transaction(() => webcastRepository.Save(webcast2));
	Assert.AreEqual(webcast.Id, webcastRepository.GetLatest().Id);
}

I get to keep the nice object initializer syntax, and I even get more clarity, since I can now specify only the properties that I am actually interested in.

The only annoying thing is that I have to define the TestableWebcast as an entity as well, but I can live with it.

The test of fire: Rhino Mocks 3.5 in the real world

time to read 2 min | 329 words

imageI have been waiting on the release for Rhino Mocks 3.5, seeing what kind of feedback I can get from users. I also had another reason, I hadn't had the chance to really give it a good testing, in the only manner that matter, using it to develop production ready software.

Here is my latest test, which I am fairly pleased with.

[TestFixture]
public class WebcastControllerTest
{ 
	private WebcastController controller;
	private IRepository<Webcast> repositoryStub;
	private StubEngineContext engineContext;
	private IUnitOfWork unitOfWorkStub;
	private IDisposable disposeGlobalUnitOfWorkRegistration;

	[SetUp]
	public void Setup()
	{
		repositoryStub = MockRepository.GenerateStub<IRepository<Webcast>>();
		unitOfWorkStub = MockRepository.GenerateStub<IUnitOfWork>();
		controller = new WebcastController(repositoryStub)
		             	{
		             		ControllerContext = new ControllerContext{Name = "webcast"},
		             	};
		engineContext = new StubEngineContext();
		controller.SetEngineContext(engineContext);
		disposeGlobalUnitOfWorkRegistration = UnitOfWork.RegisterGlobalUnitOfWork(unitOfWorkStub);
	}

	[TearDown]
	public void TearDown()
	{
		disposeGlobalUnitOfWorkRegistration.Dispose();
	}

	[Test]
	public void When_index_called_will_send_existing_webcasts_to_view()
	{
		var webcasts = new List<Webcast>();
		repositoryStub.Stub(x => x.FindAll()).Return(webcasts);

		controller.Index();

		Assert.AreSame(webcasts, controller.PropertyBag["webcasts"]);
	}

	[Test]
	public void When_display_called_will_send_webcast_to_view()
	{
		var webcast = new Webcast();
		controller.Display(webcast);

		Assert.AreSame(webcast, controller.PropertyBag["webcast"]);
	}

	[Test]
	public void When_edit_called_with_webcast_will_send_webcast_to_view()
	{
		var webcast = new Webcast();
		controller.Edit(webcast);

		Assert.AreSame(webcast, controller.PropertyBag["webcast"]);
	}

	[Test]
	public void When_saving_invalid_webcast_will_redirect_to_edit()
	{
		var webcast = new Webcast();

		controller.Validator.IsValid(webcast);
		controller.PopulateValidatorErrorSummary(webcast, controller.Validator.GetErrorSummary(webcast));

		controller.Save(webcast);

		Assert.Contains(engineContext.MockResponse.RedirectedTo, "edit");
	}

	[Test]
	public void When_saving_invalid_webcast_will_flash_error_summary_and_webcast_in_flash()
	{
		var webcast = new Webcast();

		controller.Validator.IsValid(webcast);
		controller.PopulateValidatorErrorSummary(webcast, controller.Validator.GetErrorSummary(webcast));

		controller.Save(webcast);

		Assert.AreSame(webcast, controller.Flash["webcast"]);
		Assert.AreSame(controller.Validator.GetErrorSummary(webcast), controller.Flash["errorSummary"]);
	}

	[Test]
	public void When_saving_valid_webcast_will_redirect_to_display()
	{
		var webcast = new Webcast();

		// explicitly not calling validation, the controller will assume 
		// that this is a valid object

		controller.Save(webcast);

		Assert.Contains(engineContext.MockResponse.RedirectedTo, "display");
	}

	[Test]
	public void When_saving_valid_webcast_will_save_and_flash_unit_of_work()
	{
		var webcast = new Webcast();

		// explicitly not calling validation, the controller will assume 
		// that this is a valid object

		controller.Save(webcast);

		repositoryStub.AssertWasCalled(x=>x.Save(webcast));
		unitOfWorkStub.AssertWasCalled(x=>x.TransactionalFlush());
	}
}

Active Record: Mapping Rewriting

time to read 1 min | 191 words

One of the really nice things about using the NHibernate / Active Record stack is that there are so many extensions points.

One of the more fun things is the ability to do runtime modifications of the mapping. Here is a simple example:

ActiveRecordStarter.ModelsCreated+=delegate(ActiveRecordModelCollection models, IConfigurationSource source)
{
    foreach (ActiveRecordModel model in models)
    {
        if(model.Type == typeof(User))
        {
            model.ActiveRecordAtt.Table = "MyUsers";
        }
    }
};

Here we are re-writing the table that the User entity will go to. We can get much more complex, since we have all the knowledge of the structure of the code and can apply things like naming convention, validation, etc. It is also a fast way to translate between database/conventions.

NHibernate has a similar concept, INamingStrategy, which can be used to some of the same purposes, but I like this approach better, since it gives me more semantic information.

Castle Style Errors

time to read 2 min | 379 words

I had to compare different styles of error handling approaches, and I automatically compared the ideal, Castle Style errors, to the nasty, Mystery HRESUTL of the Week.

But what does Castle Style errors means?

Let us take a look at a few of them. When an module that was registered before the MonoRail http module had thrown an exception:

throw new Exception(
	"An exception happened on Global application or on a module that run before MonoRail's module. " + 
	"MonoRail will not be initialized and further requests are going to fail. " + 
	"Fix the cause of the error reported below.", context.Context.Error);

Or what happens when you are trying to access an ActiveRecord class when you didn't initialize it properly?

String.Format("An ActiveRecord class ({0}) was used but the framework seems not " +
   "properly initialized. Did you forget about ActiveRecordStarter.Initialize() ?",
   type.FullName);

And:

String.Format("You have accessed an ActiveRecord class that wasn't properly initialized. " +
   "The only explanation is that the call to ActiveRecordStarter.Initialize() didn't include {0} class",
   type.FullName);

The common theme for those errors is that they are:

  • Descriptive
  • Show all the relevant information
  • Suggest a probable solution
  • Save time

I added the following exception:

throw new ActiveRecordException(String.Format(
	"You can't use [Property] on {0}.{1} because {2} is an active record class, did you mean to use BelongTo?",
	model.Property.DeclaringType.Name, model.Property.Name, propertyType.FullName));

I added that after I spent half an hour trying to figure out why something was wrong. Since then, I keep running into this exception, and then it is a "slap on the head, replace [Property] with [BelongsTo] and move on". And that is me, who wrote this bloody annoying exception that I am supposed to already know and avoid triggering. I can't imagine how many hours this exception alone has saved, just for my team.

In fact, when I gave a talk at DevTeach about MonoRail, I have literally built the entire demo by just following the instructions from the exceptions.

That is good error handling, and that is what I consider as the standard that you should aspire to. Anything less than that is cause for anger, anxiety and angst. Do save yourself the ulcer, put in the best errors you can.

FUTURE POSTS

No future posts left, oh my!

RECENT SERIES

  1. RavenDB 4.1 features (11):
    04 Jul 2018 - This document is included in your subscription
  2. Codex KV (2):
    06 Jun 2018 - Properly generating the file
  3. I WILL have order (3):
    30 May 2018 - How Bleve sorts query results
  4. Inside RavenDB 4.0 (10):
    22 May 2018 - Book update
  5. RavenDB Security Report (5):
    06 Apr 2018 - Collision in Certificate Serial Numbers
View all series

Syndication

Main feed Feed Stats
Comments feed   Comments Feed Stats