Miłosz Orzeł

.net, js, html, arduino, java... no rants or clickbaits.

How fast is .NET Garbage Collector? Part 2.

Read the first part of the article if you haven’t done so already. Part 1 has a brief overview of what GC is and how it performs its magic. It contains a test of GC performance with regards to large array of bytes. You can also find there a detailed information about my test environment…

This part will focus on scenarios which put a lot more pressure on GC and appear more commonly in real world applications. You will see that even a tree of more than 100 million objects can be handled quickly… But first let’s see how GC responds to big array of type object:

static void TestSpeedForLargeObjectArray()
{
    Stopwatch sw = new Stopwatch();

    Console.Write(string.Format("GC.GetTotalMemory before creating array: {0:N0}. Press key any to create array...", GC.GetTotalMemory(true)));
    Console.Read();
    object[] array = new object[100 * 1000 * 1000]; // About 800 MB (3.2 GB when filled with object instances)
             
    sw.Start();
    for (int i = 0; i < array.Length; i++)
    {
        array[i] = new object();
    }
    Console.WriteLine("Setup time: " + sw.Elapsed);
    Console.WriteLine(string.Format("GC.GetTotalMemory after creating array: {0:N0}. Press Enter to set array to null...", GC.GetTotalMemory(true)));

    if (Console.ReadKey().Key == ConsoleKey.Enter)
    {
        Console.WriteLine("Setting array to null");
        array = null;
    }
    
    sw.Restart();
    GC.Collect();
    Console.WriteLine("Collection time: " + sw.Elapsed);
    Console.WriteLine(string.Format("GC.GetTotalMemory after GC.Collect: {0:N0}. Press any key to finish...", GC.GetTotalMemory(true)));

    Console.WriteLine(array); // To avoid compiler optimization...
    Console.ReadKey();
}

Above test creates and array of 100 million items. Initially such array takes about 800 megabytes of memory (on x64 platform). This part is allocated on LOH. When object instances are created total heap allocation jumps to 3.2 GB. Array items are tiny so they are part of Small Object Heap and initially belong to Gen 0.

Here are the test results for situation when array is set to null:

GC.GetTotalMemory before creating array: 41,736. Press key any to create array...
Press any key to fill array...
Setup time: 00:00:07.7910574
GC.GetTotalMemory after creating array: 3,200,057,616. Press Enter to set array to null...
Setting array to null
Collection time: 00:00:00.7481998
GC.GetTotalMemory after GC.Collect: 57,624. Press any key to finish...

It took only about 700 ms to reclaim over 3 GB of memory!

Take a look at this graph from Performance Monitor:

Managed memory counters for large object[] array; setting array to null... Click to enlarge...

You can see that while program was filling the array, Gen 0 and Gen 1 changed size (notice though that the scale for these is 100x bigger than scale for other counters). This means that GC cycles were triggered while items were created - this is expected behavior. Notice how Gen 2 and LOH size adds up to total bytes on managed heap.

What if instead of setting array reference to null we set array items to null?

Let’s see. Here’s the graph:

Managed memory counters for large object[] array; setting array items to null... Click to enlarge...

Notice that after GC.Collect is done 800 MB are still allocated - this is LOH memory held by array itself…

Here are the results:

GC.GetTotalMemory before creating array: 41,752. Press key any to create array...
Press any key to fill array...
Setup time: 00:00:07.7707024
GC.GetTotalMemory after creating array: 3,200,057,632. Press Enter to set array elements to null...
Setting array elements to null
Collection time: 00:00:01.0926220
GC.GetTotalMemory after GC.Collect: 800,057,672. Press any key to finish...

Ok, enough with arrays. One can argue that as continues blocks of memory they are easier to handle then complex objects structures that are abundant in real word programs.

Let’s create a very big tree of small reference types:

static int _itemsCount = 0;

class Item
{
    public Item ChildA { get; set; }
    public Item ChildB { get; set; }
    
    public Item()
    {
        _itemsCount++;
    }           
}

static void AddChildren(Item parent, int depth) 
{
    if (depth == 0)
    {
        return;
    }
    else
    {
        parent.ChildA = new Item();
        parent.ChildB = new Item();

        AddChildren(parent.ChildA, depth - 1);
        AddChildren(parent.ChildB, depth - 1);                
    }
}

static void TestSpeedForLargeTreeOfSmallObjects()
{
    Stopwatch sw = new Stopwatch();

    Console.Write(string.Format("GC.GetTotalMemory before building object tree: {0:N0}. Press any key to build tree...", GC.GetTotalMemory(true)));
    Console.ReadKey();

    sw.Start();
    _itemsCount = 0;       
    Item root = new Item();            
    AddChildren(root, 26);
    Console.WriteLine("Setup time: " + sw.Elapsed);
    Console.WriteLine("Number of items: " + _itemsCount.ToString("N0"));

    Console.WriteLine(string.Format("GC.GetTotalMemory after building object tree: {0:N0}. Press Enter to set root to null...", GC.GetTotalMemory(true)));

    if (Console.ReadKey().Key == ConsoleKey.Enter)
    {
        Console.WriteLine("Setting tree root to null");
        root = null;                
    }
    
    sw.Restart();
    GC.Collect();
    Console.WriteLine("Collection time: " + sw.Elapsed);
    Console.WriteLine(string.Format("GC.GetTotalMemory after GC.Collect: {0:N0}. Press any key to finish...", GC.GetTotalMemory(true)));
                
    Console.WriteLine(root); // To avoid compiler optimization...            
    Console.ReadKey();
}

