• A new domain I know nothing about.
• Technologies I know nothing about (including 4 programming languages I only have a passing knowledge in).
• Huge codebases I know nothing about.
• People in the company: their names, roles. Whom should I ask what at any given situation?

Here are a few tips I gathered from my experience at my new job.

1) Ask questions, but…

You should be asking a lot of questions to gain the knowledge you need. Don’t be shy to ask things like ‘What does this term mean?’, ‘Who was this person and what is her role in the company?’, and of course ‘Why can’t I get this to run?’. But there’s a but here, there’s a way to ask questions as well:

– Don’t ask about everything you don’t immediately understand. Some things you can pretty easily find out on your own. There’s a lot to learn in investigating by yourself how that thing works.

– But don’t spend days investigating a question when someone can answer it for you in two minutes.

– Ask different people. Even the nicest person has his own job to do, and your questions can interrupt his flow. Also, getting the perspective of multiple people is important.

– Keep a list of things you don’t understand. Try to cross them off one by one by either finding out yourself, or asking a teammate. I put there things like terms I don’t understand, questions about why things were done a certain way and even questions about operating my mac (hey, I’m a Windows guy) which I wanted to google when I had the chance. Now, whenever I have a moment (e.g. running a long integration test) I try to cross something off the list.

2) Don’t judge, listen

As an experienced dev you feel that you bring a lot to the table, and it can be hard to resist the urge to tell teammates that some code is ugly, or that a system should have been built in a completely different way. Instead, ask ‘why is this piece of code complex’? Or, ‘what were you concerned about when you decided to build the system this way?’ The answer should teach you a lot, and you’d be surprised how much more open and candid people can be when approached in a kind, not judging manner. Many times things are the way the are for a good reason. And even when there isn’t one, remember, your old company had a lot of ugly code, patches and hacks as well, left by years of pressure and compromises. Instead of judging, try to understand the context and the history involved.

3) Ask everyone what they’re working on

This has been incredibly useful to me. Whenever I meet a teammate in the kitchen I ask them what they’re working on. They were always happy to talk about this, and the gain for me is pretty great:

• They usually have to explain the purpose of parts of the system, in order for me to understand their current task. Great for crossing things off the ‘things I don’t understand’ list!
• I get to learn the role of this person in the team, so when something comes up later, I know who’s the expert on what.
• I become friendlier with this teammate, which brings me to…

4) Be social

It’s easy to drown in your own tasks when you’re new. Things can be overwhelming, and as an experienced dev you might feel you need to prove yourself right away and complete a lot of tasks quickly. So when they ask you out to lunch you might think it’s better if you just munch on something in front of your screen. Don’t do that. Really, your first weeks at work are not only about learning technologies and systems, they’re also about creating personal connections with the people you work with. Eat lunch with teammates every day, ask them a little about their personal lives, tell them about yours. Make friends. It will make your time at the new job much jollier.

One final note: Beginnings are hard. Take it easy and remember that no one expects you to change the world in your first month or two. Good luck!

VS 2015 came out and we happily upgraded. Everything worked great, except for one thing: our integration tests started to run slowly. Like 10 times slower. The thing is, the same code, when not running under the NUnit process, worked just fine. Something was afoot.

After much investigation and profiling, we discovered the root cause: GC. Our integration tests run our entire system start-up process, which allocates a few gigs of caches. Ever since installing VS 2015, and .NET 4.6 with it, allocating all this RAM took a much longer time, due to GC. But, and this is a really important but, this doesn’t happen if you use Server GC mode, which we thought we did. Our unit tests were running under the Resharper tests runner process, which didn’t respect the <runtime> config section in our IntegrationTests app.config. That means that we were actually using workstation GC in our integration tests since forever, but didn’t notice it until .NET 4.6 came and made things much slower.

The solution to all this was forcing the Resharper test runner (or whatever process is running your tests) to use the server GC mode. I did this by opening this folder: C:\Users\YouUserName\AppData\Local\JetBrains\Installations\ReSharperPlatformVs14, and editing the file JetBrains.ReSharper.TaskRunner.CLR45.x64.exe.config. Here I just added <gcServer enabled=”true” /> under the runtime section. Now, you can either force Resharper to always use CLR 4.5 & x64 in the options (which is what we did), or do the same for all other JetBrains.ReSharper.TaskRunner config files.

