Archive for November, 2009|Monthly archive page

Switching to NLog

My application has about 165,000 lines of code, and I have been using log4net for all my logging needs.  However, for a client application that I’m working on I wondered if Log4Net was the best choice.  After doing some research and experimentation I decided it wasn’t.  Instead, NLog wins the new title, and it only took 1 hour to switch my entire 165,000 lines of code over to NLog.

Benefits of NLog over Log4Net:

  • Signs of life!  Log4Net doesn’t seem to be active any more – certainly there hasn’t been a release in ages.
  • Logging methods that accept format strings and parameters.
    This later is why switching to NLog took so long: I was able to go through my code (using VS2008 & searching across the entire solution) and remove all the irritating string concatenation, replacing them with format strings and parameters.  This means that if a logging level is turned off, the string concatenation will never occur!

So instead of:

log.Debug(“Some message ” + pieceOfData + ” and ” + someOtherData );

which ALWAYS results in 3 string concatenations even if debug logging is disabled, I can now do:

log.Debug(“Some message {0} and {1}”,pieceOfData,someOtherData );

which ONLY does a string concatenation if the debugging is enabled.

  • Automatic configuration – just start-up your application and go
  • More powerful configuration!
    Their configuration has LOTS of very cool marcos (which they call Layout Renderers).  This allowed me to eliminate a huge pile of messy C# log4net configuration code (complete with nasty casting to internal classes – which apparently is the “documented” approach) just to configure the output file to go into the user’s AppData local folder.Eliminiating C# code for a single easy-to-understand line of configuration is good!

So instead of all of this:

/// <summary>
/// Setup Log4Net and create a file appender so that it logs to a writable location!
/// (even in Vista where the "Program files" folder is read-only.
/// </summary>
private static void SetupLog4Net( string dataPath ) {
	// Configure Log4Net with the properties from the app.config file
	log4net.Config.XmlConfigurator.Configure();

	// Create the file appender and setup basic options
	var fileAppender = new log4net.Appender.RollingFileAppender();
	fileAppender.AppendToFile = false;
	fileAppender.RollingStyle = log4net.Appender.RollingFileAppender.RollingMode.Once;
	fileAppender.MaxSizeRollBackups = 4;	// The number of log files to keep around
	fileAppender.MaximumFileSize = "10MB";

	// Use an almost standard layout pattern
	const string layout = "%date  %-5level  Thread:[%-23thread]  %logger - %message%newline";
	fileAppender.Layout = new log4net.Layout.PatternLayout(layout);

	// Log data to the location application data directory because it's pretty
        // much guaranteed we can write there.
	string logFilePath = CurrentLogFilePath(dataPath);
	fileAppender.File = logFilePath;

	//Notify the appender on the configuration changes
	fileAppender.ActivateOptions();

	// Get the root logger (bit of a hack, but seems "standard") and add the file appender
	var repository =  LogManager.GetRepository() as log4net.Repository.Hierarchy.Hierarchy;
	if( repository==null ) throw new Exception("Failed to get the log4net hierarchy repository.");
	log4net.Repository.Hierarchy.Logger root = repository.Root;
	root.AddAppender(fileAppender);

	// Very important: Mark the repository as configured and notify it that is has changed
	repository.Configured = true;
	repository.RaiseConfigurationChanged(EventArgs.Empty);
}

I now have this one line of configuration code in the XML configuration file:

fileName=”${specialfolder:folder=LocalApplicationData}\MyApp\MyApp.${shortdate}.log”

That is FANTASTIC!

  • NLog is also supported by Gibraltar!  (Which I WISH I owned…)

The only down side is that padding doesn’t always work, so laying out the log file for easier reading is not there yet (from the NLog blog):

…the use of “padding” attribute on layout renderers. If you used it in v1 you may have found
that it did not work for all renderers (depending on their implementation)

Apparently this is fixed in version 2, but I don’t know when that will be available.