The test presented above creates a tree with over 130 million nodes which take almost 4.3 GB of memory.

Here’s what happens when tree root is set to null:

GC.GetTotalMemory before building object tree: 41,616. Press any key to build tree...
Setup time: 00:00:14.3355583
Number of items: 134,217,727
GC.GetTotalMemory after building object tree: 4,295,021,160. Press Enter to set root to null...
Setting tree root to null
Collection time: 00:00:01.1069927
GC.GetTotalMemory after GC.Collect: 53,856. Press any key to finish...

Managed memory counters for large tree of small objects; setting tree root to null... Click to enlarge...

It took only 1.1 second to clear all the garbage! When root reference was set to null all nodes below it became useless as defined by mark and sweep algorithm… Notice that this time LOH is not utilized as no single object instance is over 85 KB threshold.

Now let’s see what happens when the root is not set to null and all the objects survive GC cycle:

GC.GetTotalMemory before building object tree: 41,680. Press any key to build tree...
Setup time: 00:00:14.3915412
Number of items: 134,217,727
GC.GetTotalMemory after building object tree: 4,295,021,224. Press Enter to set root to null...
Collection time: 00:00:03.7172580
GC.GetTotalMemory after GC.Collect: 4,295,021,184. Press any key to finish...

This time it took 3.7 sec (less than 28 nanoseconds per reference) for GC.Collect to run – remember that reachable references put more work on GC then dead one!

There is one more scenario we should test. Instead of setting root = null let's set root.ChildA = null. This way half of the tree would became unreachable. GC will have a chance to reclaim memory and compact it to avoid fragmentation. Check the results:

GC.GetTotalMemory before building object tree: 41,696. Press any key to build tree...
Setup time: 00:00:15.1326459
Number of items: 134,217,727
GC.GetTotalMemory after creating array: 4,295,021,240. Press Enter to set root.ChildA to null...
Setting tree root.ChildA to null
Collection time: 00:00:02.5062596
GC.GetTotalMemory after GC.Collect: 2,147,537,584. Press any key to finish...

Time for final test. Let’s create a tree of over 2 million complex nodes that contain some object references, small array and unique string. Additionally lets fill some of the MixedItem instances with byte array big enough to be put on Large Object Heap.

static int _itemsCount = 0;

class MixedItem
{
    byte[] _smallArray;
    byte[] _bigArray;
    string _uniqueString;

    public MixedItem ChildA { get; set; }
    public MixedItem ChildB { get; set; }

    public MixedItem()
    {
        _itemsCount++;

        _smallArray = new byte[1000];
        if (_itemsCount % 1000 == 0)
        {
            _bigArray = new byte[1000 * 1000];
        }

        _uniqueString = DateTime.Now.Ticks.ToString();
    }
}

static void AddChildren(MixedItem parent, int depth)
{
    if (depth == 0)
    {
        return;
    }
    else
    {
        parent.ChildA = new MixedItem();
        parent.ChildB = new MixedItem();

        AddChildren(parent.ChildA, depth - 1);
        AddChildren(parent.ChildB, depth - 1);
    }
}

static void TestSpeedForLargeTreeOfMixedObjects()
{
    Stopwatch sw = new Stopwatch();

    Console.Write(string.Format("GC.GetTotalMemory before building object tree: {0:N0}. Press any key to build tree...", GC.GetTotalMemory(true)));
    Console.ReadKey();

    sw.Start();
    _itemsCount = 0;
    MixedItem root = new MixedItem();
    AddChildren(root, 20);
    Console.WriteLine("Setup time: " + sw.Elapsed);
    Console.WriteLine("Number of items: " + _itemsCount.ToString("N0"));

    Console.WriteLine(string.Format("GC.GetTotalMemory after building object tree: {0:N0}. Press Enter to set root to null...", GC.GetTotalMemory(true)));

    if (Console.ReadKey().Key == ConsoleKey.Enter)
    {
        Console.WriteLine("Setting tree root to null");
        root = null;
    }

    sw.Restart();
    GC.Collect();
    Console.WriteLine("Collection time: " + sw.Elapsed);
    Console.WriteLine(string.Format("GC.GetTotalMemory after GC.Collect: {0:N0}. Press any key to finish...", GC.GetTotalMemory(true)));

    Console.WriteLine(root); // To avoid compiler optimization...
    Console.ReadKey();
}

How will GC perform when subjected to almost 4.5 GB of managed heap memory with such complex structure? Test results for setting root to null

GC.GetTotalMemory before building object tree: 41,680. Press any key to build tree...
Setup time: 00:00:11.5479202
Number of items: 2,097,151
GC.GetTotalMemory after building object tree: 4,496,245,632. Press Enter to set root to null...
Setting tree root to null
Collection time: 00:00:00.5055634
GC.GetTotalMemory after GC.Collect: 54,520. Press any key to finish...

Managed memory counters for large tree of mixed objects; setting tree root to null... Click to enlarge...

And in case you wonder, here's what happens when root is not set to null:

GC.GetTotalMemory before building object tree: 41,680. Press any key to build tree...
Setup time: 00:00:11.6676969
Number of items: 2,097,151
GC.GetTotalMemory after building object tree: 4,496,245,632. Press Enter to set root to null...
Collection time: 00:00:00.5617486
GC.GetTotalMemory after GC.Collect: 4,496,245,592. Press any key to finish...

