Those of you who work or worked on porting Windows applications (any kind of them - ASP.NET, WinForms, console) might have come across a problem with case-sensitivity of file names. Windows file systems are either case-unaware and case-insensitive (the FAT family) or case-aware but case-insensitive (NTFS). In both cases applications performing I/O don't need to worry about using proper file name casing, as the underlying operating system will ignore the case and open the file without problems. This is not the case on Unix operating systems which have file systems that are both case-aware and case-sensitive.

Mono has had a solution for this problem for a long time - it's called IOMAP. It's a runtime mechanism which, if enabled by exporting the MONO_IOMAP variable, will translate not only file name case to the correct form used on disk, but will also strip DOS drive designators from the paths and translate DOS path separator character to the Unix one, thus making the application work seamlessly. The convenience comes at a price, of course, as translating the file names involves performing a lot of disk I/O to discover the real file name. So if your application is supposed to be ran on Unix most (if not all) of the time then the better to dive into the source and make sure that file names on disk are consistent with their use in the source code.

With small applications the operation is usually straight-forward and takes little time. With bigger codebases, however, it might pose a problem, especially if strings used to access files are constructed in different places of the application as opposed to being just plain literals.

For that reason I have recently created a Mono profiler module (it is somewhat of a misnomer, as the utility has little to do with code profiling) which aims at helping the developer/porter to find places in code which call .NET I/O routines passing them misformed file/directory paths as well as identify places where those strings are constructed. The former part is very simple and it merely prints to the console a stack trace leading to the I/O routine call site every time file/directory name mapping is performed. The latter part, however, is a bit more problematic as it has to deal with two separate moments in string's life - its creation and its actual use. The code uses the Mono profiler API to monitor string allocations storing all the strings created in hash tables as well as remembering the stack frame which leads to the string creation site. The code which does that is pretty fast, so it doesn't impact your application's performance too much even though it collects and stores a large amount of data (mostly pointers and some strings, though). When file name mapping is performed during file I/O, the profiler code looks up the string address and retrieves the stack trace to store it for later use. When the application exits a summary report is printed to the console which includes some statistics on the string, its original (requested) and target (mapped) form as well as a location (if it was possible to determine it) where the string was created. The location is determined using simple heuristics, so it might sometimes point to a location which is near the place where the string was created. The heuristics code walks the stack frames looking for first frame which is in application code - that is it ignores the well-known class library assemblies shipped with Mono (corlib, System*, some Mono* assemblies etc) and all the assemblies installed in the GAC. The first frame which doesn't belong in either of the above is considered to be user's code and is reported to be the string allocation location. If the stack trace doesn't contain any such frames, full trace is recorded and shown in the summary.

To take advantage of this utility you will need Mono from trunk (or 2.8 when it is released). It is advisable to compile your application with full debugging information, so that source files and line numbers can be reported (otherwise only Namespace.Class.Method will be printed). To enable the utility, make sure the MONO_IOMAP environment variable is present and set to 'all', 'case' or 'drive' and execute your application as follows:

   mono --debug --profile=iomap your_application.exe

   MONO_OPTIONS="--debug --profile=iomap" xsp2

$ MONO_IOMAP=all mono --profile=iomap --debug iomap-report-sample.exe 
Running test: Mismatched file name case.
-=-=-=-=-=-=- MONO_IOMAP REPORT -=-=-=-=-=-=-
 - Requested file path: 'files/Test2.txt'
 -     Found file path: 'Files/test2.txt'