This is not an ideal solution. We would have to remember to keep editing these files every time we reinstall ReSharper. Also, I can’t really explain what has made things so much worse in the new workstation GC. I guess time will tell.

1. Compile times are so slow, that every time I compiled I died a small death. Before 1.2 they had no incrmental build, so every file I changed, I had to wait like 5 minutes for the entire project the build. It literally meant that every feature I wanted to develop took me 5 times more than it should have.
2. XCode support for it was crappy, without basic features such as a rename refactoring.
3. Compiling with optimizations (-o flag) was extremely buggy, resulting sometimes in compiled code that was just wrong, especially in code with lots of closures. But compiling without optimizations meant your code was extremly slow.
4. Even with optimizations, Swift 1.0 had really, really crappy peformance. The dictionary data structure, in particular, was so slow, that I simply had to avoid it everywhere, using NSMutableDictionary or even arrays if I could. I haven’t tested it on Swift 1.2, but I pray it is much faster now.
5. No Exceptions. Write once, crash everywhere.
6. Unlike most other programming languages these days, Swift is not open source. Want to look at that Dictionary code? See how you could use it better? Well, you can’t, and you won’t, ever.

But the issue I want to talk about today is the Swift String type. The language designers had decided on a very intresting approach here, they made the string characters not constant in size. As you know, Java or C# a String is basiclly an array of two-byte UTF-16 characters. So for the string “I love emojis ” the smiley there would be represented by two separate characters. Not so in Swift, in which the String type was designed to handle unicode surrogates in a more elegant matter, and the emoji would be considered just one character.

In an ideal world, this would be a Good Thing. But in a world where every millisecond counts, this presents a performance issue. How do you access the 5th character in a Swift string? Well, you can’t use an indexer because of the variable character length. You have to iterate over the characters until you reach the 5th one. And that’s pretty slow. How do you know the string length? Same problem, an O(n) operation. So although the Swift string is more ‘correct’ than the Java/C# implementation, if you don’t pay attention, and if you do a lot of string manipulation like we do, it can kill the peformance of your app. And who knows? Maybe that piece of code you’re writing will never ever have to handle emojis or surrogate characters (because you’re using only English dictionary words or whatever). In this case you’re writing slower code for no reason at all.

Fortunately, there’s a workaround. You can use the String’s utf16 property to treat it as a UTF-16 string. So str.utf16[5] will get you the 5th character quickly. Even iteration on str.utf16 is much faster (at least in Swift 1.0) than iterating the String characters themselves. This tells me that the underlying structure is still an array of UTF-16 characters, but I can’t say for sure as the Swift is not open source.. However, there are some caveats.

1. str.utf16[5] has a type of UInt16. So if you want to check if it is a dot (‘.’), you have to use something like “.”.utf16[0], which is fugly.
2. If you want to convert str.utf16[5] back to a string, you can use “\(UnicodeScalar(myUInt16))”. However, this code will CRASH your app if this is the first half of an emoji, or in other words, a non valid unicode code point. And as I said, there are no exceptions in Swift, so you can’t try-catch it. You have to roll your own IsValidUnicodeCodePoint method, based on this definition. Or just copy Java’s Character.isSurrogate method, which is what I did.

To conclude, I find this design choice of the Swift string to be interesting, but weird. They are optimizing for 1% of the cases, hurting peformance for the other 99%. There is a workaround, but it is not pretty. But hey, the language is young, so maybe in 1.3?

Benchmark on a mobile device

Well, if you’re like us and developing a Scala library to be used with an existing app, it is useful to benchmark your lib externally. Usually performance bottlenecks that you’ll solve after running a benchmark from command line will translate to your app, and it is so much easier to benchmark on your PC and not on a mobile device. But the word ‘usually’ there is important. The HotSpot JVM and Dalvik (=Android’s VM) are quite different beasts, and memory constraints on your mobile device are also very different.

Therefore, I found it useful to build a standalone app in order to test my library’s performance. It has one button, which I programmed to call my library in different scenarios. It prints out how long it took to run the scenario (Side note: it was surprising to find out that my PC is ~100 times faster than my Nexus 4, which means that every 1 millisecond I measured on my PC is a whopping 100ms on mobile!).