So what it all means? The conclusion is that unless you are writing applications which require extreme efficiency or total guarantee of uninterrupted execution, you should be really glad that .NET uses automatic memory management. GC is a great piece of software that frees you from mundane and error prone memory handling. It lets you focus on what really matters: providing features for application users. I’ve been professionally writing .NET applications for past 8 years (enterprise stuff, mainly web apps and Windows services) and I’m yet to witness1 a situation when GC cost would be a major factor. Usually performance bottleneck lays in things like: bad DB configuration, inefficient SQL/ORM queries, slow remote services, bad network utilization, lack of parallelism, poor caching, sluggish client side rendering etc. If you avoid basic mistakes like creating to many strings you probably won’t even notice that there is a Garbage Collector :)

Update 31.08.2014: I've just run the most demanding test (big tree of small reference types with all objects surviving GC cycle) on my new laptop. The result is 3.3s compared to 3.7s result presented in the post. Test program: .NET 4.5 console app in Release mode run without debugger attached. Hardware: i7-4700HQ 2.4-3.4GHz 4 Core CPU, 8GB DDR3/1600MHz RAM. System: Windows 7 Home Premium x64.

1. I’ve met some out of memory exceptions related to LOH fragmentation. The good thing is that LOH algorithms are improving and x86 platform, which is especially susceptible to such errors, is becoming a thing of the past…

How fast is .NET Garbage Collector? Part 1.

.NET GC is very fast! Well... I hope you need more than this reassuring statement, if so, read on :) I will show you some test results to prove that I’m not lying but first I will give you a quick reminder about what GC is:

Garbage Collector is fundamental component of .NET CLR. It takes care of freeing managed heap memory so a programmer doesn’t have to think about deallocation. Contrary to popular belief, GC handles memory occupied for both reference and value types. Why? Because quite often space for things like structures or integers is allocated on the heap. It happens for example when value type is an item of array or is a field in a class instance.

GC in .NET uses mark and sweep algorithm: it walks through objects graph starting from root elements (such us statics, references on stack or registers) and marks every object it can reach. When the walk is done, GC knows it can safely free the memory of objects that have not been marked – because as unreachable they are useless for the application.

For efficiency purposes GC supports notion of generations. When the object is created it belongs to Gen 0 (except for so called large objects). If Gen 0 object survives GC cycle it’s moved to Gen 1. If it survives one more cycle it goes to Gen 2 and stays there (there’s no Gen 31). Most objects are short lived – they don’t get pass Gen 0 or Gen 1 so .NET GC tries to free memory from lower generations first. It does Gen 2 (aka full collection) far less often then Gen 0 collection. If the object is big – above 850002 bytes it is allocated in Large Object Heap (LOH) and goes straight to Gen 2. Treating big objects the same way as small objects would have negative impact on heap defragmentation3 algorithms because moving such objects is time-consuming.

GC supports different modes for workstation and server configurations, is able to do some work in background threads, has to consider special cases like finalizers or pined memory buffers, its settings vary between platforms (e. g. CLR on PC is not the same as the one on Xbox)… well let’s stop here – I’ve promised a “quick reminder”! 

Ok, time for the test! 

In this first post I will show you how fast .NET GC can handle large arrays of value (non-reference) types. The test will involve an array of bytes that occupies about two gigabytes of memory. Despite its large size, such object does not put much pressure on the Garbage Collector. This is because the only reference GC has to check is the one for the array itself. If array becomes unreachable all memory occupied by its elements can be safely reused. Additionally, such array, being part of LOH, is not copied (to avoid heap fragmentation) when it survives collection cycle… In the second installment of this article I will show you how GC can handle more complex scenarios. We will examine performance for object array, and more importantly, a tree of objects with thousands of references… 

Note about test environment: I’ve run the test code on desktop PC with Intel i-5 2400 3.1 GHz 4 Core CPU, 12 GB of DDR 3/1333 RAM, running Windows 7 Ultimate x64. The program was a .NET 4.0 console application compiled in Release mode and run without debugger attached.

Here’s the test code:

static void TestSpeedForLargeByteArray()
{
    Stopwatch sw = new Stopwatch();

    Console.Write(string.Format("GC.GetTotalMemory before creating array: {0:N0}. Press any key to create array...", GC.GetTotalMemory(true)));
    Console.ReadKey();
    byte[] array = new byte[2000 * 1000 * 1000]; // About 2 GB
   
    sw.Start();
    for (int i = 0; i < array.Length; i++)
    {
        array[i] = 1; // Touch array elements to fill working set              
    }          
    Console.WriteLine("Setup time: " + sw.Elapsed);

    Console.WriteLine(string.Format("GC.GetTotalMemory after creating array: {0:N0}. Press Enter to set array to null...", GC.GetTotalMemory(true)));
    if (Console.ReadKey().Key == ConsoleKey.Enter)
    {
        Console.WriteLine("Setting array to null");
        array = null;
    }
               
    sw.Restart();
    GC.Collect();                 
    Console.WriteLine("Collection time: " + sw.Elapsed);
    Console.WriteLine(string.Format("GC.GetTotalMemory after GC.Collect: {0:N0}. Press any key to finish...", GC.GetTotalMemory(true)));

    Console.WriteLine(array); // To avoid compiler optimization...
    Console.ReadKey();
}