-= Stack Trace =-
   at System.Environment.get_StackTrace() in /usr/src/tmp/mono/mcs/class/corlib/System/Environment.cs:line 183
   at System.IO.MonoIO.GetFileAttributes(System.String , MonoIOError ByRef )
   at System.IO.MonoIO.ExistsDirectory(System.String path, MonoIOError ByRef error) in /usr/src/tmp/mono/mcs/class/corlib/System.IO/MonoIO.cs:line 252
   at System.IO.Directory.Exists(System.String path) in /usr/src/tmp/mono/mcs/class/corlib/System.IO/Directory.cs:line 201
   at System.IO.FileStream..ctor(System.String path, FileMode mode, FileAccess access, FileShare share, Int32 bufferSize, Boolean anonymous, FileOptions options) in /usr/src/tmp/mono/mcs/class/corlib/System.IO/FileStream.cs:line 246
   at System.IO.FileStream..ctor(System.String path, FileMode mode, FileAccess access, FileShare share)
   at System.IO.File.OpenRead(System.String path) in /usr/src/tmp/mono/mcs/class/corlib/System.IO/File.cs:line 331
   at System.IO.StreamReader..ctor(System.String path, System.Text.Encoding encoding, Boolean detectEncodingFromByteOrderMarks, Int32 bufferSize) in /usr/src/tmp/mono/mcs/class/corlib/System.IO/StreamReader.cs:line 171
   at System.IO.StreamReader..ctor(System.String path, System.Text.Encoding encoding)
   at System.IO.File.ReadAllText(System.String path, System.Text.Encoding encoding) in /usr/src/tmp/mono/mcs/class/corlib/System.IO/File.cs:line 542
   at System.IO.File.ReadAllText(System.String path) in /usr/src/tmp/mono/mcs/class/corlib/System.IO/File.cs:line 537
   at app.MismatchedFileNames() in /home/grendel/Projects/work/iomap-report-sample/iomap-report-sample.cs:line 45
   at app.RunTest(System.String banner, System.Action test) in /home/grendel/Projects/work/iomap-report-sample/iomap-report-sample.cs:line 24
   at app.Main(System.String[] args) in /home/grendel/Projects/work/iomap-report-sample/iomap-report-sample.cs:line 39

-=-=-=-=-=-=- MONO_IOMAP REPORT -=-=-=-=-=-=-
 - Requested file path: '/home/grendel/Projects/work/iomap-report-sample/files'
 -     Found file path: '/home/grendel/Projects/work/iomap-report-sample/Files'

-= Stack Trace =-
   at System.Environment.get_StackTrace() in /usr/src/tmp/mono/mcs/class/corlib/System/Environment.cs:line 183
   at System.IO.MonoIO.GetFileAttributes(System.String , MonoIOError ByRef )
   at System.IO.MonoIO.ExistsDirectory(System.String path, MonoIOError ByRef error) in /usr/src/tmp/mono/mcs/class/corlib/System.IO/MonoIO.cs:line 252
   at System.IO.Directory.Exists(System.String path) in /usr/src/tmp/mono/mcs/class/corlib/System.IO/Directory.cs:line 201
   at System.IO.FileStream..ctor(System.String path, FileMode mode, FileAccess access, FileShare share, Int32 bufferSize, Boolean anonymous, FileOptions options) in /usr/src/tmp/mono/mcs/class/corlib/System.IO/FileStream.cs:line 270
   at System.IO.FileStream..ctor(System.String path, FileMode mode, FileAccess access, FileShare share)
   at System.IO.File.OpenRead(System.String path) in /usr/src/tmp/mono/mcs/class/corlib/System.IO/File.cs:line 331
   at System.IO.StreamReader..ctor(System.String path, System.Text.Encoding encoding, Boolean detectEncodingFromByteOrderMarks, Int32 bufferSize) in /usr/src/tmp/mono/mcs/class/corlib/System.IO/StreamReader.cs:line 171
   at System.IO.StreamReader..ctor(System.String path, System.Text.Encoding encoding)
   at System.IO.File.ReadAllText(System.String path, System.Text.Encoding encoding) in /usr/src/tmp/mono/mcs/class/corlib/System.IO/File.cs:line 542
   at System.IO.File.ReadAllText(System.String path) in /usr/src/tmp/mono/mcs/class/corlib/System.IO/File.cs:line 537
   at app.MismatchedFileNames() in /home/grendel/Projects/work/iomap-report-sample/iomap-report-sample.cs:line 45
   at app.RunTest(System.String banner, System.Action test) in /home/grendel/Projects/work/iomap-report-sample/iomap-report-sample.cs:line 24
   at app.Main(System.String[] args) in /home/grendel/Projects/work/iomap-report-sample/iomap-report-sample.cs:line 39

