Alois Kraus

Enterprise Library 4 Released - And It Is Fast!

Alois Kraus — Wed, 21 May 2008 00:07:03 GMT

In case you have not noticed the Patterns & Practices Team has released the greatest and latest version of the Enterprise Library. More info's can be found at Grigory Melniks blog.

What’s New in v4.0?

This release of Enterprise Library includes the following:

– Integration with the Unity Application Block

– Windows Management Instrumentation (WMI) 2.0 support and improved instrumentation

– Performance improvements (particularly, in the Logging Application Block)

– Pluggable Cache Managers

– Visual Studio 2008 support

– Bug fixes

Unity looks cool but I was not able to see any noticeable startup performance gain. The usage of dynamic code generation (Build Plans) to invoke ctors and properties seems not to pay off when we create from each type only one or two instances. WMI looks nice but you need this stuff only if your architecture does not have central configuration mechanism. Alternatively you could use a custom configuration source which gets its configuration from somewhere else (WCF?) quite easily. The Visual Studio 2008 integration is (of course) seamless as expected. One really cool thing is buried in the performance improvements section where the Logging Application Block has got some attention. As noted in my previous article Really Fast Formatting With Enterprise Library there are massive performance gains possible by doing some intelligent preprocessing of the TextFormatter templates and getting into a more functional style of programming. The formatting performance of the new Enterprise Library is >10 times better. It seems that these improvements were not on the original road map (the March CTP did not contain any improvements in this area) but my proposal was taken and implemented.

I did try to extend the improved TextFormatter but did give up soon because this portion of the Enterprise Library plays a little closed source here and does not let me override the formatting of any existing token. Fortunately a little copy & paste did solve this issue quite nicely (not the best pattern of code reuse but it works). By applying the new formatting method via delegates I was able to get performance gains over a factor 2 in logging throughput which helps scalability a lot. Come and get it and see it for yourself.

Enterprise Library 4 CTP - Improvements/Logging Application Block

Alois Kraus — Thu, 10 Apr 2008 01:20:17 GMT

The Enterprise Library 4 CTP and the feature list can be found at the Codeplex Home page.

General Features of Entlib 4 (Excerpt from Release Notes)

· Enterprise Library 4.0 takes advantage of the improved features in the .NET WMI 2.0 API to provide update capability for configuration exposed through the Manageable Configuration Source. Objects defined in the Enterprise Library configuration, such as databases, trace listeners, and cache backing stores, are exposed through WMI as a set of classes that you can query and update. Providing that you have the relevant Windows permission to update WMI values, any changes you make to the properties of these classes are reflected back through the Manageable Configuration Source and update the configuration information exposed to your application. Changes do not affect the original configuration file contents and may be overridden by Group Policy.

· In version 4.0, Enterprise Library has the Allow Partially-Trusted Caller attribute (APTCA) on all assemblies. This means that you can call the methods of Enterprise Library and the application blocks from an application running in a partial trust environment. You can do this with the signed assemblies provided with Enterprise Library. There is no longer any requirement, as there was in version 3.x, to recompile the source code and the source code for Object Builder then either use the unsigned binaries or strong-name them yourself.

That is good news for all medium trust ASP.NET web developers and Active Directory administrators that want to have an easy way to configure the application blocks in a central way.

New Logging Application Features (Excerpt from Release Notes)

· The application block now allows you to specify a value for the Filter property of each of the Trace Listeners. This property applies a filter that selects the level of message that it will detect. The valid values are All, Off, Critical, Error, Warning, Information, Verbose, and Activity Tracing. The setting effectively means "the specified level and everything more important." For example, the Warning setting will detect warnings, errors, and critical events. The default is All, which means that the behavior of the listener is the same as in previous versions of Enterprise Library if a value is not specified in the configuration.

· The application block now allows you to specify that the RollingFlatFileTraceListener will start a new file at midnight every day. To use this behavior, set the value of the RollInterval property of the RollingFlatFileTraceListener to Midnight.

· The application block contains performance improvements that include the following:

◦ Delayed gathering of context information until actually requested (except in distributed scenarios where context information is gathered even if not used).

◦ Automatic flushing is now configurable. However, the default is to flush always, which means that the behavior of the listener is the same as in previous versions of Enterprise Library if a value is not specified in the configuration. To disable automatic flushing, set the AutoFlush property of the Log Source to True. It is then your responsibility to ensure that all entries are flushed to the target, especially if an exception or failure occurs in the application. Otherwise, you will lose any cached logging information not yet written to the target.

· Log file names now support the use of environment variables. You can include environment variables such as %WINDIR%, %TEMP%, and %USERPROFILE% in the Filename property of the Flat File Trace Listener, Rolling Flat File Trace Listener, and XML Trace Listener.

The application block implements several new performance counters that you can use to monitor performance and operations. The new counters are Total Logging Events Raised, Total Trace Listener Entries Written, and Total Trace Operations Started.

First Impressions