As you can see test is very simple. The code uses two methods of static GC class: GC.GetTotalMemory and GC.Collect. The former returns the amount of allocated managed memory and the latter forces Garbage Collector to do its job and free unused memory. The only thing that might be surprising is the loop that touches array items. Without it you will witness “strange” phenomenon: after array is defined GC.GetTotalMemory would report about 2 GB but you will not see memory usage increase in Task Manager! This is because taskmgr.exe shows Working Set data. You can run more advanced tool: Resource Monitor (resmon.exe) to see what’s happening: 

This is the screenshot before the “touch”:

Memory usage before access to array items. Click to enlarge...

And this is the one after the loop is executed:

Memory usage after access to array items. Click to enlarge...

Here are the test results (yeah, finally):

GC.GetTotalMemory before creating array: 41,568. Press any key to create array...
Setup time: 00:00:01.0633903
GC.GetTotalMemory after creating array: 2,000,053,864. Press Enter to set array to null...
Setting array to null
Collection time: 00:00:00.1443391
GC.GetTotalMemory after GC.Collect: 53,800. Press any key to finish...

What you can see here is that it took GC just around 150 milliseconds to free about 2 GB of memory. Nice, huh? You can appreciate the speed especially if you compare it with 1 second it took to just iterate over the array!

Below is a screenshot from Performance Monitor (perfmon.exe) running couple of .NET memory counters:

Performance Monitor with managed memory counters. Click to enlarge...

Our array is a big object (well over LOH threshold) – hence after it is defined memory of LOH increases yet Gen 0 heap size remains flat. 

Below are the results for GC.Collect run when reference to the array was not set to null:

GC.GetTotalMemory before creating array: 41,568. Press any key to create array..
Setup time: 00:00:01.0385779
GC.GetTotalMemory after creating array: 2,000,053,864. Press Enter to set array to null...
Collection time: 00:00:00.0001287
GC.GetTotalMemory after GC.Collect: 2,000,053,824. Press any key to finish...

Fraction of a millisecond. Totally negligible! Why I’m even mentioning a test for situation when memory is not collected? Well, in part two you will see that GC usually has more work to do when heap items survive collection cycle…

I hope to post the second part of the article in about a week or two. No promises though – you know, life… ;)

Update 26.07.2014: I've changed the screenshot from perfmon (Gen 0 and Gen 1 scale is bigger now).

Update 24.06.2014: I wrote the second part of this article few days ago. Click here to read it.

1. You can use GC.GC.MaxGeneration method to check it.

2. LOH threshold is an implementation detail. Most sources mention 85KB as the limit but it's not always the case - array of doubles with as little as 1000 items goes on LOH (on x86)...

3. .NET 4.5 introduces LOH improvements for better fragmentation prevention through balancing and enhanced free list usage. Future releases will probably have compaction option too.

Html Agility Pack - massive information extraction from WWW pages

Recently I needed to acquire some database. Unfortunately it was published only as a website that presented 50 records per single page. Whole database had more than 150 thousand records. What to do in such situation? Click through 3000 pages, manually collecting data in a text file? One week and it's done! ;) Better to write a program (so called scraper) which will do the work for you. The program has to do three things:

  • generated a list of addresses from which data should be collected;
  • visit pages sequentially and extract information from HTML code;
  • dump data to local database and log work progress.