File 1: Hello, world - test2.txt here


-=-=-=-=-=-=- MONO_IOMAP REPORT -=-=-=-=-=-=-
 - Requested file path: 'files/test.txt'
 -     Found file path: 'Files/TesT.txt'

-= Stack Trace =-
   at System.Environment.get_StackTrace() in /usr/src/tmp/mono/mcs/class/corlib/System/Environment.cs:line 183
   at System.IO.MonoIO.GetFileAttributes(System.String , MonoIOError ByRef )
   at System.IO.MonoIO.ExistsDirectory(System.String path, MonoIOError ByRef error) in /usr/src/tmp/mono/mcs/class/corlib/System.IO/MonoIO.cs:line 252
   at System.IO.Directory.Exists(System.String path) in /usr/src/tmp/mono/mcs/class/corlib/System.IO/Directory.cs:line 201
   at System.IO.FileStream..ctor(System.String path, FileMode mode, FileAccess access, FileShare share, Int32 bufferSize, Boolean anonymous, FileOptions options) in /usr/src/tmp/mono/mcs/class/corlib/System.IO/FileStream.cs:line 246
   at System.IO.FileStream..ctor(System.String path, FileMode mode, FileAccess access, FileShare share)
   at System.IO.File.OpenRead(System.String path) in /usr/src/tmp/mono/mcs/class/corlib/System.IO/File.cs:line 331
   at System.IO.StreamReader..ctor(System.String path, System.Text.Encoding encoding, Boolean detectEncodingFromByteOrderMarks, Int32 bufferSize) in /usr/src/tmp/mono/mcs/class/corlib/System.IO/StreamReader.cs:line 171
   at System.IO.StreamReader..ctor(System.String path, System.Text.Encoding encoding)
   at System.IO.File.ReadAllText(System.String path, System.Text.Encoding encoding) in /usr/src/tmp/mono/mcs/class/corlib/System.IO/File.cs:line 542
   at System.IO.File.ReadAllText(System.String path) in /usr/src/tmp/mono/mcs/class/corlib/System.IO/File.cs:line 537
   at app.MismatchedFileNames() in /home/grendel/Projects/work/iomap-report-sample/iomap-report-sample.cs:line 46
   at app.RunTest(System.String banner, System.Action test) in /home/grendel/Projects/work/iomap-report-sample/iomap-report-sample.cs:line 24
   at app.Main(System.String[] args) in /home/grendel/Projects/work/iomap-report-sample/iomap-report-sample.cs:line 39

File 2: Hello, world - TesT here


Running test: Access from an assembly.
Reading a file.
-=-=-=-=-=-=- MONO_IOMAP REPORT -=-=-=-=-=-=-
 - Requested file path: 'fileS/tESt.txt'
 -     Found file path: 'Files/TesT.txt'