Somebody has also already written an article about NLog and PostSharp which is cool because it means “free” logging.

I also can’t get it to do rolling log files every time the application starts up.  I’ve posted a question on the NLog forum here.

Robert

Things I have found to be true #1

A life lesson that I learned the hard way is this:

If I’m right about something it should easily to convince somebody of my point of view.

Now, “easy” might mean doing some research and writing up a small Word document if it’s a professional disagreement at work.   It almost certainly means understanding the other person’s context:  their point of view, their understanding of the way things work and ought to work, and the constraints they have to work within and why those constraints are there (and if they  can possibly be removed, often with creative thinking or brining somebody else into the discussion and repeating this process).

For example, I had a disagreement with boss  about something.  Before I tried to convince them I was right, I first asked lots of questions to understand why he thought he was right.  I didn’t know the constraints the boss was working under, but I knew that their boss and the boss’s boss were often dogmatic about technology, and I respected the boss as a very intelligent person that always tried to make the best decisions (yes, it was great working with this gentleman!)  So I worked hard to understand his constraints.

Mountain boyOnce I understood his context, I realized two things:  1. his understanding of the technologies in question was slightly incorrect (he is after-all the boss and slightly removed the technology after 20 years in management) and 2.  he was rightly concerned about alignment with strategic technology direction, a few other projects that were doing something similar, larger scale, security initiates  and how my suggested technology would worth within those constraints, etc.  With that deeper understanding of the problem and solution criteria I did some research, wrote up a small Word document that outlined at a high level how two technologies worked, the pros and cons of both approaches and presented a summary evaluation of both technologies against a more complete set of criteria than I had originally been aware of.  In the end we almost always chose the right technology.

This actually happened about 20 times in the 4 years that I had the pleasure of working with this gentleman, and sometimes the technology I had suggested was the better choice, and sometimes once I understood everything better my original thinking was wrong.  Thus, this life lesson has an inescapable and important corollary:

If, after correctly understanding the complete problem, understanding all the solution criteria and understanding any other constraints, my original point of view may be wrong.  However, that’s okay because we can now choose the right solution together.

And a few times, my original thinking was right, but artificial, capricious and immutable constraints defined by the boss’s boss’s boss (etc) meant that we couldn’t do the right thing, so we chose the best thing we could under the circumstances.

PS.  The dogma clause

Obviously sometimes the constraints the other person is working within are their own personal dogma, and therefore absolutely preclude any ability to change their mind regardless of any amount of evidence.  Hopefully (and usually?) this is not the case in a professional setting like work.  I therefore cast out such situations as obviously not applicable to a professional discussion like this one is pretending to be.  I also make it a rule to try my best to avoid issues with people whose personal dogma on the issue overrides evidence.  However, it does happen even at work (as it the case with the boss’s boss’s boss etc above).  I have found the best solution in such situations is to politely say that you’ll have to agree to disagree, then do what they are asking while looking for another job…

Failed to deserialize change-set. Operation is not valid due to the current state of the object.

I’ve had a long disucssion with myself over on the MSDN forums here:
http://forums.silverlight.net/forums/p/140254/313870.aspx#313870

I’ve reproduced it here:

I’ve written a domain service that allows basic CRUD operations for a person’s “Contacts”.  Lots and lots of unit tests run just fine against the server side code, and the Silverlight client can download all the contacts I put into the database using a SQL script and display them very nicely.

Unfortunately, I can’t create a new contact from the Silverlight side.  In the submit operation’s completed event handler I get the error message:

{System.Windows.Ria.Data.EntityOperationException:
Failed to deserialize change-set. Operation is not valid due to the current state of the object.
at System.Windows.Ria.Data.HttpDomainClient.GetRequestResult(HttpDomainClientAsyncResult httpAsyncResult)
at System.Windows.Ria.Data.HttpDomainClient.EndSubmitCore(IAsyncResult asyncResult)
at System.Windows.Ria.Data.DomainClient.EndSubmit(IAsyncResult asyncResult)
at System.Windows.Ria.Data.DomainContext.CompleteSubmitChanges(IAsyncResult asyncResult)}