Address generation should be quite easy. For most sites pagination is built with plain links in which page number is clearly visible in the main part of URL (http://example.com/somedb/page/1) or in the query string (http://example.com/somedb?page=1). If pagination is done via ajax calls situation is a bit more complex, but let's not bother with that in this post... When you know the pattern for page number parameter, all it's needed is a simple loop with something like:

string url = string.Format("http://example.com/somedb?page={0}", pageNumber)

Now it's time for something more interesting. How to extract data from a webpage? You can use WebRequest/WebResponse or WebClient classes from System.Net namespace to get page content. After that you can obtain information via regular expressions. You can also try to treat downloaded content as XML and scrutinize it with XPath or LINQ to XML. These are not good approaches, however. For complicated page structure writing correct expression might be difficult, one should also remember that in most cases webpages are not valid XML documents. Fortunately Html Agility Pack library was created. It allows convenient parsing of HTML pages, even these with malformed code (i.e. lacking proper closing tags). HAP goes through page content and builds document object model that can be later processed with LINQ to Objects or XPath.

To start working with HAP you should install NuGet package named HtmlAgilityPack (I was using version 1.4.6) and import namespace with the same name. If you don't want to use NuGet (why?) download zip file from project's website and add reference to HtmlAgilityPack.dll file suitable for your platform (zip contains separate versions for .NET 4.5 and Silverlight 5 for example). Documentation in .chm file might be useful too. Attention! When I opened downloaded file (in Windows 7), the documentation looked empty. "Unlock" option from file's properties screen helped to solve the problem.

Retrieving webpage content with HAP is very easy. You have to create HtmlWeb object and use its Load method with page address:

HtmlWeb htmlWeb = new HtmlWeb();
HtmlDocument htmlDocument = htmlWeb.Load("http://en.wikipedia.org/wiki/Paintball");

In return, you will receive object of HtmlDocument class which is the core of HAP library.

HtmlWeb contains a bunch of properties that control how document is retrieved. For example, it is possible to indicate whether cookies should be used (UseCookies) and what should be the value of User Agent header included in HTTP request (UserAgent). For me AutoDetectEncoding and OverrideEncoding properties were especially useful as they let me correctly read document with Polish characters.

HtmlWeb htmlWeb = new HtmlWeb() { AutoDetectEncoding = false, OverrideEncoding = Encoding.GetEncoding("iso-8859-2") };

StatusCode (typeSystem.Net.HttpStatusCode) is another very useful property of HttpWeb. With it you can check the result of latest request processing.

Having HtmlDocument object ready, you can start to extract data. Here's an example of how to obtain links addresses and texts from previously downloaded webpage (add using System.Linq):

IEnumerable<HtmlNode> links = htmlDocument.DocumentNode.Descendants("a").Where(x => x.Attributes.Contains("href"));
foreach (var link in links)
{
    Console.WriteLine(string.Format("Link href={0}, link text={1}", link.Attributes["href"].Value, link.InnerText));       
}

Property DocumentNode of type HtmlNode points to page's root. Method Descendants is used to retrieve all links (a tag) that contain href attribute. After that texts and address are printed on the console. Quite easy, huh? Few other examples:

Getting HTML code of the whole page:

string html = htmlDocument.DocumentNode.OuterHtml;

Getting element with "footer" id:

HtmlNode footer = htmlDocument.DocumentNode.Descendants().SingleOrDefault(x => x.Id == "footer");

Getting children of div with "toc" id and displaying names of child nodes which have type different than Text:

IEnumerable<HtmlNode> tocChildren = htmlDocument.DocumentNode.Descendants().Single(x => x.Id == "toc").ChildNodes;
foreach (HtmlNode child in tocChildren)
{
    if (child.NodeType != HtmlNodeType.Text)
    {
        Console.WriteLine(child.Name);
    }
}

Getting list elements (li tag) that have toclevel-1 class:

IEnumerable<HtmlNode> tocLiLevel1 = htmlDocument.DocumentNode.Descendants()
    .Where(x => x.Name == "li" && x.Attributes.Contains("class")
    && x.Attributes["class"].Value.Split().Contains("toclevel-1"));

Notice that Where filter is quite complex. Simple condition:

Where(x => x.Name == "li" && x.Attributes["class"].Value == "toclevel-1")

is not correct! Firstly there is no guarantee that each li tag will have class attribute set so we need to check if attribute exist to avoid NullReferenceException exception. Secondly the check for toclevel-1 is flawed. HTML element might have many classes, so instead of using == it's worthwhile to use Contains(). Plain Value.Contains is not enough though. What if we are looking for "sec" class and element has "secret" class? Such element will be matched too! Rather than Value.Contains you should use Value.Split().Contains. This way an array of strings will be checked via equals operator (instead of searching a single string for substring).

Getting texts of all li elements which are nested in minimum one li element:

var h1Texts = from node in htmlDocument.DocumentNode.Descendants()
              where node.Name == "li" && node.Ancestors("li").Count() > 0
              select node.InnerText;

Beyond LINQ to Objects, XPath might also be used to extract information. For example:

Getting a tags that have href attribute value starting with # and longer than 15 characters:

IEnumerable<HtmlNode> links = htmlDocument.DocumentNode.SelectNodes("//a[starts-with(@href, '#') and string-length(@href) > 15]");

Finding li elements inside div with id "toc" which are third child in their parent element:

IEnumerable<HtmlNode> listItems = htmlDocument.DocumentNode.SelectNodes("//div[@id='toc']//li[3]");

XPath is a complex tool and it's impossible to show all its great capabilities in this post...

HAP lets you explore page structure and content but it also allows page modification and save. It has helper methods good for detecting document encoding (DetectEncoding), removing HTML entities (DeEntitize) and more... It is also possible to gather validation information (i.e. check if original document had proper closing tags). These topics are beyond the scope of this post.

While processing consecutive pages, dump useful information to local database most suitable for your needs, Maybe .csv file will be enough for you, maybe SQL database will be required? For me plain text file was sufficient.

Last thing worth doing is ensuring that scraper properly logs information about its work progress (for sure you want to know how far your program went and if it encountered any errors). For logging it is best to use specialized library such as log4net. There's a lot of tutorials on how to use log4net so I will not write about it. But I will show you a sample configuration which you can use in console application:

<?xml version="1.0" encoding="utf-8" ?>
<configuration>
    <configSections>
        <section name="log4net" type="log4net.Config.Log4NetConfigurationSectionHandler, log4net"/>          
    </configSections>
    <log4net>        
        <root>
            <level value="DEBUG"/>            
            <appender-ref ref="ConsoleAppender" />
            <appender-ref ref="RollingFileAppender"/>
        </root>
        <appender name="ConsoleAppender" type="log4net.Appender.ColoredConsoleAppender">
            <layout type="log4net.Layout.PatternLayout">
                <conversionPattern value="%date{ISO8601} %level [%thread] %logger - %message%newline" />
            </layout>
            <mapping>
                <level value="ERROR" />
                <foreColor value="White" />
                <backColor value="Red" />
            </mapping>
            <filter type="log4net.Filter.LevelRangeFilter">
                <levelMin value="INFO" />                
            </filter>
        </appender>         
        <appender name="RollingFileAppender" type="log4net.Appender.RollingFileAppender">
            <file value="Log.txt" />
            <appendToFile value="true" />
            <rollingStyle value="Size" />
            <maxSizeRollBackups value="10" />
            <maximumFileSize value="50MB" />
            <staticLogFileName value="true" />
            <layout type="log4net.Layout.PatternLayout">
                <conversionPattern value="%date{ISO8601} %level [%thread] %logger - %message%newline%exception" />
            </layout>
        </appender>
    </log4net>    
</configuration>

Above config contains two appenders: ConsoleAppender and RollingFileAppender. The first logs text to console window, ensuring that errors are clearly distinguished by color. To reduce amount of information LevelRangeFilter is set so only entries with INFO or higher level are presented. The second appender logs to text file (even entries with DEBUG level go there). Maximum size of singe file is set to 50MB and total files number limit is set to 10. Current log is always in Log.txt file...

And that's all, scraper is ready! Run it and let it labor for you. No dull, long hour work - leave it for people who don't know how to program :)