The startup performance improvements with Unity (which is already released) are not done yet but I hope that this will help to make the usage of the application blocks nearly invisible. The new dependency injection mechanism which uses reflection like ObjectBuilder (slow) but uses dynamically generated IL code to call the actual constructors/getter/setter methods. That increases the object creation performance dramatically. I hope that this will make a noticeable difference in a real world application.

After doing a quick diff I found some improvements in the Logging Application Block. They do mainly concern the configuration via WMI and group policies with ADM templates. That enables to query and deploy logging configuration via an Active Directory without changing a physical file on the target machines. That is a nice feature but I have to yet to see if that does work in all scenarios. Low privileged users do not always have full WMI access which could hinder the usage of the new feature in low trust environments.

Writing to a log file seems to be very easy but it did take over three years (Jan. 2005 was the first release) to support environment variables in file names. The delivered code quality was always very good but why on earth did it take so long? Working agile with a very strict timeline does enable the P&P team to deliver top features on time but low priority features such as this one have been dropped. That is no problem since the community did deliver very quickly the missing features such as the Rolling File Trace Listener from Erwyn van der Meer which is in my opinion still the one of the cleanest implementations of a Rolling File Trace Listener. What I really miss is a backflow of great community extensions to the Enterprise Library main code base.

A really nifty feature of the new Rolling File Trace Listener is the roll interval Midnight to enable to start a new log file at every day. Although one should not expect a roll over exactly at midnight since the roll over is only performed when the next log call arrives after the time span has elapsed.

Logging Application Block Performance

The creation of LogEntry objects has become dramatically faster since the current values are only read when needed. That is good but not perfect (yet). The main observations I did make

LogEntry: Process Id, Process Name and AppDomain Name will never change during the lifetime of an application. They could be read only once and copied from static variables to the actual instance variables on demand.
LogEntry: The native and managed thread id is fetched on demand which could be too late if the output destination does asynchronous operations (queuing?).
Formatters: There is no progress in the text formatter performance. That is surprising to say the least since delayed LogEntry variable expansion does not help much if you use a TextFormatter with the default template to format your LogEntry. I whish so much I could check out the sources for TextFormatter ....

The Good/The Whishes/The Summary for Entlib 4

Good:

Many new features (central configuration, unity integration, ...)
Performance Improvements

Wishes

High quality community extensions should be included in the main code base.
Do NOT Authenticode sign the strong named binaries again. I really hate the 15s startup delays of non Internet connected machines! Yes I know with .NET 3.5 there is a way to turn Authenticode verification off in the App.config file but .NET 2.0 users will suffer from this.
Do include the pdb's for Release and Debug for all shipped binaries (ObjectBuilder too).

The next release of the Enterprise Library does deliver cool features such as Unity and support for group policy based configuration. Finally the Patterns & Practices team has found the time to fix some minor quirks which have been annoying but not mission critical. Since the new release seems to be API compatible with the previous versions you should definitely consider to upgrade as soon as possible. Have a look at the blog of Grigori Melnik for latest announcements about the upcoming release of Entlib 4.

Try/Finally Pattern - Take a different path when an exception has occurred.

Alois Kraus — Tue, 08 Apr 2008 23:37:42 GMT

Error handling is a difficult beast. And there is always one more way to do it. Thottam Sriram did write some nice examples what main cases you usually have to deal with. The most ugly case is the one where you cannot handle an exception but you need to do different cleanup logic in a finally block.

public void Func()

        {
            bool cleanup = true;
 
            try
            {
                OtherFunc();
                cleanup = false;
            }
            catch (Exception)
            {
                // perform Cleanup on error
            }
            finally
            {
                if (cleanup)
                {
                    // perform cleanup on error
                }
            }
        }
 

The necessity to keep a state variable for a corner case does complicate the code quite a lot. You can get around that by knowing that .NET exceptions just wrap SEH (Structured Exception Handling) of Windows. The CLR does make extensive usage of SEH which you can read in the wonderful article from Chris Brumme. To sum it up in a few words if an exception is thrown an Exception Pointers structure is allocated. The actual exception processing is done two in two steps.

Ask all exception handlers what about the current error can be done. If one says it can fix it the exception processing is stopped. No exception will ever happen.
If no handler could fix it in the first pass they are actually invoked one by one and the stack unwinding does start.

C++ has special keywords for SEH named __try/__except/__leave which cannot be mixed with the regular try/finally C++ keywords within one function because only one exception handling chain within a function does make sense. Now you could ask how that complicated stuff can make by error handling easier? Well since we know that during an exception unwind scenario for the executing thread an Exception Pointers structure must exist we can check for its existence and we can distinguish the non exception case from the other. The BCL gives us direct access to this precious information via Marshal.GetExceptionPointers. Armed with that knowledge we can create a simple helper class that returns true if we are in an exception unwind case.

    public static class ExceptionHelper
    {
        /// <summary>
        /// Check if we are in a exception unwind scenario or not.
        /// </summary>
        public static bool InException
        {
            get 
            {   // Errata: The red marked code seems to be necessary. Since unit tests with .NET 2.0 
                // have shown that only checking for the Exception Pointers structure does not always work.
                return Marshal.GetExceptionPointers() == IntPtr.Zero &&
                       Marshal.GetExceptionCode() == 0 ? false : true;
            }
        }
    }