-= Stack Trace =-
   at System.Environment.get_StackTrace() in /usr/src/tmp/mono/mcs/class/corlib/System/Environment.cs:line 183
   at System.IO.MonoIO.GetFileAttributes(System.String , MonoIOError ByRef )
   at System.IO.MonoIO.ExistsDirectory(System.String path, MonoIOError ByRef error) in /usr/src/tmp/mono/mcs/class/corlib/System.IO/MonoIO.cs:line 252
   at System.IO.Directory.Exists(System.String path) in /usr/src/tmp/mono/mcs/class/corlib/System.IO/Directory.cs:line 201
   at System.IO.FileStream..ctor(System.String path, FileMode mode, FileAccess access, FileShare share, Int32 bufferSize, Boolean anonymous, FileOptions options) in /usr/src/tmp/mono/mcs/class/corlib/System.IO/FileStream.cs:line 246
   at System.IO.FileStream..ctor(System.String path, FileMode mode, FileAccess access, FileShare share)
   at System.IO.File.OpenRead(System.String path) in /usr/src/tmp/mono/mcs/class/corlib/System.IO/File.cs:line 331
   at System.IO.StreamReader..ctor(System.String path, System.Text.Encoding encoding, Boolean detectEncodingFromByteOrderMarks, Int32 bufferSize) in /usr/src/tmp/mono/mcs/class/corlib/System.IO/StreamReader.cs:line 171
   at System.IO.StreamReader..ctor(System.String path, System.Text.Encoding encoding)
   at System.IO.File.ReadAllText(System.String path, System.Text.Encoding encoding) in /usr/src/tmp/mono/mcs/class/corlib/System.IO/File.cs:line 542
   at System.IO.File.ReadAllText(System.String path) in /usr/src/tmp/mono/mcs/class/corlib/System.IO/File.cs:line 537
   at LibClass.ReadFile(System.String dir, System.String fileName) in /home/grendel/Projects/work/iomap-report-sample/iomap-report-lib.cs:line 12
   at app.AccessFromAssembly() in /home/grendel/Projects/work/iomap-report-sample/iomap-report-sample.cs:line 51
   at app.RunTest(System.String banner, System.Action test) in /home/grendel/Projects/work/iomap-report-sample/iomap-report-sample.cs:line 24
   at app.Main(System.String[] args) in /home/grendel/Projects/work/iomap-report-sample/iomap-report-sample.cs:line 40

-=-=-=-=-=-=- MONO_IOMAP REPORT -=-=-=-=-=-=-
 - Requested file path: '/home/grendel/Projects/work/iomap-report-sample/fileS'
 -     Found file path: '/home/grendel/Projects/work/iomap-report-sample/Files'

-= Stack Trace =-
   at System.Environment.get_StackTrace() in /usr/src/tmp/mono/mcs/class/corlib/System/Environment.cs:line 183
   at System.IO.MonoIO.GetFileAttributes(System.String , MonoIOError ByRef )
   at System.IO.MonoIO.ExistsDirectory(System.String path, MonoIOError ByRef error) in /usr/src/tmp/mono/mcs/class/corlib/System.IO/MonoIO.cs:line 252
   at System.IO.Directory.Exists(System.String path) in /usr/src/tmp/mono/mcs/class/corlib/System.IO/Directory.cs:line 201
   at System.IO.FileStream..ctor(System.String path, FileMode mode, FileAccess access, FileShare share, Int32 bufferSize, Boolean anonymous, FileOptions options) in /usr/src/tmp/mono/mcs/class/corlib/System.IO/FileStream.cs:line 270
   at System.IO.FileStream..ctor(System.String path, FileMode mode, FileAccess access, FileShare share)
   at System.IO.File.OpenRead(System.String path) in /usr/src/tmp/mono/mcs/class/corlib/System.IO/File.cs:line 331
   at System.IO.StreamReader..ctor(System.String path, System.Text.Encoding encoding, Boolean detectEncodingFromByteOrderMarks, Int32 bufferSize) in /usr/src/tmp/mono/mcs/class/corlib/System.IO/StreamReader.cs:line 171
   at System.IO.StreamReader..ctor(System.String path, System.Text.Encoding encoding)
   at System.IO.File.ReadAllText(System.String path, System.Text.Encoding encoding) in /usr/src/tmp/mono/mcs/class/corlib/System.IO/File.cs:line 542
   at System.IO.File.ReadAllText(System.String path) in /usr/src/tmp/mono/mcs/class/corlib/System.IO/File.cs:line 537
   at LibClass.ReadFile(System.String dir, System.String fileName) in /home/grendel/Projects/work/iomap-report-sample/iomap-report-lib.cs:line 12
   at app.AccessFromAssembly() in /home/grendel/Projects/work/iomap-report-sample/iomap-report-sample.cs:line 51
   at app.RunTest(System.String banner, System.Action test) in /home/grendel/Projects/work/iomap-report-sample/iomap-report-sample.cs:line 24
   at app.Main(System.String[] args) in /home/grendel/Projects/work/iomap-report-sample/iomap-report-sample.cs:line 40

Reading file: Hello, world - TesT here