Additionally you can try a little exercise: instead of creating a list of all pages to visit, determine only the first page and find a link to next page in currently processed one...

P.S. Keep in mind that HAP works on HTML code that was sent by the server (this code is used by HAP to build document model). DOM which you can observe in browser's developer tools is often a result of scripts execution and might differ greatly form the one build directly from HTTP response.

Update 08.12.2013: As requested, I created simple demo (Visual Studio 2010 solution) of how to use Html Agility Pack and log4net. The app extracts some links from wiki page and dumps them to text file. Wiki page is saved to htm file to avoid dependency on web resource that might change. Download

Short but very usueful regex – lookbehind, lazy, group and backreference

Recently, I wanted to extract calls to external system from log files and do some LINQ to XML processing on obtained data. Here’s a sample log line (simplified, real log was way more complicated but it doesn’t matter for this post):

Call:<getName seqNo="56789"><id>123</id></getName> Result:<getName seqNo="56789">John Smith</getName>

I was interested in XML data of the call:

<getName seqNo="56789">
  <id>123</id>
</getName>

Quick tip: super-easy way to get such nicely formatted XML in .NET 3.5 or later is to invoke ToString method on XElement object:

var xml = System.Xml.Linq.XElement.Parse(someUglyXmlString);     
Console.WriteLine(xml.ToString());

When it comes to log, some things were certain: 

  • call’s XML will be logged after “Call:” text on the beginning of line
  • call’s root element name will contain only alphanumerical chars or underscore
  • there will be no line brakes in call’s data
  • call’s root element name may also appear in the “Result” section

Getting to the proper information was quite easy thanks to Regex class:

Regex regex = new Regex(@"(?<=^Call:)<(\w+).*?</\1>");
string call = regex.Match(logLine).Value;

This short regular expressions has a couple of interesting parts. It may not be perfect but proved really helpful in log analysis. If this regex is not entirely clear to you - read on, you will need to use something similar sooner or later. 

Here’s the same regex with comments (RegexOptions.IgnorePatternWhitespace is required to process expression commented this way):

string pattern = @"(?<=^Call:) # Positive lookbehind for call marker
                   <(\w+)      # Capturing group for opening tag name
                   .*?         # Lazy wildcard (everything in between)
                   </\1>       # Backreference to opening tag name";   
Regex regex = new Regex(pattern, RegexOptions.IgnorePatternWhitespace);
string call = regex.Match(logLine).Value;

Positive lookbehind

(?<=Call:) is a lookaround or more precisely positive lookbehind. It’s a zero-width assertion that lets us check whether some text is preceded by another text. Here “Call:” is the preceding text we are looking for. (?<=something) denotes positive lookbehind. There is also negative lookbehind expressed by (?<!something).  With negative lookbehind we can match text that doesn’t have particular string before it. Lookaround checks fragment of the text but doesn't became part of the match value. So the result of this:

Regex.Match("X123", @"(?<=X)\d*").Value

Will be "123" rather than "X123".

.NET regex engine has lookaheads too. Check this awesome page if you want to learn more about lookarounds. 

Note: In some cases (like in our log examination example) instead of using positive lookaround we may use non-capturing group...

Capturing group

<(\w+) will match less-than sign followed by one or more characters from \w class (letters, digits or underscores). \w+ part is surrounded with parenthesis to create a group containing XML root name (getName for sample log line). We later use this group to find closing tag with the use of backreference. (\w+) is capturing group, which means that results of this group existence are added to Groups collection of Match object. If you want to put part of the expression into a group but you don’t want to push results into Groups collection you may use non-capturing group by adding a question mark and colon after opening parenthesis, like this: (?:something)

Lazy wildcard

.*? matches all characters except newline (because we are not using RegexOptions.Singleline) in lazy (or non-greedy) mode thanks to question mark after asterisk. By default * quantifier is greedy, which means that regex engine will try to match as much text as possible. In our case, default mode will result in too long text being matched:

<getName seqNo="56789"><id>123</id></getName> Result:<getName seqNo="56789">John Smith</getName>

Backreference

</\1> matches XML close tag where element's name is provided with \1 backreference. Remember the (\w+) group? This group has number 1 and by using \1 syntax we are referencing the text matched by this group. So for our sample log, </\1> gives us </getName>. If regex is complex it may be a good idea to ditch numbered references and use named references instead. You can name a group by <name> or ‘name’ syntax and reference it by using k<name> or k’name’. So your expression could look like this:

@"(?<=^Call:)<(?<tag>\w+).*?</\k<tag>>"

or like this:

@"(?<=^Call:)<(?'tag'\w+).*?</\k'tag'>"

The latter version is better for our purpose. Using < > signs while matching XML is confusing. In this case regex engine will do just fine with < > version but keep in mind that source code is written for humans…

Regular expressions look intimidating, but do yourself a favor and spend few hours practicing them, they are extremely useful (not only for quick log analysis)!

Fast pixel operations in .NET (with and without unsafe)

Bitmap class has GetPixel and SetPixel methods that let you acquire and change color of chosen pixels. Those methods are very easy to use but are also extremely slow. My previous post gives detailed explanation on the topic, click here if you are interested.

Fortunately you don’t have to use external libraries (or resign from .NET altogether) to do fast image manipulation. The Framework contains class called ColorMatrix that lets you apply many changes to images in an efficient manner. Properties such as contrast or saturation can be modified this way. But what about manipulation of individual pixels? It can be done too, with the help from Bitmap.LockBits method and BitmapData class…

Good way to test individual pixel manipulation speed is color difference detection. The task is to find portions of an image that have color similar to some chosen color. How to check if colors are similar? Think about color as a point in three dimensional space, where axes are: red, green and blue. Two colors are two points. The difference between colors is described by the distance between two points in RGB space.

Colors as points in 3D space diff = sqrt((C1R-C2R)2+(C1G-C2G)2+(C1B-C2B)2)

This technique is very easy to implement and gives decent results. Color comparison is actually a pretty complex matter though. Different color spaces are better suited for the task than RGB and human color perception should be taken into account (e. g. our eyes are more keen to detect difference in shades of green that in shades of blue). But let’s keep things simple here…

Our test image will be this Ultra HD 8K (7680x4320, 33.1Mpx) picture (on this blog it’s of course scaled down to save bandwidth):

Color difference detection input image (scaled down for blog)

This is a method that may be used to look for R=255 G=161 B=71 pixels (car number "36"). It sets matching pixels as white (the rest will be black):

static void DetectColorWithGetSetPixel(Bitmap image, byte searchedR, byte searchedG, int searchedB, int tolerance)
{
    int toleranceSquared = tolerance * tolerance;
    
    for (int x = 0; x < image.Width; x++)
    {
        for (int y = 0; y < image.Height; y++)
        {
            Color pixel = image.GetPixel(x, y);

            int diffR = pixel.R - searchedR;
            int diffG = pixel.G - searchedG;
            int diffB = pixel.B - searchedB;

            int distance = diffR * diffR + diffG * diffG + diffB * diffB;

            image.SetPixel(x, y, distance > toleranceSquared ? Color.Black : Color.White);
        }
    }
}

Above code is our terribly slow Get/SetPixel baseline. If we call it this way (named parameters for clarity):

DetectColorWithGetSetPixel(image, searchedR: 255, searchedG: 161, searchedB: 71, tolerance: 60);

we will receive following outcome:

Color difference detection output image (scaled down)

Result may be ok but having to wait over 84300ms* is a complete disaster! 

Now check out this method:

static unsafe void DetectColorWithUnsafe(Bitmap image, byte searchedR, byte searchedG, int searchedB, int tolerance)
{
    BitmapData imageData = image.LockBits(new Rectangle(0, 0, image.Width, image.Height), ImageLockMode.ReadWrite, PixelFormat.Format24bppRgb);
    int bytesPerPixel = 3;

    byte* scan0 = (byte*)imageData.Scan0.ToPointer();
    int stride = imageData.Stride;

    byte unmatchingValue = 0;
    byte matchingValue = 255;
    int toleranceSquared = tolerance * tolerance;

    for (int y = 0; y < imageData.Height; y++)
    {
        byte* row = scan0 + (y * stride);

        for (int x = 0; x < imageData.Width; x++)
        {
            // Watch out for actual order (BGR)!
            int bIndex = x * bytesPerPixel;
            int gIndex = bIndex + 1;
            int rIndex = bIndex + 2;

            byte pixelR = row[rIndex];
            byte pixelG = row[gIndex];
            byte pixelB = row[bIndex];

            int diffR = pixelR - searchedR;
            int diffG = pixelG - searchedG;
            int diffB = pixelB - searchedB;

            int distance = diffR * diffR + diffG * diffG + diffB * diffB;

            row[rIndex] = row[bIndex] = row[gIndex] = distance > toleranceSquared ? unmatchingValue : matchingValue;
        }
    }

    image.UnlockBits(imageData);
}

It does exactly the same thing but runs for only 230ms over 360 times faster!

Above code makes use of Bitmap.LockBits method that is a wrapper for native GdipBitmapLockBits (GDI+, gdiplus.dll) function. LockBits creates a temporary buffer that contains pixel information in desired format (in our case RGB, 8 bits per color component). Any changes to this buffer are copied back to the bitmap upon UnlockBits call (therefore you should always use LockBits and UnlockBits as a pair). Bitmap.LockBits returns BitmapData object (System.Drawing.Imaging namespace) that has two interesting properties: Scan0 and Stride. Scan0 returns an address of the first pixel data. Stride is the width of single row of pixels (scan line) in bytes (with optional padding to make it dividable by 4). 

BitmapData layout

Please notice that I don’t use calls to Math.Pow and Math.Sqrt to calculate distance between colors. Writing code like this: 