The code from above becomes now

        public void ImprovedFunc()
        {
            try
            {
                OtherFunc();
            }
            finally
            {
                if (ExceptionHelper.InException)
                {
                    // perform cleanup on error
                }
                else
                {
                    // Do normal cleanup in non exception case
                }
            }
        }
 

We did get rid of the catch clause and the state variable. That little trick can make your life easier in some situations. You can call the check property not only in a finally clause but also from a helper function because the Exception Pointers structure is thread local and visible as long exception processing is going on.

Remarks

At CLR IL (Intermediate Language) level there is the fault keyword which is similar. It acts like a finally block that is only executed when an exception has occurred. Besides the fact that C# does not support it is not really something that I would want. When an error happens I must execute nearly the same cleanup actions as in the non exceptional case. For that reason code sharing within one code block is essential to prevent code duplication both handlers. If you try to be smart and use the goto keyword (yes I won't dare to use it if it would have worked) to jump from a from a catch handler into the finally handler to skip a portion of the cleanup code you will get a compile error.

Since we have got our hands on the Exception Pointers structure we should be able to find there some reference to the managed exception and perhaps even return it. I tried that and failed. By looking at the Rotor source code I could not find evidence that this structure does contain any hints to the managed exception object. It looks like that the managed Thread implementation has it stored somewhere but since CLR objects are a mixture of IL code and C++ classes it is not feasible to use a simple fixed offset and cast it to the managed exception object.

If somebody has more info about that I am always interested to learn more ...

Really Fast Formatting with Enterprise Library

Alois Kraus — Tue, 15 Jan 2008 00:18:46 GMT

One of the action points for Enterprise Library 4 is to improve the performance of the TextFormatter. I like performance problems and found some interesting results I would like to share here. TextFormatter does take a template where the placeholders are expanded for every log message. The template does look like this

Timestamp: {timestamp}
Message: {message}
Category: {category}
Priority: {priority}
EventId: {eventid}
Severity: {severity}
Title:{title}
Machine: {machine}
Application Domain: {appDomain}
Process Id: {processId}
Process Name: {processName}
Win32 Thread Id: {win32ThreadId}
Thread Name: {threadName}
Extended Properties: {dictionary({key} - {value}
)}

TextFormatter does use StringBuilder to create from the template a mutable string and does then call StringBuilder.Replace for each token it could contain. It does basically a String.IndexOf to find if something has to be replaced and then allocates a new string which contains enough space for the token to be inserted. This process is repeated until all gaps are filled. This results in searches for tokens which are not present in the current template and some memory allocation/copy overhead because the string to replace will never have the same size.

But the most expensive things are the TokenFunctions which do expand e.g. the Extended Properties collection at the end of the example template. A quick look into the source shows where the problem is:

public virtual void Format(StringBuilder messageBuilder, LogEntry log)

    {
       ...
            string messageString = messageBuilder.ToString();
       ...
 

The performance optimization to use StringBuilder in the Formatter has cornered the TokenFunction formatter because it cannot to a simple replace of a fixed string and needs to parse the template. But StringBuilder gives you no access to the not yet constructed string and you need to use therefore this solution.

Armed with this knowledge I came up with an alternate approach to format a text template which does not suffer from the deficiencies of StringBuilder.Replace. The trick is to simply use StringBuilder.Append. To be able to do this I split the template apart in its constant (marked in orange) parts and use for each dynamic content a retriever function. The tuple (string, callback) is put into an object (MicroFormatter) from which we can create a list that allows us to build up the expanded template step by step. Registering template fill callbacks does eliminate all string searches and (nearly) all buffer reallocations. The cool thing is that this is also possible for the TokenFunctions which can now directly format the parsed template.

public class MicroFormatter
    {
        /// <summary>
        /// Constant prefix which is part of the message template
        /// </summary>
        public string Prefix { get; set; }
 
        /// <summary>
        /// Gets the dynamic content of the LogEntry
        /// </summary>
        public Func<LogEntry, string> Retriever { get; set; }
 
        /// <summary>
        /// TokenFunction formatter wrapper function which does need a string template as parameter which is then formatted.
        /// The formatted string is then returned
        /// </summary>
        public Func<LogEntry, string, string> TokenFuncRetriever { get; set; }
 
        /// <summary>
        /// Template which is expanded by the token e.g. "dictionary({key} - {value}" for the DictionaryFormatter
        /// </summary>
        public string TokenFuncTemplate { get; set; }
 
        public MicroFormatter()
        {
        }
 
        public MicroFormatter(string prefix, string tokenFuncTemplate, Func<LogEntry, string, string> tokenFuncRetriver)
        {
            Prefix = prefix;
            TokenFuncTemplate = tokenFuncTemplate;
            TokenFuncRetriever = tokenFuncRetriver;
        }
 
        public MicroFormatter(string prefix, Func<LogEntry, string> retriever)
        {
            Prefix = prefix;
            Retriever = retriever;
        }
 
        /// <summary>
        /// Appends to a StringBuilder instance the static and dynamic contents of the parsed template
        /// </summary>
 
publicvoid Format(LogEntry entry, StringBuilder template)
 
        {
            if (Prefix != null) // Append constant template part
            {
                template.Append(Prefix);
            }
 
            if (Retriever != null) // Add dynamic content of LogEntry
            {
                template.Append(Retriever(entry));
            }
            else if (TokenFuncRetriever != null) // Or add dynamic content of TokenFunction
            {
                template.Append(TokenFuncRetriever(entry, TokenFuncTemplate));
            }
        }
    }

This allows us to generate a easy Format Method:

    // Combined list of microformatters which allow an easy StringBuilder.Append instead of
    // a much slower StringBuilder.Replace which does first search (many times pointless) and
    // then replaces the string which needs to reallocate and copy the buffer
    List<MicroFormatter> myFormatters = new List<MicroFormatter>();
 
    public string Format(LogEntry entry)
    {
        // allocate string builder can be dynamically sized
        StringBuilder sb = new StringBuilder(500);
 
        // Call formatters in sequence they were entered to build the spitted
        // template piece by piece together again.
        foreach (MicroFormatter fmt in myFormatters)
        {
           fmt.Format(entry, sb);
        }
 
        return sb.ToString();
    }

The red lines are the important changes which give us much better performance. This simple solution does improve the formatting speed over 14 times! That should be enough for everyone ;-) Another costly part is the creation of the LogEntry itself which does call a private method in its default ctor (CollectIntrinsicProperties) which can cost quite some time. It would be nice if the P&P team would make this function virtual so one has a chance to optimize things a bit. This would be beneficial if somebody does want to filter LogEntry derived objects which can be filtered out without needing any of the other properties. That would allow to defer the costly data collection when it is really ensured that the entry will be logged.

Performance

All Performance Tests were performed with an Intel Core Duo 6600 @ 2.40 GHz with 3 GB RAM, EntLib 3.1, VS2008 RTM and the message template which is shown at the start of the article.

Test Case (executed 100K times)	Execution Frequency in 1/s	Speed Gain (x factor)
Create LogEntry	22 000	-
Format LogEntry TextFormatter	5 300	1
Format LogEntry SmartFormatter	75 000	14

More Code

The complete code of my SmartFormatter is shown below:

namespace Logging
{
    /// <summary>
    /// Really fast formatter with equivalent features as TextFormatter of the Enterprise Library
    /// </summary>
    public class SmartFormatter : ILogFormatter
    {
        protected const char TokenStartChar = '{';
 
        protected const string timeStampToken = "{timestamp}";
        protected const string messageToken = "{message}";
        protected const string categoryToken = "{category}";
        protected const string priorityToken = "{priority}";
        protected const string eventIdToken = "{eventid}";
        protected const string severityToken = "{severity}";
        protected const string titleToken = "{title}";
        protected const string errorMessagesToke = "{errorMessages}";
 
        protected const string machineToken = "{machine}";
        protected const string appDomainNameToken = "{appDomain}";
        protected const string processIdToken = "{processId}";
        protected const string processNameToken = "{processName}";
        protected const string threadNameToken = "{threadName}";
        protected const string win32ThreadIdToken = "{win32ThreadId}";
        protected const string activityidToken = "{activity}";
 
        protected const string NewLineToken = "{newline}";
        protected const string TabToken = "{tab}";
 
        protected const string DictionaryStartToken = "{dictionary(";
        protected const string KeyValueStartToken = "{keyvalue(";
        protected const string TimeStampStartToken = "{timestamp(";
        protected const string ReflectedPropertyStartToken = "{property(";
        protected const string EndToken = ")}";
 
        /// <summary>
        /// Key is the Token template e.g. "{timestamp}" and value is a callback function that retrieves the requested string from
        /// a LogEntry object.
        /// </summary>
        protected internal Dictionary<string, Func<LogEntry, string>> myTokenToFunc = new Dictionary<string, Func<LogEntry, string>>();
 
        /// <summary>
        /// Key is the Token Function start e.g. "{dictionary(" and value is a callback function that formats from a
        /// configured template the contents of a LogEntry object.
        /// </summary>
        protected internal Dictionary<string, Func<LogEntry, string, string>> myTokenFormatterToFunc = new Dictionary<string, Func<LogEntry, string, string>>();
 
        // Combined list of MicroFormatters which allow an easy StringBuilder.Append instead of
        // a much slower StringBuilder.Replace which does first search (many times pointless) and
        // then replaces the string which needs to reallocate and copy the buffer
        List<MicroFormatter> myFormatters = new List<MicroFormatter>();
 