However,  in the submit operation completed event handler submitOp.EntitiesInError.Count()=0.  Thus, it doesn’t seem to be my new contact instance object that’s the problem.

I’ve overriden all the methods in the domain service adding try/catch blocks (or at least a breakpoint) and just calling base.whatever()  the only method that seems to be called is the Initialize(DomainServiceContext context) method, which completes normally.  The insert method of the domain service is definitely not called:

[Insert]
 public void AddContact( ContactDto newContact ) {
    Contract.Requires(GetCurrentUserId()!=null, "The request must be authenticated");
    Contract.Requires(newContact!=null, "The contact to add must not be null");
    Contract.Requires(newContact.Id==0, "All new contacts must have a zero ID");
    Contract.Ensures(newContact.Id!=0, "The contact's ID should not be zero after adding it to the database");
    System.Diagnostics.Trace.WriteLine("*** SERVER *** AddContact( "+ newContact + " )");
    var userID = GetCurrentUserId();
    this.UnitOfWork.SaveContact(userID, newContact);
 }

The JSON that is passed to the server is:

[{"Entity":{"__type":"Contact:#MyApplication.DataAccessLayer.Contracts.Data",
"Archived":null,
 "Category":null,
 "Company":"ABC inc",
 "DataVersion":null,
 "DateCreated":"\/Date(-621355788000000500)\/",
 "DateModified":null,
 "DateViewed":null,
 "FirstName":"Robert",
 "HomeAddressId":null,
 "Id":0,
 "LastName":"McCarter",
 "Notes":null,
 "NotificationFrequency":null,
 "OwnerId":0,
"SpouseFirstName":null,
 "SpouseLastName":null,
 "WorkAddressId":null},
"Id":0,
 "Operation":1,
 "OperationData":null,
 "OperationName":null}]

So, in a separate solution I started from scratch and created a new Silverlight  .NET RIA Services project. I copied the definition of the DTO contact class into this new project.  I can easily create new instances of the DTO contact class in the new project.   Then I copied my simplified GUI in to the original project and it doesn’t work, I get the same error as above.  Then I copied my simplified domain service to the original project and it STILL doesn’t work, I get the same error.

The contact DTO class was being automatically generated by my ORM tool, and was being annotated by that tool as follows:

[System.Runtime.Serialization.DataContract(Name="Contact")]
public partial class ContactDto : BaseEntityDto {
....
}

When I had previously copied the DTO code to my simplified experimentation project I had not copied the attributes.  The moment I copied the attributes it stopped working.  Changing the name of the data contract to match the name of the class fixes the problem.

Notice that this is actually visible in the original JSON:

    Contact:#MyApplication.DataAccessLayer.Contracts.Data

this should have been

    ContactDto:#MyApplication.DataAccessLayer.Contracts.Data

I don’t know WCF so I don’t fully understand what this name is actually doing, although according to the MSDN documentation (http://msdn.microsoft.com/en-us/library/system.runtime.serialization.datacontractattribute.aspx) the default value is the name of the class.

Is it possible that this is a bug in .NET RIA Services, where RIA Services is assuming the data contract name is the same as the class name even when it doesn’t have to be?

Update:

I’ve asked Mindscape if LightSpeed could be modified to make this work:
http://www.mindscape.co.nz/forums/Post.aspx?ThreadID=2507&PostID=7399

 

 

Binding WPF to Dynamic Objects in the ViewModel tier

http://msdn.microsoft.com/en-us/library/bb613588%28VS.100%29.aspx#binding

WPF supports data binding to objects that implement IDynamicMetaObjectProvider.
For example, if you create a dynamic object that inherits from DynamicObject in code,
you can use markup extension to bind to the object in XAML.

This is very cool, and should dramatically simplify the creation of the ViewModel tier!  I’ll blog about this more later