Beware of the GC

After I built a demo app, I started clicking my big “TEST PERF” button, and noticed the printouts on my logcat (you should know that calls to “println” from Scala appear there (as Log.i), so it is useful to print out timing information from within your Scala code). I immediately noticed many messages, similar to this:

GC_FOR_ALLOC freed 362K, 13% free 4116K/4688K, paused 181ms, total 182ms

This means that the GC kicked in, and paused my app for 181ms, which is A LOT. But hey, you may ask, it seems the GC points out that my heap is 4688K, which is a lot less than my app’s heap size limit! Well, Dalvik doesn’t allocate a very big heap for your app initially. It grows it slowly. And before it grows it, it will attempt to free up memory. Hence, the above depressing message. How do we deal with this? Well, the best thing to do is try to allocate less memory! Let’s try that then.

Analyzing your heap

Using the Android DDMS, or in my case, the built-in Intellij plugin for Android, you can dump your device’s heap. I did so after clicking the “TEST PERF” button a couple of times, but before a GC was triggered. This allows me to check out the temporary objects I created in a profiler. I’m using YourKit profiler, which is a paid one, but the resulting hprof file (which IntelliJ helpfully converts to the standard format, if you’re a DDMS user you have to use the hprof–conv command line) can be viewed in any decent profiler, I believe. I started checking out the objects which are unreachable from the GC root – these are the temporary objects that the GC will collect, and my main problem. I came up with a few conclusions, which I think will be useful to any Scala on Android developer.

The Scala tax

Scala loves to create short lived objects. Android and Dalvik don’t like these so much. But not all is lost, Scala is still extremely usable under these conditions, you just have to be careful in how you use it.

Vectors – careful with those

Vector is the default IndexedSeq implementation, and it is a great data structure, in fact our “go to” data structure usually. But you need to be careful with it:

1. The Vector will allocate an Object[32] array to hold a single item. That’s a waste on our low memory machine. Consider using Arrays instead of Vectors where appropriate to overcome this issue.
2. Using IndexedSeq() to create an empty vector will create a redundant Object[32] array. You should use IndexedSeq.empty or Vector.empty instead.
3. Vector.tail is more costly than List.tail, as it creates a new Vector. If you have a recursive function that uses.head and .tail (a common pattern in Scala and other functional languages), consider using a list, or access your vector using the indexer (e.g. myVector(5)).

Method chaining – embrace .view

So you have a vector, an array or a list, and you’re doing something like vector.map(…).filter(…).map(…). Bad idea. In this example, you’ll be allocating a temporary vector after each method call. Instead, do a vector.view.map(…).filter(…).map(…).toVector. This will make sure you only allocate one vector, at the end of the chain.

Boxing is your enemy

Oh man, how I wish the JVM had the CLR’s generics and value types support. Unfortunately, it does not. This means that your beautiful generic function, which can work on any type, will probably cause boxing when used with primitive types. You might see it in your profiler as scala.runtime.BoxesRunTime.boxToInteger(int) or similar calls. Here’s some tips on avoiding boxing:

• You can try using the @specialized annotation on your generic method or class. It doesn’t work in every case, and in one critical place in my code I had to…
• Copy & paste some functions to work directly with an Integer.
• Beware of using Option[Int]. It will box your integer. I have a lot of these, and haven’t yet decided the best approach. I might change my code to return –1 as the “None” value, or consider using this alternative Option class.
• Some lambda expressions, which are based on classes that are not specialized, will cause your primitive to box. You might want to skip the lambdas in this case.

While instead of for

Scala for loops might not be what you think they are. They are more like C# Linq expressions than C# for or foreach. They get translated to map() and withFilter() calls with anonymous function for the loop body. This means that code like:

for(index <- 0 until s.size){
 //do stuff
}

Will allocate:

• An object for the anonymous function that represents the loop’s body
• A Range object for the (0 until s.size) expression

This can be easily replaced with a while loop that does none of the above:

var index = 0
while (i < s.size) {
//do stuff
 i+=1
}

Yes, this is uglier, and I don’t recommend doing it everywhere. Just in the places that hurt the most (get called most often).

Beware of implicit conversions