        /// <summary>
        /// For brevity we use the C# 3.0 lambda syntax
        /// </summary>
        protected internal virtual void AddWellknownTokens()
        {
            myTokenToFunc.Add(timeStampToken, (LogEntry ent) => { return ent.TimeStampString; });
            myTokenToFunc.Add(messageToken, (LogEntry ent) => { return ent.Message; });
            myTokenToFunc.Add(categoryToken, FormatCategoriesCollection);
            myTokenToFunc.Add(priorityToken, (LogEntry ent) => { return ent.Priority.ToString(); });
            myTokenToFunc.Add(eventIdToken, (LogEntry ent) => { return ent.EventId.ToString(); });
            myTokenToFunc.Add(severityToken, (LogEntry ent) => { return ent.Severity.ToString(); });
            myTokenToFunc.Add(titleToken, (LogEntry ent) => { return ent.Title; });
            myTokenToFunc.Add(errorMessagesToke, (LogEntry ent) => { return ent.ErrorMessages; });
            myTokenToFunc.Add(machineToken, (LogEntry ent) => { return ent.MachineName; });
            myTokenToFunc.Add(appDomainNameToken, (LogEntry ent) => { return ent.AppDomainName; });
            myTokenToFunc.Add(processIdToken, (LogEntry ent) => { return ent.ProcessId; });
            myTokenToFunc.Add(processNameToken, (LogEntry ent) => { return ent.ProcessName; });
            myTokenToFunc.Add(threadNameToken, (LogEntry ent) => { return ent.ManagedThreadName; });
            myTokenToFunc.Add(win32ThreadIdToken, (LogEntry ent) => { return ent.Win32ThreadId; });
            myTokenToFunc.Add(activityidToken, (LogEntry ent) => { return ent.ActivityId.ToString(); });
            myTokenToFunc.Add(NewLineToken, (LogEntry ent) => { return Environment.NewLine; });
            myTokenToFunc.Add(TabToken, (LogEntry ent) => {return "\t"; });
 
            // register token functions
            myTokenFormatterToFunc.Add(DictionaryStartToken, (LogEntry ent, string template) =>
            {
                DictionaryToken token = new DictionaryToken();
                return token.FormatToken(template, ent);
            });
 
            myTokenFormatterToFunc.Add(KeyValueStartToken, (LogEntry ent, string template) =>
                {
                    KeyValueToken token = new KeyValueToken();
                    return token.FormatToken(template, ent);
                });
 
            myTokenFormatterToFunc.Add(TimeStampStartToken, (LogEntry ent, string template) =>
                {
                    TimeStampToken token = new TimeStampToken();
                    return token.FormatToken(template, ent);
                });
 
            myTokenFormatterToFunc.Add(ReflectedPropertyStartToken, (LogEntry ent, string template) =>
                {
                    ReflectedPropertyToken token = new ReflectedPropertyToken();
                    return token.FormatToken(template, ent);
                });
        }
 
        public SmartFormatter()
        {}
 
        public SmartFormatter(string template)
        {
            AddWellknownTokens();
            BuildFormatterList(template);
        }
 
        public string Format(LogEntry entry)
        {
            // allocate string builder can be dynamically sized
            StringBuilder sb = new StringBuilder(500);
 
            // Call formatters in sequence they were entered to build the splitted
            // template piece by piece together again.
            foreach (MicroFormatter fmt in myFormatters)
            {
                fmt.Format(entry, sb);
            }
 
            return sb.ToString();
        }
 
        /// <summary>
        /// Returns the template in between the parentheses for a token function.
        /// Expecting tokens in this format: {keyvalue(myKey1)}.
        /// </summary>
        /// <param name="startPos">Start index to search for the next token function.</param>
        /// <param name="message">Message template containing tokens.</param>
        /// <returns>Inner template of the function.</returns>
        protected virtual string GetInnerTemplate(string tokenFuncStart, int startPos, string message)
        {
            int tokenStartPos = message.IndexOf(tokenFuncStart, startPos) + tokenFuncStart.Length;
            int endPos = message.IndexOf(EndToken, tokenStartPos);
            return message.Substring(tokenStartPos, endPos - tokenStartPos);
        }
 