double distance = Math.Sqrt(Math.Pow(pixelR - searchedR, 2) + Math.Pow(pixelG - searchedG, 2) + Math.Pow(pixelB - searchedB, 2));

to process millions of pixels is a terrible idea. Such line can make our optimized method about 25 times slower! Using Math.Pow with integer parameters is extremely wasteful and we don’t have to calculate square root to determine if distance is longer than specified tolerance.

Previously presented method uses code marked with unsafe keyword. It allows C# program to take advantage of pointer arithmetic. Unfortunately, unsafe mode has some important restrictions. Code must be compiled with \unsafe option and executed for fully trusted assembly. 

Luckily there is a Marshal.Copy method (from System.Runtime.InteropServices namespace) that can move data between managed and unmanaged memory. We can use it to copy image data into a byte array and manipulate pixels very efficiently. Look at this method:

static void DetectColorWithMarshal(Bitmap image, byte searchedR, byte searchedG, int searchedB, int tolerance)
{        
    BitmapData imageData = image.LockBits(new Rectangle(0, 0, image.Width, image.Height), ImageLockMode.ReadWrite, PixelFormat.Format24bppRgb);

    byte[] imageBytes = new byte[Math.Abs(imageData.Stride) * image.Height];
    IntPtr scan0 = imageData.Scan0;

    Marshal.Copy(scan0, imageBytes, 0, imageBytes.Length);
  
    byte unmatchingValue = 0;
    byte matchingValue = 255;
    int toleranceSquared = tolerance * tolerance;

    for (int i = 0; i < imageBytes.Length; i += 3)
    {
        byte pixelB = imageBytes[i];
        byte pixelR = imageBytes[i + 2];
        byte pixelG = imageBytes[i + 1];

        int diffR = pixelR - searchedR;
        int diffG = pixelG - searchedG;
        int diffB = pixelB - searchedB;

        int distance = diffR * diffR + diffG * diffG + diffB * diffB;

        imageBytes[i] = imageBytes[i + 1] = imageBytes[i + 2] = distance > toleranceSquared ? unmatchingValue : matchingValue;
    }

    Marshal.Copy(imageBytes, 0, scan0, imageBytes.Length);

    image.UnlockBits(imageData);
}

It runs for 280ms, so it is only slightly slower than unsafe version. It is CPU efficient but uses more memory then previous method – almost 100 megabytes for our test Ultra HD 8K image in RGB 24 format.

If you want to make pixel manipulation even faster you may process different parts of the image in parallel. You need to make some benchmarking first because for small images the cost of threading may be bigger than gains from concurrent execution. Here’s a quick sample of code that uses 4 threads to process 4 parts of the image simultaneously. It yields 30% time improvement on my machine. Treat is as a quick and dirty hint, this post is already to long…

static unsafe void DetectColorWithUnsafeParallel(Bitmap image, byte searchedR, byte searchedG, int searchedB, int tolerance)
{
    BitmapData imageData = image.LockBits(new Rectangle(0, 0, image.Width, image.Height), ImageLockMode.ReadWrite, PixelFormat.Format24bppRgb);
    int bytesPerPixel = 3;

    byte* scan0 = (byte*)imageData.Scan0.ToPointer();
    int stride = imageData.Stride;

    byte unmatchingValue = 0;
    byte matchingValue = 255;
    int toleranceSquared = tolerance * tolerance;

    Task[] tasks = new Task[4];
    for (int i = 0; i < tasks.Length; i++)
    {
        int ii = i;
        tasks[i] = Task.Factory.StartNew(() =>
            {
                int minY = ii < 2 ? 0 : imageData.Height / 2;
                int maxY = ii < 2 ? imageData.Height / 2 : imageData.Height;

                int minX = ii % 2 == 0 ? 0 : imageData.Width / 2;
                int maxX = ii % 2 == 0 ? imageData.Width / 2 : imageData.Width;                        
                
                for (int y = minY; y < maxY; y++)
                {
                    byte* row = scan0 + (y * stride);

                    for (int x = minX; x < maxX; x++)
                    {
                        int bIndex = x * bytesPerPixel;
                        int gIndex = bIndex + 1;
                        int rIndex = bIndex + 2;

                        byte pixelR = row[rIndex];
                        byte pixelG = row[gIndex];
                        byte pixelB = row[bIndex];

                        int diffR = pixelR - searchedR;
                        int diffG = pixelG - searchedG;
                        int diffB = pixelB - searchedB;

                        int distance = diffR * diffR + diffG * diffG + diffB * diffB;

                        row[rIndex] = row[bIndex] = row[gIndex] = distance > toleranceSquared ? unmatchingValue : matchingValue;
                    }
                }
            });
    }

    Task.WaitAll(tasks);

    image.UnlockBits(imageData);
}

Update 2018-01-08: If you really want to do some complex and efficient image processing then you should use specialized library like OpenCV. Few months ago I've written "Detecting a Drone - OpenCV in .NET for Beginners (Emgu CV 3.2, Visual Studio 2017)" blog post series that will help you do it...

* .NET 4 console app, executed  on MSI GE620 DX laptop: Intel Core i5-2430M 2.40GHz (2 cores, 4 threads), 4GB DDR3 RAM, NVIDIA GT 555M 2GB DDR3, HDD 500GB 7200RPM, Windows 7 Home Premium x64.