Sometimes Scala will implicitly wrap your object with another object. Say you’re calling str.indexWhere(c=>c.isUpper). Did you know that your string is being wrapped with a StringOps object, and your char is being wrapped with a RichChar object? This might cause redundant allocations where you least expect them. In one performance critical place, I ended replacing an indexWhere call with a static function I created, that skipped both the StringOps conversion and the lambda expression altogether.

Scala’s Map gotcha

Scala’s Map.get, will wrap your value in an Option. Very convenient, I admit, but sometimes you just can’t afford the extra allocation. This sucks, but I had to use Java’s HashMap in one place to avoid this.

Conclusion & Disclaimer

My suggestions are things you should pay attention to, but you should only apply them where it hurts and after you noticed them in a profiler. You don’t want to pre-optimize your code, as you’ll just end up with uglier, not necessarily faster (or more memory efficient) code. Still, you should be very aware of where your code allocates memory when running on Android. Dump you heap, and optimize away. Good luck!

Let’s say you defined this case class:

case class Person (name: String, age: Int, salary: Double, isNice:Boolean = false)

You can write a collection of Person to a .csv file this way:

import com.gingersoftware.csv.ObjectCSV._
//...
val person1 = new Person("Doron,y",10,5.5)
val person2 = new Person("David",20,6.5)
writeCSV(IndexedSeq(person1,person2), fileName)

val peopleFromCSV = readCSV[Person](fileName)
assert(peopleFromCSV === IndexedSeq(Person("Doron,y",10,5.5),Person("David",20,6.5)))

Nice and simple, right? It serves our needs nicely, but it comes with some caveats:

1) It only works with Scala 2.11, as it uses scala.reflect which wasn’t really stable on 2.10. So make sure you have set scalaVersion := “2.11.0” in your build.sbt.

2) It only works with case classes, as all the reflection stuff is based on using your case class primary constructor.

3) For reading, we only currently support the following data types: Int, Double, Boolean and String. We’ll probably add more as we need them. Writing works with everything, as we just .toString it all.

4) We can only read/write CSV files with headers, and the header must begin with the comment mark (#).

5) The API currently doesn’t expose ways to control the type of separator used in the CSV file, but it is very easy to add (the scala–csv project does support it).

6) We didn’t test it for speed, reading is likely to be slow as it uses reflection heavily.

libraryDependencies += "com.gingersoftware" % "object-csv_2.11" % "0.1"

   1: public class SplunkAppender : IAppender

   2:     {        

   3:         public async void DoAppend(log4net.Core.LoggingEvent loggingEvent)

   4:         {

   5:             var clientIp = _clientIpRetriever.GetClientIp();

   6:             var message = new SplunkMessage(loggingEvent.Level, loggingEvent.ExceptionObject, clientIp);

   7:             var success = await _splunkLogger.Report(message);

   8:             //do something unimportant

   9:         }

  10:  

  11:         public void Close() { }

  12:         public string Name {get; set;}        

  13:     }

   1: Unhandled Exception: System.Exception: Exception of type 'System.Exception' was thrown.

   2:    at ConsoleApplication1.ClientIpRetriever.GetClientIp() in d:\Projects\Blog\ConsoleApplication1\Program.cs:line 25

   3:    at ConsoleApplication1.SplunkAppender.<DoAppend>d__0.MoveNext() in d:\Projects\Blog\ConsoleApplication1\Program.cs:line 34

   4: --- End of stack trace from previous location where exception was thrown ---

   5:    at System.Runtime.CompilerServices.AsyncMethodBuilderCore.<ThrowAsync>b__5(Object state)

   6:    at System.Threading.QueueUserWorkItemCallback.WaitCallback_Context(Object state)

   7:    at System.Threading.ExecutionContext.RunInternal(ExecutionContext executionContext, ContextCallback callback, Object state, Boolean preserveSyncCtx)

   8:    at System.Threading.ExecutionContext.Run(ExecutionContext executionContext, ContextCallback callback, Object state, Boolean preserveSyncCtx)

   9:    at System.Threading.QueueUserWorkItemCallback.System.Threading.IThreadPoolWorkItem.ExecuteWorkItem()

  10:    at System.Threading.ThreadPoolWorkQueue.Dispatch()

  11:    at System.Threading._ThreadPoolWaitCallback.PerformWaitCallback()