        /// <summary>
        /// Parse the template and create the list of microformatters. This way we get an ordered list
        /// of things we really have to do instead of trying to blindly format tokens in a template which
        /// may not be present
        /// </summary>
        /// <param name="template"></param>
        internal virtual protected void BuildFormatterList(string template)
        {
            MicroFormatter fmt = new MicroFormatter();
            List<char> curNonTokenString = new List<char>();
            bool isTokenChar = false;
 
            // Go through template and build list of Microformatters
            for(int i = 0; i<template.Length; i++)
            {
                isTokenChar = false;
                if (template[i] == TokenStartChar)
                {
                    // Transform all template variables 
                    foreach (string token in myTokenToFunc.Keys)
                    {
                        if (template.IndexOf(token, i) == i)
                        {
                            i += token.Length-1;
                            MicroFormatter formatter = new MicroFormatter();
                            formatter.Prefix = new string(curNonTokenString.ToArray());
                            // Get for this token the callback function which retrieves
                            // from a LogEntry object the resulting dynamic string
                            formatter.Retriever = myTokenToFunc[token];
                            myFormatters.Add(formatter);
                            isTokenChar = true;
                            curNonTokenString.Clear();
                            break;
                        }
                    }
 
                    // Transform all Token functions in the message template
                    foreach (string tokenStart in myTokenFormatterToFunc.Keys)
                    {
                        if (template.IndexOf(tokenStart, i) == i)
                        {
                            string tokenTemplate = GetInnerTemplate(tokenStart,i, template);
                            i += tokenStart.Length + tokenTemplate.Length + EndToken.Length - 1;
 
                            // Create formatter for this token function and store the token function
                            // template inside the formatter
                            MicroFormatter formatter = new MicroFormatter(new string(curNonTokenString.ToArray()),
                                                                          tokenTemplate, 
                                                                          myTokenFormatterToFunc[tokenStart]);
                            myFormatters.Add(formatter);
                            isTokenChar = true;
                            curNonTokenString.Clear();
                            break;
                        }
                    }
                }
 
                // if the current template character does not belong to a token variable or function
                // store it later as constant template part in the next MicroFormatter instance
                if (!isTokenChar)
                {
                    curNonTokenString.Add(template[i]);
                }
            }
 
            // the rest of the template is constant
            if (curNonTokenString.Count != 0)
            {
                myFormatters.Add( new MicroFormatter(new string(curNonTokenString.ToArray()), null) );
            }
        }
 
        public static string FormatCategoriesCollection(LogEntry ent)
        {
            StringBuilder categoriesListBuilder = new StringBuilder();
            int i = 0;
            foreach (String category in ent.Categories)
            {
                categoriesListBuilder.Append(category);
                if (++i < ent.Categories.Count)
                {
                    categoriesListBuilder.Append(", ");
                }
            }
            return categoriesListBuilder.ToString();
        }
   }
}

Visual Studio VS2008 Is Out!

Alois Kraus — Wed, 21 Nov 2007 01:27:00 GMT

This is my first test post with Windows Live Writer 2008. I hope it will not mess up when I paste source code ....

But back to business. VS2008 formerly known as Orcas is out! It is just great and has many cool features inside it.

You can download various editions of Visual Studio 2008 at the following locations.

One of the best features are Language Integrated Queries (LINQ). The first question that does arise is if LINQ to Objects is able to replace common for loops in terms of performance in every case. To check it out I did write a very simple test where we filter for specific items in an array and return the filtered list.

List<string> Test = new List<string> { "This", "is", "a", "list", "that", "will", "be", "filtered", "with",
"a", "for", "loop", "and", "LINQ"};

List<string> FilterFor(string substr)
{
List<string> ret = new List<string>();

     foreach (string str in Test)
     {
         if (str.Contains(substr))
             ret.Add(str);
     }

return ret;
}

List<string> FilterForLinq(string substr)
{
var ret = from str in Test where str.Contains(substr) select str;
return ret.ToList<string>();
}

On my Intel Core Duo 6600 @ 2.40 GHz with 3 GB RAM I get

	First Call in ms	Tight Loop in Calls/ms
FilterFor	1	584
FilterForLinq	2	454
FilterForLinq with IEnumerable<string> as return value	1	17543

The values were measured with the .NET Framework 3.5 RTM in release configuration. It seems that for simple filters we see a small (20%) speed loss if we use LINQ in very tight loops. But when I used a profiler (ANTS 3.0) I did get no speed difference. Since the profiler uses callbacks to get the exact timing we loose data locality and CPU cache benefits which slows the program nearly 100 times down such small effects are not visible anymore.

When we do only create the query but do not execute it we are over 30 times faster than the traditional array based approach. Lazy evaluation is the key to defer the actual work if we do not need all values or do not use them always. Huge speed gains are possible by doing only as much work as need but no more. I am looking forward to PLINQ which could take advantage of my two CPUs.

If you want to get started with more complex queries I recommend the 101 LINQ Samples site to learn what you can do with such queries or MSDN.

Best Practices Not Followed - Zune Player And A German Windows XP

Alois Kraus — Tue, 20 Feb 2007 12:50:00 GMT

Today I got my brand new Zune MP3 player which I did win at a Microsoft Event. Lucky me ;-). Ok install the software and you are ready to rockn roll, I thought, and I was wrong. Very wrong. At 94% of the installation it did stop with an error which was there even after a reboot. A quick Google search did confirm that other users had this problem also. One of the possible installation problems was the the Users group has the wrong name. Aha! I have a German Windows XP where the Users group is named Benutzer. The solution was to simply fire up the user management snapin and rename the Benutzer group to User. But wait I do not have installed a Home Edition of Windows XP. Darn there is no usable User Management Snapin installed. This was especially annoying since I did program a user and group management MMC snapin for my employer several years ago. I do even know the API calls. After trying around with WMI and DirectoryEntry, WindowsIdentity under Powershell, C# and VB Script I gave up and decided that there must be a simpler solution. And there was. The net command of Windows does allow you to programmatically manage groups and users. No rename there but it should be enough to create a Users group and assign it to my user account.