-=-=-=-=-=-=-= MONO_IOMAP Stats -=-=-=-=-=-=-=
    Count: 2
Requested: /home/grendel/Projects/work/iomap-report-sample/fileS
   Actual: /home/grendel/Projects/work/iomap-report-sample/Files
Locations:
        LibClass:ReadFile (string,string) in /home/grendel/Projects/work/iomap-report-sample/iomap-report-lib.cs:12

    Count: 7
Requested: fileS/tESt.txt
   Actual: Files/TesT.txt
Locations:
        LibClass:ReadFile (string,string) in /home/grendel/Projects/work/iomap-report-sample/iomap-report-lib.cs:12

    Count: 4
Requested: /home/grendel/Projects/work/iomap-report-sample/files
   Actual: /home/grendel/Projects/work/iomap-report-sample/Files
Locations:
        app:MismatchedFileNames () in /home/grendel/Projects/work/iomap-report-sample/iomap-report-sample.cs:45
        app:MismatchedFileNames () in /home/grendel/Projects/work/iomap-report-sample/iomap-report-sample.cs:45

    Count: 7
Requested: files/Test2.txt
   Actual: Files/test2.txt
Locations:
        app:MismatchedFileNames () in /home/grendel/Projects/work/iomap-report-sample/iomap-report-sample.cs:45

    Count: 7
Requested: files/test.txt
   Actual: Files/TesT.txt
Locations:
        app:MismatchedFileNames () in /home/grendel/Projects/work/iomap-report-sample/iomap-report-sample.cs:46

Many years ago when coding in C/C++ or assembler I learned one important rule - DO micro-optimize your code. Unlike macro scale optimization, which should be done after your code is generally working and feature complete, micro optimization should be applied as you go. Why? Because sticking to a few simple rules (which don't affect the overall way in which the code works) as you code is easier than having to fish for the small inefficiencies in your source later on. Some of the optimizations can be performed by the compiler (like taking a constant expression out of loop) but some still depend on the coder doing the Right Thing™.

It seems that, a month ago, I proved that I had forgotten the rules I learned and applied in the past by committing code which affected Mono ASP.NET's performance in a really major way. I'm posting this blog entry as a memento to myself and to others who, like me, might have forgotten that such rules still apply in the 21st century despite all our smart compilers, sophisticated virtual machines and runtimes.

The committed code did (eventually) something like this:

void Method (string s)
{
    string s2 = GetSomeString ()

    CallMethod (s + '@' + s2);
}

The CallMethod line caused (as we discovered yesterday) a drammatic decrease in MojoPortal's performance - its home page would open on my computer, using local connection in 2.56s (yes, seconds) on average. Gonzalo went hunting for the issue and this morning I read a mail from him pin-pointing (after lots and lots of time wasted on it) the performance loss to that very line. I fixed the issue in our code and suddenly the load time for the page went down to ~107ms (yes, milliseconds)! One might ask whether it was because concatenating two strings and a char is so inefficient? Yes, it is inefficient (as the operation has to convert a char to a string, then allocate and concatenate two more strings) but not enough to justify such performance loss. The key here is the frequency at which the code is being called - GetSection gets called hundreds (if not thousands) of times during one request, and the operation's summed up time contributes to the peformance loss.

This is exactly what I described at the beginning of this post - a micro optimization, a right thing to do in the right place. It can be compared to adding two integer or float variables whose values don't change in a loop which takes thousands of iterations and is invoked by some code very often. The addition is not very expensive if your code performs it once in a while, but in the scenario when it repeatedly calls the code, you will see major loss of performance. The solution is to take the operation outside of the loop. This is precisely what happened here.

So, even in this day and age - ladies and gentlemen, do micro-optimize and pay attention to where your "slightly inefficient" code lives :)

Update:

As Jon suggested below, I should have suggested possible solutions to the issue:

• CallMethod could take 3 arguments instead of one (depends on what the method does, of course) - that was the solution chosen in this instance to fix the issue as the string concatenation wasn't at all necessary.
• Using "@" instead of '@' would avoid costly (culture-sensitive) conversion of a char to string