Hmm. Pretty obvious. GetClientIp Throws an exception, which is not caught, erm, anywhere. But wait a minute, surely log4net handles exceptions thrown by appenders, right? And even if it doesn’t it should make a single request fail, not the entire-freaking-process?!

Then I looked at the stack trace, which contains stuff like AsyncMethodBuilderCore and I realized this happens because it’s an async method. Stephen Cleary had this to say about async void methods:

Async void methods have different error-handling semantics. When an exception is thrown out of an async Task or async Task<T> method, that exception is captured and placed on the Task object. With async void methods, there is no Task object, so any exceptions thrown out of an async void method will be raised directly on the SynchronizationContext that was active when the async void method started.

In order to simplify error handling, an async method will never throw an exception to the calling code. The exception can be observed via the created Task. Otherwise you’d have to handle in a different way the case of an exception thrown before the await call and after it. But as Stephen Cleary says above, there is simply no way to catch an exception thrown by an async void method, except for the AppDomain.UnhandledException event or something of the sort.

In my case, GetClientIp threw an exception. The calling code is an async void method, so the exception was never caught and it crashed the process. FUN. The solution? Don’t use an async void method, and if you do, make sure to catch your exceptions! I ended up with something that looked like this:

   1:  

   2:     public class SplunkAppender : IAppender

   3:     {        

   4:         public void DoAppend(log4net.Core.LoggingEvent loggingEvent)

   5:         {

   6:             var clientIp = _clientIpRetriever.GetClientIp();

   7:             var message = new SplunkMessage(loggingEvent.Level, loggingEvent.ExceptionObject, clientIp);

   8:             SendMessageToSplunk(message);

   9:         }

  10:  

  11:         private async void SendMessageToSplunk(SplunkMessage message)

  12:         {

  13:             try

  14:             {

  15:                 var success = await _splunkLogger.Report(message);

  16:                 //do something unimportant

  17:             }

  18:             catch(Exception x)

  19:             {

  20:                 LogLog.Error(GetType(), "Error in SplunkAppender.", x);

  21:             }            

  22:         }

  23:         public void Close() { }

  24:         public string Name {get; set;}        

  25:     }

The DoAppend method is not async anymore, so any exception will be thrown and caught in the standard way. I do still have an async void helper method, but it is protected with a try-catch clause, and so production has been stable ever since.

The command ~*e!clrstack (=view stack trace of all managed threads) showed us that most of the threads are deadlocked in log4net’s AppenderSkeleton class. It looks something like this:

   1: public void DoAppend(LoggingEvent loggingEvent) 

   2: {

   3:     lock(this)

   4:     {

   5:         //bla bla bla... do some stuff

   6:         Append(loggingEvent); //method in child class

   7:         //bla bla bla... do more stuff                

   8:     }

   9: }

Lo and behold! There’s some locking here. I wasn’t even aware that log4net is locking on each call to Append, although it makes sense of course when your usual task is writing to files (one could suggest that there are better ways to approach that as well, and one would probably be right). Our own custom appender isn’t really writing to files, it sends log messages to Splunk (a pretty awesome system, albeit very expensive).

   1: public class SplunkAppender : AppenderSkeleton

   2:    {

   3:        protected override async void Append(log4net.Core.LoggingEvent loggingEvent)

   4:        {

   5:            var message = new SplunkMessage(loggingEvent.Level, loggingEvent.ExceptionObject);

   6:            var success = await _splunkLogger.Report(message);

   7:            //do something with the success status, not really relevant

   8:        }

   9:    }

I know what you’re thinking. Why is your append method async? Well, since logging to Splunk is a networked operation, we don’t want it to be done on the current thread. So our own SplunkLogger just puts messages in a queue, and a dedicated thread will send them to Splunk. But we also want to know if and when the message was succesfully sent. Hence, an async task that only completes when the message is actually sent.

You’ve probably figured out right now what happended to our threads by now. If for whatever reason messages are stuck in the queue and not being sent, then the lock in DoAppend is never released! The Monitor.Exit() call won’t happen until the task returns, as the async/await system rightfully makes sure of that. Log calls from other threads will never be able to complete.