I add the description in German so others have the chance to find this information with Google/Another MS approved search engine.

Kann Zune Player nicht mit deutschem Windows XP installieren. Die Installation stoppt bei 94%. Um den Fehler zu beheben bitte folgende Befehle auf einem DOS command Prompt eingeben. Der String YourUserName mit dem aktuellen Benutzer Namen ersetzen. Danach sollte die Zune Player installation fehlerfrei funktionieren.

net localgroup "Users" /ADD
net localgroup "Users" "YourUserName" /ADD

net localgroup "INTERACTIVE" /ADD
net localgroup "INTERACTIVE" "YourUserName" /ADD

This will fix the error which do show up in the Windows Application Event Log.

An error occurred while applying security settings. Users is not a valid user or group. This could be a problem with the package, or a problem connecting to a domain controller on the network. Check your network connection and click Retry, or Cancel to end the install. Unable to locate the user's SID, system error 1332; (NULL); (NULL); (NULL).

Zune -- Error 1609. An error occurred while applying security settings. INTERACTIVE is not a valid user or group. This could be a problem with the package, or a problem connecting to a domain controller on the network. Check your network connection and click Retry, or Cancel to end the install. Unable to locate the user's SID, system error 1332; (NULL); (NULL); (NULL).

What do we learn from this. Even Microsoft does not always follow its own security programming best practices. The Users and Interactive groups can easily be retrieved via it's well known SIDs (Security Identifiers) and not by their localized names. For my vigilant Microsoft Employee readers I paste them here so they can fix this issue faster ;-).

SID: S-1-5-32-545
Name: Users
Description: A built-in group. After the initial installation of the operating system, the only member is the Authenticated Users group. When a computer joins a domain, the Domain Users group is added to the Users group on the computer.

SID: S-1-5-4
Name: Interactive
Description: A group that includes all users that have logged on interactively. Membership is controlled by the operating system.

I cannot tell you how good this player is compared to my IPod Nano which I incidentally did win also (no it was not an Apple event). It does still sync my MP3 folders which it managed to find somehow. What I do not like is that it does not show up as new drive where I can simply copy the files onto. This might be a tribute to DRM which will hopefully become history in the not so distant future.

Funny side note: At the back of my Zune are greetings from Seattle.

Hello From Erlangen ;-)

Create Strong Named Assemblies - The Easy Way

Alois Kraus — Wed, 24 Jan 2007 02:21:00 GMT

Strong naming has always been a complicated matter. Sometimes it is even impossible when you get unsigned assemblies from a third party software vendor and you have to build strong named assemblies to install them into the GAC. When you decide to strong name your project it is a all or nothing decision. If your target is strong named then all references must also be strong named. If you do not have the source code and a project for your third party dll you will not be able to sign your project. I have created Signer which is hosted at CodePlex that allows you to add strong names to binaries within minutes. You can even create a strong named build of your whole project without any changes to your build settings. Below is a picture which shows Signer in action:

How does it work?

Signer does basically a full round trip by decompiling the assembly into IL code make the necessary modifications and compile it back to a valid assembly. The required modifications include

Update of all references
Change/Removal of InternalsVisibleToAttribute
Update of custom attributes with a type parameter
A little fix to work around an ILDASM problem

Reference Update in IL

This is the easy part. A reference does consist of the assembly name, public key token and it's version. Signer has only to insert the public key token where none is present to patch the IL file.

.assembly extern Microsoft.Practices.EnterpriseLibrary.Common
{
.publickeytoken = (BE CA 05 5E 5B 7D 2D C8 ) // Inserted by Signer if not present
.ver 2:0:0:0
}

InternalsVisibleTo Attribute

With .NET 2.0 the InternalsVisibleTo attribute was introduced that allows to grant other assemblies access to classes and methods marked with the internal keyword. To prevent in a strong name scenario that an unsigned assembly does get access to internals directly (you can use reflection instead but this comes with a perf cost) the CLR does check at runtime if all InternalsVisibleTo attribute declarations grant access to strong named assemblies only. If not a runtime exception is thrown and the process terminates.

.custom instance void [mscorlib]System.Runtime.CompilerServices.InternalsVisibleToAttribute::.ctor(string) =
   ( 01 00 48 4D 69 63 72 6F 73 6F 66 74 2E 50 72 61   // ..HMicrosoft.Pra
                                63 74 69 63 65 73 2E 45 6E 74 65 72 70 72 69 73   // ctices.Enterpris
                                65 4C 69 62 72 61 72 79 2E 4C 6F 67 67 69 6E 67   // eLibrary.Logging
                                2E 43 6F 6E 66 69 67 75 72 61 74 69 6F 6E 2E 44   // .Configuration.D
                            65 73 69 67 6E 2E 54 65 73 74 73 00 00 )          // esign.Tests.."