Once we figured this out, the solution was simple. Stop locking! Our SplunkLogger is thread-safe anyway, so this wasn’t required at all in the first place. Unfortunately this means we had to leave the conveinence of AppenderSkeleton and directly implement IAppender. You lose some filters and formatting support there, but luckily for us we weren’t really using these features in this appender.

Less luckily for us, there were more problems with this code. More on that in the next post, stay tuned.

The source code for the converted project can be found on GitHub, and the binaries can be found here.

Now, before I tell you a bit about the conversion process, here are a few important notes:

• This is not the full CJ parser. This is the first-stage Charniak parser only (Aug06 version). The re-ranking second stage was not converted.
• We converted only the non-multithreaded version of the main loop (oparseit.c and not parseit.c). Still, the parsing code should support calls from multiple threads should you choose to do so (up to the MAXNUMTHREADS parameter which defaults to 4).
• This is a completely native version of the parser, it doesn’t need cygwin/mingw32 or anything of the sort.
• It does need, however, the Visual C++ 2012 Redistributables to run.
• You need Visual Studio 2012 to open the project (but you can probably easily port it to older VS versions).
• We are not actually using this in our product, anywhere. We thought about using it, but we’re not. This is provided ‘as is’ as a service to the community, and the original license of the parser remains in place.

So now that the formalities are out of the way, here are some details about the conversion process. First, I should note that I am no C++ expert. C# is my thing, and while I did some C/C++ projects in the university, it was quite a while ago. Therefore, it was not an easy task and it took me a few days to get the entire thing to work. Here are some things I had to do (probably not all, this was a long time ago):

• Convert all the .c files to .cpp files so Visual Studio will be happy with the code using C++ constructs.
• Fix header issues of all sorts (like using #stdafx.h everywhere).
• Add unicode support by changing all the constant strings to have the L macro applied on them, use wchar_t everywhere in the code, use wistream and friends instead of istream and friends, etc.
• Figuring out code and files that are not needed for pure parsing and get rid of them. The less files I have to touch, the better. So for instance, I got rid of all the EvalTree stuff in the original parser (a different command which evaluates parse trees. Didn’t need that).

The biggest headache, though, was the performance issue. For some reason, the parser performed much worse on Windows than on Linux, and it was pretty hard to understand why. I ended up using the Visual Studio C++ profiler, and traced the issue to a line that allocates a large array of objects. Digging a little further, I noticed that each allocated object contains a large std::list, so in fact, I was allocating lots of lists. The code basically boils down to this:

list<char*>* item = new list<char*>[160000]; 

I measured the code above to be 10 times slower on Windows than on Linux. Funky, eh? At first I thought that memory allocation on Windows is slower than on Linux. Who knows, right? Well, the folks at StackOverflow helped me realize that memory allocation has nothing to do with this, it is actually the std::list constructor that is slower in the Microsoft implementation, probably because it allocates a bigger initial buffer. Once I knew this, I was able to tweak to code to dynamically allocate the std::lists, so I was able to create a lot less of them. This solved the performance issue, and in fact I measured the parser to be even faster on Windows that on Linux now.

That’s it for now, I guess. If you have any questions about using the binaries or the code posted above, please contact me.

   1: Document document = new Document();

   2: document.add(new Field("ngram", ngram, Field.Store.YES, Field.Index.ANALYZED));

   3: NumericField frequencyField = new NumericField("frequency", Field.Store.YES, true);

   4: frequencyField.setLongValue(frequency);

   5: document.add(frequencyField);

As you can see, we are indexing and storing both the ngram and the frequency fields, where one is a string and the other is a long.

After the indexing was done, we wanted to search the index. Our main use case for searching is this: take a bunch of words, and return the most frequent n-grams that contain them. My natural inclination was to use sorting for this, by using IndexSearcher.search(Query query, int n, Sort sort). This allows us to supply a Sort object that would sort by the frequency field in descending order.

This turned out to be a bad idea. Lucene handles sorting by using the FieldCache. This means it tried to load all the frequencies of all the n-grams in the index into an array. This is a lot of data to load, and an OutOfMemoryException was thrown. But then I realized that I always wanted results to return ordered by frequency. I don’t need different result sets to be sorted by different fields, so this information should be stored in the index itself and shouldn’t require a cache.

Therefore, I arrived at the concept of Scoring. Scoring in Lucene determines how results are ordered by default, which is exactly what I needed. The default algorithm attempts to return the results most relevant to a given query, and I wanted to spice it up with my frequency information. The way you do that in Lucene is by using document level boosting. This allows you to say that a specific document is more relevant than others. At first I did the naive thing and set the boost to be the frequency, like this:

   1: document.setBoost(frequency);

It even seemed to work for a while, but then I noticed a couple of issues:

1. The boost factor was too dominant: Lucene sometimes preferred to return n-grams with less query words, but have a greater frequency, over n-grams with more query words, but with less frequency. So, for instance if I search for “pleasure meet you” it would prefer “I want to meet you” (100000 frequency) over “pleasure to meet you” (10000 frequency). This caused me to revise my perspective: I don’t always want results to be returned ordered by frequency, the amount of contained query words is an important factor as well.
2. Sometimes results weren’t exactly ordered by frequency. An n-gram with 1000 frequency seemed to have exactly the same score as an n-gram with 10000 frequency, even though it was given a higher boost factor.

While the first issue was rather obvious, the second one had me baffled for a while. It turns out even though the boost value is a float, it is stored as only a byte, as the document norm. This value combines the document boost, the field boost (individual fields can be boosted as well, not useful for my case) and a length factor, which basically says that shorter documents are better (again not relevant for me, all the n-grams in a single index have the same length). So basically, we took a long (the frequency), which has a huge range of different values, and stuffed it into a byte which only allows for 256 different values. Obviously, I’m going to lose a bit of precision here.

The solution to both issues was to compute the boost in a different way. Instead of setting it to the frequency, we will set it to some function of the frequency. This should achieve:

1. Smaller values for the boost factor, so it doesn’t override the coordination factor, which causes documents with more query terms to get a higher score.
2. A better ordering of n-grams by frequency. An n-gram with 2000 frequency should get a higher score than an n-gram with 1000 frequency, but I don’t care if an n-gram with 110000 frequency has the same score as 100000 frequency. In essence, I can afford losing precision at the higher ranges of frequency, but less so in the lower ranges.

The function we came up with looks something like this:

   1: public static float getBoost(long frequency) {

   2:     double boost = (Math.log(frequency) / Math.log(1.5)) * 10;

   3:     if (boost > 255)

   4:         return 255;

   5:     return Math.round((float)boost);

   6: }

Basically, we want the boost to be a number between 1 and 255 (which achieves our first goal of smaller boost values). By taking a log of the frequency (base 1.5) we are not only getting smaller values, but also achieving our second goal, of better precision for lower frequency values.  Above a certain threshold, all the n-grams will have the same boost factor of 255.

At this point I thought I was done, but I was still seeing precision loss. Lucene’s default way of encoding a float to a byte and vice versa didn’t suit me; It tries to represent a large range of values when I just need to use 1-255. Therefore, I had to create my own Similarity class which overrides this behaviour.

   1: public class NgramSimilarity extends DefaultSimilarity { 

   2:     @Override

   3:     public float computeNorm(String field, FieldInvertState state) {

   4:        return state.getBoost();    //ignore length factor

   5:    }     

   6:     @Override

   7:     public byte encodeNormValue(float f) {

   8:         return (byte)f;

   9:     }

  10:     @Override

  11:     public float decodeNormValue(byte b) {

  12:         return b & 0xFF; //makes the byte unsigned so we can use the full 0-255 range

  13:     }

  14: }

First, since the length factor is irrelevant to us, we override computeNorm in order to ensure that norm = boost only. Second, as you can see, the encoding method is quite simple, and just casts the float to byte. We know for sure that the boost is in the range of 1-255 and that norm = boost, so we can safely cast. The decoding method is a little weirder; Apparently Java’s byte is signed (unlike C#’s byte which is unsigned). A simple cast back from byte to float would have a given us a negative number, hence we apply the 0xFF mask.

We now just have to apply our Similarity class to IndexWriter, like this:

   1: IndexWriterConfig indexWriterConfig = new IndexWriterConfig(Version.LUCENE_35, analyzer);

   2: indexWriterConfig.setSimilarity(new NgramSimilarity());

   3: IndexWriter writer = new IndexWriter(directory, indexWriterConfig);

It is also important to remember to use the custom Similarity class when searching (that’s when decodeNormValue is called):

   1: IndexSearcher searcher = new IndexSearcher(reader);

   2: searcher.setSimilarity(new NgramSimilarity());

And now we’re done.

My only niggle about Lucene is the documentation; It has excellent documentation, but only in the form of a book (which I read and enjoyed). But a PDF book is a lot less cosy to work with than something that is truly online (like blog posts). You can’t google and get results from Lucene In Action. Other than that, I would say that Lucene has been a perfect fit for our purpose. It is easily customizable, so we could tune it to our specific needs, and gives excellent query performance.  Open source is awesome, isn’t it?

serviceHost.Open();

while (Console.ReadKey().Key != ConsoleKey.Q)

{

    Console.WriteLine("Press Q to exit");

}

Basically, we start a WCF service, and wait for the user to press Q to exit the application. Fairly standard, and used to work until .NET 4.5.

Digging a little further, I found out that the system was stuck on some third-party code which was doing something like:

Console.Error.WriteLine("Error!");

We have other places that write to stdout (Console.WriteLine), but this seems to be the only place that writes to stderr (and only in very specific cases, which is why I didn’t notice it until today).

In order to reproduce the issue, I wrote the following program:

public static void Main()

{            

    var readTask = new Task(() =>

                                {

                                    Console.WriteLine("enter something");

                                    Console.ReadKey();

                                });

    var writeTask = new Task(() => Console.Error.WriteLine("hello"));

    readTask.Start();

    Thread.Sleep(100);            

    writeTask.Start();

    Task.WaitAll(readTask, writeTask);

}

We have two threads, one waits for an input from the user, and the other writes to Console.Error. This program will never terminate under .NET 4.5 (at least until you press a key), but will terminate under .NET 4.0. Fun! Let’s compare the .NET 4.5 and 4.0 source code in order to find out what happens here. Here is Console.ReadKey in .NET 4.5:

   1: Win32Native.InputRecord ir;

   2: int numEventsRead = -1; 

   3: bool r;

   4:  

   5: lock (InternalSyncObject) {

   6:    if (_cachedInputRecord.eventType == Win32Native.KEY_EVENT) { 

   7:        // We had a previous keystroke with repeated characters.

   8:        ir = _cachedInputRecord; 

   9:        if (_cachedInputRecord.keyEvent.repeatCount == 0) 

  10: ....

Can you see the lock in line 5? It doesn’t exist in the .NET 4.0 source. And here’s Console.Error in both .NET 4.0 and 4.5:

   1: public static TextWriter Error {

   2:     [HostProtection(UI=true)] 

   3:     get { 

   4:         Contract.Ensures(Contract.Result<TextWriter>() != null);

   5:         // Hopefully this is inlineable. 

   6:         if (_error == null)

   7:             InitializeStdOutError(false);

   8:         return _error;

   9:     } 

  10: }

As you can see, if this is the first time we’re using the stream it will try to initialize it. So let’s see the initialization code (again, for both .NET 4.0 and 4.5).

   1: private static void InitializeStdOutError(bool stdout) 

   2: { 

   3:     // Set up Console.Out or Console.Error.

   4:     lock(InternalSyncObject) { 

   5:         if (stdout && _out != null)

   6:             return;

   7:         else if (!stdout && _error != null)

   8:             return; 

   9: ....

Hmm, that lock seems familiar! This is what’s causing our code to deadlock. Console.ReadKey now locks a synchronization object which gets locked when you attempt to access stderr for the first time. Therefore, the solution is simple, we need to cause Console.Error to initialize before the call to Console.ReadKey.

   1: Console.Error.WriteLine("Initializing stderr to prevent threading issues...");

   2:  

   3: serviceHost.Open();

   4: while (Console.ReadKey().Key != ConsoleKey.Q)

   5: {

   6:     Console.WriteLine("Press Q to exit");

   7: }

Note that this may happen to you even if you’re targeting .NET 4.0, as long as you have .NET 4.5 installed. This is because .NET 4.5 is an in-place replacement for .NET 4.0, so you’re always running with the safer (and deadlock-causing) Console.ReadKey() if you installed the new framework version.