You have to insert the public key which is over 300 bytes long into your project which is quite tedious if you want to do it manually. At the moment Signer makes life easy and simply removes the attribute to prevent run time errors but if needed the change is trivial.

Custom Attributes
This was by far the most tricky part. When you declare custom attributes with a type parameter the full qualified type name including assembly and public key token is inserted into the IL code. Normally you get this as a binary blob but with the /CAVERBAL option of ILDASM which was introduced with .NET 2.0 things get much easier.

.custom instance void [System]System.ComponentModel.EditorAttribute::.ctor(class [mscorlib]System.Type,
                                                                           class [mscorlib]System.Type)
= {
type(class
'Microsoft.Practices.EnterpriseLibrary.Configuration.Design.ReferenceEditor,
Microsoft.Practices.EnterpriseLibrary.Configuration.Design, Version=2.0.0.0, Culture=neutral,
    PublicKeyToken=beca055e5b7d2dc8')
type(class
  'System.Drawing.Design.UITypeEditor, System.Drawing, Version=2.0.0.0, Culture=neutral,
   PublicKeyToken=b03f5f7f11d50a3a')
}

Signer does parse the attributes and does set the PublicKeyToken where needed.

ILDASM Problems
All would work wonderful if, well if the nice /CAVERBAL option would produce running code. But I got many ConfiguratonErrors exceptions which told me that the default value was of the wrong type. Arghhh. After digging a little deeper I found out what was going on. Suppose you have a simple configuration class for settings inside the App.Config file:

using System;

using System.Collections.Generic;

using System.Text;

using System.Configuration;

namespace NoRoundTrip

{

enum MyValues

{

}

class Check : ConfigurationSection

{

const string PropName = "Name";

// DefaultValue is a property of type object

[ConfigurationProperty(PropName,DefaultValue=MyValues.V1)]

public MyValues Value

{

get { return (MyValues) this[PropName]; }

}

class Program

{

static void Main(string[] args)

{

Check c = new Check();

MyValues defValue = c.Value; // get default value

}

The program will work without problem when used as is. But after decompiling with the /CAVERBAL option and recompiling you will get a nasty runtime exception:

Unhandled Exception: System.Configuration.ConfigurationErrorsException:
The default value for the property 'Name' has different type than the one of the property itself.

Here is the innocent looking IL code
    .custom instance void
[System.Configuration]System.Configuration.ConfigurationPropertyAttribute::.ctor(string)
        = {
string('Name')
            property object 'DefaultValue' = object( int32(0) )
  }

The ConfigurationProperty DefaultValue does not preserve type identity for enums but does simply declare them as its native integer value which will lead to this exception during run time because there is an extra check code in the BCL code. The generated IL code is valid for the CLR but not for the BCL. Signer does get around this issue by decompiling every assembly once with the parser friendly /CAVERBAL option and the second time without. It will then merge the binary blobs for the ConfigurationProperty Attributes into the other IL file to get a fully functional assembly. Once this obstacle was solved all worked perfectly.

Signer Usage

If you start Signer without any options you will get a pretty self explanatory help to do signing. The only thing to remeber is that the .NET Framework tool sn is needed to generate a strong name key pair by simply executing sn -k c:\key.snk and you are ready to use Signer out of the box with your project.

Signer (C) by Alois Kraus 2007 (akraus1@gmx.de) version 1.0.0.0

Signer -k <KeyFile> -outdir <Output Dir> -a <Assembly1> <Assembly2> ... [-decomp "Options" -comp "Options" -debug]
   Signer does sign all assemblies and updates their references if the assembly is not already signed
   This way you can convert a whole bunch of assemblies which have never seen a key file into strong named assemblies without recompiling!
   -k        Key File name of key container file which is created usually by the sign tool (sn -k)
   -outdir   Output directory where the strong signed assemblies are copied to
   -decomp   Additional ildasm options e.g. "/STATS"
   -comp     Additional ilasm options e.g. "/X64"
   -a        Can be a list of assembly names or a wildcard search pattern e.g. *.dll
   -debug    Do not delete temporary IL files in %TEMP% flder after completion

Example: Signer -k c:\key.snk -outdir .\build -a *.dll *.exe Copy the signed assemblies into the newly created directory build.
Example: Signer -k c:\key.snk -outdir . -a *.dll *.exe        Sign and overwrite the orignal binaries in current directory.

Error: No Key file specifed (use -k KeyFile ).
Error: No Output directory specifed (use -outdir Dir ).
Error: No input assemblies specified (use -a Assembly ).

Conclusions

It was fun to create the tool while learning quite a lot about the assembly structure, strong names and IL. As you can see strong names are not really a protection for your software as they can be easily removed and your assemblies resigned without big problems. The only real advantage strong names offer is that you can prove that an assembly which has your public key on it was created by you as long as your secret key is kept safe.
From this point other extensions to Signer are quite easy to add. E.g. removal of strong names, make internals public or adding your own InternalsVisibleTo attribute to other assemblies. The world is full of possibilities ;-).