Thursday, December 1, 2011

JSON–yet another tutorial :)

What is JSON?

JSON (or JavaScript Object Notation) is a highly portable data interchange format. While its structure is recognized natively by Javascript (as it is Javascript), its formatting conventions are easily recognized by other C-like languages.

JSON is built on two structures:

  • A collection of name/value pairs. In various languages, this is realized as an object, record, struct, dictionary, hash table, keyed list, or associative array. Example:
var jason = {
"age" : "28",
"hometown" : "Cairo, Egypt",
"gender" : "male"
};

The object created in the example could be accessed like any other object.

  • An ordered list of values. In most languages, this is realized as an array, vector, list, or sequence. Example,
var family = [{
"name" : "Jason",
"age" : "24",
"gender" : "male"
},
{
"name" : "Kyle",
"age" : "21",
"gender" : "male"
}];

This array could be accessed like any array of objects.

Since JSON and XML are both used for data exchange, you may find yourself in the middle of deciding which format to use.

Reasons to choose JSON over XML
  1. JSON is easier to read than XML (especially of large amounts of data)
  2. JSON requires less tags than XML – XML items must be wrapped in open and close tags whereas JSON you just name the tag once
  3. Because JSON is transportation-independent, you can just bypass the XMLHttpRequest object for getting your data.
  4. JavaScript is not just data – you can also put methods and all sorts of goodies in JSON format.
  5. JSON is better at helping procedural decisions in your JavaScript based on objects and their values (or methods).
  6. You can get JSON data from anywhere, not just your own domain.
Reasons to choose XML over JSON
  1. Easy to take XML and apply XSLT to make XHTML.
  2. XML is supported by many more desktop applications than JSON.
  3. XML can put JSON in it on the way back to the client.
  4. AJAX includes XML in it and not JSON.

.Net Support for JSON

.Net framework provides System.Web.Script.Serialization.JavaScriptSerializer to serialize and deserialize objects. Here is a simple example:

using System;
using System.Collections.Generic;
using System.Linq;
using System.Web;
using System.Web.UI;
using System.Web.UI.WebControls;
namespace JSON_Demo1
{
public partial class Page1 : System.Web.UI.Page
{
protected void Page_Load(object sender, EventArgs e)
{
Employee oEmployee1 = new Employee { Name = "Emp1", ID = "11", Age = "30" };
Employee oEmployee2 = new Employee { Name = "Emp2", ID = "22", Age = "31" };
Employee oEmployee3 = new Employee { Name = "Emp3", ID = "33", Age = "20" };
List oList = new List() { oEmployee1, oEmployee2, oEmployee3 };
System.Web.Script.Serialization.JavaScriptSerializer oSerializer = new System.Web.Script.Serialization.JavaScriptSerializer();
string sJSON = oSerializer.Serialize(oList);
Response.Write(sJSON);
}
}
public class Employee
{
public string Name { get; set; }
public string Age { get; set; }
public string ID { get; set; }
}
}

When you run the above application, you will see the JSON array on the response like so:

JSON_Demo11

Now let’s change this example a little bit so we can make Ajax call to get the JSON data and parse it using javaScript. Change the code-behind to look like:

using System;
using System.Collections.Generic;
using System.Linq;
using System.Web;
using System.Web.UI;
using System.Web.UI.WebControls;
using System.Web.Services;

namespace JSON_Demo1
{
public partial class Page1 : System.Web.UI.Page
{
protected void Page_Load(object sender, EventArgs e)
{
Response.Write(GetJSONData());
}

[WebMethod()]
public static string GetJSONData()
{
Employee oEmployee1 = new Employee { Name = "Emp1", ID = "11", Age = "30" };
Employee oEmployee2 = new Employee { Name = "Emp2", ID = "22", Age = "31" };
Employee oEmployee3 = new Employee { Name = "Emp3", ID = "33", Age = "20" };
List oList = new List() { oEmployee1, oEmployee2, oEmployee3 };
System.Web.Script.Serialization.JavaScriptSerializer oSerializer = new System.Web.Script.Serialization.JavaScriptSerializer();
return oSerializer.Serialize(oList);
}
}
public class Employee
{
public string Name { get; set; }
public string Age { get; set; }
public string ID { get; set; }
}

}

now change the .aspx page to look like:

<%@ Page Language="C#" AutoEventWireup="true" CodeBehind="Page1.aspx.cs" Inherits="JSON_Demo1.Page1" %>

<!DOCTYPE html PUBLIC "-//W3C//DTD XHTML 1.0 Transitional//EN" "http://www.w3.org/TR/xhtml1/DTD/xhtml1-transitional.dtd">
<html xmlns="http://www.w3.org/1999/xhtml">
<head runat="server">
<title></title>
<script src="http://ajax.googleapis.com/ajax/libs/jquery/1.7.1/jquery.min.js" type="text/javascript"></script>
<script type="text/javascript">
$(document).ready(function () {
$.ajax({
type: "POST",
url: "Page1.aspx/GetJSONData",
contentType: "application/json; charset=utf-8",
dataType: "json",
success: function (msg) {
BuildTable(msg.d);
}
});
});

function BuildTable(msg) {
var table = '<table> <thead> <tr> <th>Name</th> <th>ID</th> <th>Age</th> </thead> <tbody>';
var myJSONObject = eval( msg );
for (var i = 0; i < 3; i++) {
var row = '<tr>';
row += '<td>' + myJSONObject[i].Name + '</td>';
row += '<td>' + myJSONObject[i].ID + '</td>';
row += '<td>' + myJSONObject[i].Age + '</td>';
row += '</tr>';
table += row;
}
table += '</tbody></table>';
$('#Container').html(table);
}
</script>
</head>
<body>
<div id="Container">
</div>
</body>
</html>


Now let’s run the application and see the output:



JSON_Demo12

In the previous example, we created a WebMethod, then call it from jQuery and pass the output of it to JavaScript method BuildTable(msg). This method convert the string msg into a JSON array of objects and then loop on that array to build the shown simple data table. We also rendered the JSON data to the browser directly from server-side code, just to show the original data and how it transformed using JSON.

In this post we gave a brief background about JSON, when use it and when use XML to send data, how .Net provides native serializer for JSON, and how to deserialize it using JavaScript. We may look into more advanced topics regarding JSON in future posts.

Good Luck

Tuesday, November 22, 2011

An introduction to Microsoft Message Queuing–Part 2

In the previous post, we explored very basic concepts of MSMQ. We used non-transactional queue to send and receive a message. In this post we will try to dive more into Message Queuing Queues.

Simply, queues are logical containers that Message Queuing uses to store and later forward messages, providing the bases for the loosely coupled aspects of Message Queuing. Queues can be created by applications and by Message Queuing. Queues created by applications or by users in an MMC snap-in are referred to as application queues. Queues created by Message Queuing are referred to as system-generated queues (we will talk about system- generated queues in another post).

Depending on the service provided by the queue, application queues can be public or private, and they can be transactional or nontransactional.

Application queues can play any of the following roles:

  • Destination queues : any queue used to send/receive messages between applications.
  • Administration queues : used for acknowledgment messages returned by Message Queuing or connector applications.
  • Response queues : used by receiving applications to return response messages to the sending application.
  • Report queues : used to store report messages returned by Message Queuing.
Destination Queues

Destination queues are any queue used to send/receive messages between applications. The sending application on computer 1 sends the messages to the queue and the receiving application on computer 2 reads the messages from the queue. Typically, destination queues are located on the same computer as the receiving application in order to minimize network traffic.

Public Versus Private Queues The decision to use public or private destination queues depends primarily on whether you want other applications to be able to locate the queues or not. Message Queuing registers private queues locally by storing a description of each queue in a separate file in the local queue storage (LQS) folder on the local computer (the default Lqs folder is %windir%\System32\MSMQ\Storage\Lqs). Also a description of each public queue created on the local computer is also stored locally in a separate file in the Lqs folder.

Adv. of Public Queues:

  • Registered in the directory service, so it can be located by other Message Queuing applications.
  • Persistent and its registration information can be backed up.

Adv. of Private Queues:

  • Requires minimal directory service overhead(faster to create, no latency, and no replication)
  • Can be created and deleted when the directory service is not working
  • Can be accessed directly by name without query the directory service.

Div. of Private Queues:

  • It is registered on local computer, so it is properties cannot be obtained by Message Queuing applications running on remote computers. Private queues can be exposed to other applications by making the location of the private queue known to the applications. To distribute the location of a private queue, an application can send the format name of the private queue as the response queue property of a message.

Transactional Versus Nontransactional Queues The decision to use transactional or nontransactional queues is based on whether the applications accessing the queue will be sending and receiving messages within the context of a transaction. So, what is a transaction ? a transaction is to execute a multiple-steps process such that either all or none of the steps will complete. In reality, transactions are handled by rolling back any steps that have already occurred if the entire transaction is not completed successfully.

When sending messages, only transactional queues can accept messages sent in the context of a transaction. These messages are also referred to as transactional messages. In a similar way, nontransactional queues can only accept messages sent outside the context of a transaction. Note that only transactional messages are delivered with exactly-once-delivery (EOD) guarantees.

When receiving messages, only local transactional queues can be accessed within the context of a transaction. The transactional queue must be local to the receiving application. On the other hand, nontransactional queues can be accessed within or outside of a transaction. Also, transactional queues, local or remote, can be accessed outside of a transaction (because we ask it to do less than what it can do).

If you just want to be able to recover lost messages, don’t use transactional queues. You can set the Recoverable property of a every message you sent. Or you can sent the queue property DefaultPropertiesToSend.Recoverable to true.

Creating a Transactional Queue
  • Through the snap in : just check the check-box Transactional below the queue name textbox.
  • Programmatically : just like privateQueue = MessageQueue.Create(".\\Private$\\privateQueue", true);

MessageQueue have a property called Transactional that you can check to ensure that the queue is transactional

MSMQ supports two types of transactions: Internal and External.

Internal Transactions

Class MessageQueueTransaction can be used to Begin(), Commit(), Abort() the transaction. It also can be passed through Send() and Receive() methods to that operation falls under a transaction. The class also exposes a Status property to give the transaction status. Transaction status can be one of:

  • Initialized : The transaction has been initialized but not yet started.
  • Pending : The transaction has been began but not committed or aborted yet.
  • Committed : The transaction has been committed.
  • Aborted : The transaction has been aborted.

Transaction Types when sending or receiving using MessageQueue class through transactional queues, you could pass one of the values in MessageQueueTransactionType enumeration. This specifies how you would like to interact with the queue. These values are:

  • Single : each queue operation will be doine in a separate internal transaction.
  • None : enable you to receive a message from a transactional queue, but outside a transaction. It also enables us to send a transactional message to a non-transactional queue.
  • Automatic : used with external transactions to direct the send or receive operations to use an already existing transaction context.

Now lets compile these pieces into one example to get sense of what internal transactional queues means.

using System;
using System.Collections.Generic;
using System.Linq;
using System.Text;
using System.Messaging;

namespace MSMQ_Demo3
{
class Program
{
static void Main(string[] args)
{
MessageQueueTransaction mqTran = new MessageQueueTransaction();
MessageQueue queueA = MessageQueue.Create(".\\Private$\\TranQueueA", true);
MessageQueue queueB = MessageQueue.Create(".\\Private$\\TranQueueB", true);
mqTran.Begin();
try
{
queueA.Send("Message A", "Label A", mqTran );
queueB.Send("Message B", "Label B", mqTran );
mqTran.Commit();
}
catch(Exception ex)
{
mqTran.Abort();
Console.WriteLine(ex.Message);
}

MessageQueue queueC = new MessageQueue(".\\Private$\\TranQueueA");
MessageQueue queueD = new MessageQueue(".\\Private$\\TranQueueB");
string strMsg = "";
mqTran.Begin();
try
{
Message msg = queueC.Receive(mqTran);
msg.Formatter = new XmlMessageFormatter(new Type[1] { typeof(string) });
strMsg = msg.Body.ToString();
msg = queueD.Receive(mqTran);
msg.Formatter = new XmlMessageFormatter(new Type[1] { typeof(string) });
strMsg += " \n ";
strMsg += msg.Body.ToString();
Console.WriteLine(strMsg);
mqTran.Commit();
}
catch (Exception ex)
{
mqTran.Abort();
Console.WriteLine(ex.Message);
}
Console.WriteLine();
}

}
}



In this example we created two transactional queues, send two messages to them. Then we received these messages. Both the sending and receiving done in a transaction that commits only after the success of all operations. If any errors happened, we abort the whole transaction and rollback all operations done in it.

In future posts we will talk more about MSQM details.

Thursday, November 17, 2011

An introduction to Microsoft Message Queuing

What is MSMQ ? Message Queuing (also known as MSMQ) is a messaging infrastructure and a development tool for creating distributed messaging applications for Microsoft Windows operating systems. Applications developed for Message Queuing send messages to queues, which are temporary storage locations, from which messages can proceed to their final destination as conditions permit.

Installing MSMQ The procedures to install MSMQ on Windows Server 2008, Winows Server 2008 R2, Windows 7, Windows Vista, Windows XP, and Windows Server 2003 are available here

Basic Messaging

MSMQ1

The image shows the basic messaging scenario. You have two applications: a sending application and a receiving application. A sending application prepares a message and puts it into a queue. A message can be any piece of information that the receiving application understands. The receiving application receives the message from the queue and processes it. One thing to note here is that the sender and the receiver are not tightly coupled and they can work without the other application being online.

Messaging in .Net To build a messaging application we need to create at least three components: queue, application to send messages, and another application to receive these messages.

Types of queues The basic types of MSMQ queues are: private and public. Public queues are those that are published in the active directory. So, applications running on different servers throughout the network can find and use public queues through the active directory. Private queues on the other hand are available locally on a particular machine and are not published in the active directory.

Creating a Queue Queues can be created either programmatically or through the computer management snap-in (if you installed MSMQ on your machine).

  • Programmatically The System.Messaging.MessageQueue class provides all the necessary functionality to work with and manipulate MSMQ queues. It is like a wrapper around message queuing. MessageQueue.Create(path) creates a non-transactional message queue at the specified path (we will talk about transactional and non-transactional queues later). For public queues, path is MachineName\QueueName. For private queues, MachineName\Private$\QueueName. You can use "." for the local computer. Code should look like:
MessageQueue privateQueue = MessageQueue.Create(".\\Private$\\privateQueue"); 




  • Through the computer management snap-in Open the computer management snap-in (right click computer, then manage). Navigate to Services and Applications, then Message Queuing. Right click on Private Queues –> New –> Private Queue. Or right click on public Queues –> New –> Public Queue.



MMC



Sending a message Use Send() method of your previously created MessageQueue object like so





privateQueue.Send("Message Body (could be any managed object)", "Message Label");



Receiving a message There are two types of operations with respect to reading a message fom the Queue: Peeking and Receiving. When we receive a message from the queue, the message is removed from the queue. Peeking is similar to Receiving but here the message is not removed from the queue. Code could look like





MessageQueue anotherPrivateQueue = new MessageQueue(".\\Private$\\privateQueue");


System.Messaging.Message msg = anotherPrivateQueue.Receive();



Additional Considerations before writing the first complete messaging application




  • You have to check if there is already a Message Queuing queue with the same name before creating your new queue. Use MessageQueue.Exists(path) to check for queue existence.


  • When receiving a message and before accessing its body, you have to set the Formatter property of the Message object. There is a lot of built-in formatters. For now, we can use XMLFormatter.



Now, let’s get things together into a “Hello, World” example. Open Visual Studio, New project, Windows forms. All reference to System.Messaging namespace. Then edit your code to look like so:





using System;
using System.Collections.Generic;
using System.Linq;
using System.Text;
using System.Messaging;

namespace MSMQ_Demo
{
class Program
{
static void Main(string[] args)
{
try
{
MessageQueue privateQueue;
if (!MessageQueue.Exists(".\\Private$\\privateQueue"))
privateQueue = MessageQueue.Create(".\\Private$\\privateQueue");
else
privateQueue = new MessageQueue(".\\Private$\\privateQueue");

privateQueue.Send("Hello, World !", "Message Label");
MessageQueue anotherPrivateQueue = new MessageQueue(".\\Private$\\privateQueue");
System.Messaging.Message msg = anotherPrivateQueue.Receive();
msg.Formatter = new System.Messaging.XmlMessageFormatter(new Type[1] { typeof(string) });
Console.WriteLine(msg.Body.ToString());
}
catch (Exception ex)
{
Console.WriteLine(ex.Message);
}
}
}
}



If you run the project, you will see a message-box displaying “Hello, World !”. This message content created by had been sent from MSMQ queue, received by another MSMQ, and processed. In our example both the sending and the receiving queues exist in the same application for the sake of simplicity. In real world applications they reside in very different areas.

This is a very basic introduction to MSMQ and non-transactional queues. In future posts, we will explore more advanced topics in MSMQ.

Friday, October 21, 2011

Asserts in NUnit

Assertions (or asserts for short) are helper methods that can assist us in determining whether a method under test is performing correctly or not. They let us assert conditions, data, and so on. All assertion methods will report failures (that’s when the assertion is false) or errors (that’s when we get an unexpected exception) and report these through the NUnit test runner. when a failure or error occurs, execution of the current test method is aborted. Other Test within the same test fixture will still be run.

Classic Asserts

  • Assert.AreEqual (expected, actual, string message)
    • For floating-point numbers we need to specify the tolerance of the equality.
    • Assert.AreEqual(3.33, 10.0/3.0, 0.01)  // Checks the result but looks only for the first two decimal places.
  • Assert.Less(x, y)     // asserts that x < y
  • Assert.Greater(x, y)      // asserts that x > y
  • Assert.LessOrEqual(x, y)    // asserts that x <= y
  • Assert.GreaterOrEqual(x, y)    // asserts that x >= y
  • Assert.IsNull(object, string message)
  • Assert.IsNotNull(object, string message)
  • Assert.AreSame(expected, actual, string message)
  • Assert.IsTrue(bool condition, string message)
  • Assert.IsFalse(bool condition, string message)
  • Assert.Fail(string message)
    • Fails the test immediately, can be used to mark sections of code that should not be reached.

*message in all previous statements is optional.

Constrain-Based Asserts

These are new assertion style introduced in NUnit 2.4. That new style enable many expectations to be evaluated together in a single assertion:

Assert.That(4, Is.LessThan(5) & Is.GreatThan(0));

  • Assert.That(actual, Is.EqualTo(expected))
  • Assert.That(actual, Is.Not.EqualTo(expected));
  • Assert.That(actual, Is.AtMost(expected));        //equivalent to Assert.LessOrEqual()
  • Assert.That(actual, Is.Atleast(expected));        //equivalent to Assert.GreaterOrEqual()
  • Assert.That(expected, Is.Null);
  • Assert.That(expected, Is.Not.Null);                 //equivalent to Assert.That(expected, !Is.Null);
  • Assert.That(expected, Is.Empty);                   //for collections and strings
  • Assert.That(actual, Is.InstanceOfType(expected));
  • Assert.That(actual, Has.Length(expected));
  • Assert.That(actualCollection, List.Contains(expectedValue));
    • Assert.That({5, 3, 2}, List.contains(2))   //will pass
  • Assert.That(actualCollection, Is.SubsetOf(expectedCollection));
    • Assert.That({5, 3, 2}, Is.SubsetOf({5, 4, 3, 2, 1})
  • Assert.That(actual, Text.StartsWith(expected)); //asserts that the expected string is at the beginning of actual
  • Assert.That(actual, Text.Matches(expected));    //asserts that the expected regular expression string matches actual
  • FileAssert.AreEqual(FileInfo expected, FileInfo actual);
    • FileAssert.AreEqual(String pathToExpected, String PathToActual);

NUnit and Exceptions

Part of your code behavior may be throwing a specific exception in certain cases. If you want to assert that your code throws the exceptions that it designed to throw, you need to tag your test method with attribute: [ExpectedException(typeof(ExpectedException))].

   1:  [TestFixture]


   2:  public class ImportListTest


   3:  {


   4:      [Test]


   5:      [ExpectedException(typeof(ArgumentNullException))]


   6:      public void NullList()


   7:      {


   8:          Class1.ImportList(null);


   9:      }


  10:  }



This test method in now expected to throw an exception [from the call to ImportList(null)]. If it doesn’t, the test will fail. If a different exception is thrown (even a superclass of the one specified), the test fails. The test passes only if the exact exception specified is thrown.



Temporarily ignoring tests



If you wrote the test code first and will start writing code incrementally (something like TDD), you may temporarily ignore tests that you still implementing the code required to pass them. You could just tag these tests with attribute [Ignore(“Optional Message”)] . NUnit will report that these tests were skipped and show a yellow bar in the GUI, so you won’t forget about it later.

Structuring unit tests in NUnit

Our goal in the previous post Introduction to NUnit, was just to introduce the unit testing using NUnit as simple as possible. Now it is the time to elaborate more on NUnit framework, structuring and organizing your test cases. If you examined the test code again:

   1:  using System;


   2:  using NUnit.Framework;


   3:  namespace ClassLibrary1


   4:  {


   5:      [TestFixture]


   6:      public class CmpTest


   7:      {


   8:          [Test]


   9:          public void LargestOf3()


  10:          {


  11:              int[] numbers = new int[] { 8, 9, 7 };


  12:              Assert.That(Cmp.Largest(numbers), Is.EqualTo(9));


  13:          }


  14:      }


  15:  }



The code is pretty straightforward. The using statement on line 2 brings in the necessary NUnit classes.



Next, we have the class definition on line 6: each class that contains tests must be annotated with a [TestFixture] attribute. The class have to be public, so the test runners can run it. The class must have a public, no-parameter constructor.



Finally, the test class contains individual methods annotated with [Test] attributes. Any public, parameterless method specified with a [Test] attribute will be run automatically by NUnit.



Structuring Unit Tests



As a good object-oriented design concept, a class should be focused on one responsibility and only one. This applies to test fixtures as well. Test fixtures should be focused on verifying behavior in a specific scenario. Its name should reflect this scenario. Tests inside that fixture should test different behaviors within this scenario. Tests should be organized around behaviors, not necessarily individual methods. To keep things readable and clear in the test runner output, favor putting fixture classes under a namespace that includes the name of the class that the fixture are testing.




   1:  namespace solutionName.Test.ShoppingCartTest


   2:  {


   3:      [TestFixture]


   4:      public class EmptyCartFixture


   5:      {


   6:          [Test]


   7:          public void OverallRateIsZero() { }


   8:      }


   9:  }



Categories



NUnit provides an easy way to mark and run individual test and fixtures by using categories. A category is just a name that we define. We can associate different test methods with one or more categories, that enable us to select which categories we want to exclude (or include) when running the tests. A category is specified as an attribute.




   1:  using System;


   2:  using NUnit.Framework;


   3:  namespace ClassLibrary1


   4:  {


   5:      [TestFixture]


   6:      public class CmpTest


   7:      {


   8:          [Test]


   9:          [Category("Short")]


  10:          public void LargestOf3()


  11:          {


  12:              int[] numbers = new int[] { 8, 9, 7 };


  13:              Assert.That(Cmp.Largest(numbers), Is.EqualTo(9));


  14:          }


  15:   


  16:          [Test]


  17:          [Category("Long")]


  18:          [Category("Fred")]


  19:          public void LargestOf3Alt()


  20:          {


  21:              int[] numbers = new int[3];


  22:              numbers[0] = 1;


  23:              numbers[1] = 1;


  24:              numbers[2] = 1;


  25:              Assert.That(Cmp.Largest(numbers), Is.EqualTo(1));


  26:          }


  27:   


  28:          [SetUp]


  29:          public void LargestOf3Alt2()


  30:          {


  31:              int[] numbers = new int[1];


  32:              numbers[0] = 0;


  33:              Assert.That(Cmp.Largest(numbers), Is.EqualTo(0));


  34:          }


  35:      }


  36:  }



In the GUI, if you excluded “Short” methods from run, only LargestOf3() will be selected and executed.



NUnit3



When categories are used, only the tests in the selected categories will be run. Those tests in categories that are not selected are not reported at all. If no category selected in the GUI, then all methods will be executed unless it is tagged with Explicit attribute. The Explicit attribute causes a test or test fixture to be ignored unless it is explicitly selected for running.



Per-Method Setup and Teardown  We should write our test in order that each test can run independently of other tests; this allows us to run any test at any time in any order. In order to accomplish that we may need to reset things between tests or clean up after a test has run. [Setup] and [TearDown] attributes are used for these tasks.



Per-Fixture Setup and Teardown  If we need to set something up or clean up after the entire test class has run, use [TestFixtureSetup] and [TestFixtureTearDown] for that.



Although setup and teardown methods generally come in pair, they don’t have to do so.



Suppose we need some sort of database connection for each test. Rather than duplicating code in each test method that connects to and disconnects from the database, we could use SetUp and TearDown methods. Since creating the initial connection to the database can be slow, we may want to do that only once before all the tests run by using TestFixtureSetUp.




   1:  [TestFixture]


   2:  public class DBTest


   3:  {


   4:      private SqlConnection dbConn;


   5:              


   6:      [TestFixtureSetUp]


   7:      public void PerFixtureSetup()


   8:      {


   9:          dbConn = new SqlConnection("ConnectionString");


  10:          dbConn.Open();


  11:      }


  12:   


  13:      [SetUp]


  14:      public void PerTestSetup()


  15:      {


  16:          //populate database with test data


  17:      }


  18:   


  19:      [TearDown]


  20:      public void PerTestTearDown()


  21:      {


  22:          // clean up database


  23:      }


  24:   


  25:      [TestFixtureTearDown]


  26:      public void PerFixtureTearDown()


  27:      {


  28:          dbConn.Close();


  29:          dbConn.Dispose();


  30:      }


  31:   


  32:      [Test]


  33:      public void AccountAccess()


  34:      {


  35:          // Uses dbConn


  36:      }


  37:   


  38:      [Test]


  39:      public void EmployeeAccess()


  40:      {


  41:          // Uses dbConn


  42:      }


  43:  }



In this example, here is the methods run sequence: PerFixtureSetup >> PerTestSetup >> AccountAccess >> PerTestTearDown >> PerFixtureTearDown >> PerFixtureSetup >> PerTestSetup >> EmployeeAccess >> PertestTearDown >> PerFixtureTearDown.



In this post we tried to elaborate more on the NUnit framework and how we structure and organize test cases in NUnit.

Introduction to NUnit

What is unit testing?

According to Jeff Canna, unit testing ensures that a particular method of a class successfully performs a set of specific tasks. Each test confirms that a method produces the expected output when given a known input.

What is NUnit? NUnit is an open source framework that facilitates unit testing for all .NET languages. It allows you to build your test cases directly into the code of the project.

How do I get NUnit? Download the appropriate file from here and install it. That’s it !!

Write your code

We will write our code now and let it drive our testing cases and exploration of NUnit. Make a new project, class library that similar to the code below. Below an implementation of a “largest” method that returns the largest number in a list.

   1:  using System;


   2:  namespace ClassLibrary1


   3:  {


   4:      public class Cmp


   5:      {


   6:          public static int Largest(int[] list)


   7:          {            


   8:              int max = Int32.MaxValue;


   9:              for (int index = 0; index < list.Length - 1; index++)


  10:              {


  11:                  if (list[index] > max)


  12:                      max = list[index];


  13:              }


  14:              return max;


  15:          }


  16:      }


  17:  }



Test your code



Now it comes to the testing step. Writing test cases is a big topic to be discussed here. We will try to make our first test as simple as possible because there is much to be tested the first time besides the code itself. First, add reference to NUnit and then write our test cases.




  1. Right click on the references in “Solution Explorer” and click add a reference.


  2. Click on tab “Browse”


  3. Navigate to your NUnit directory and go into the bin subdirectory. For me this directory is in “C:\Program Files (x86)\NUnit 2.5.10\bin\net-2.0\framework”


  4. Select nunit.framework.dll and click OK.



Then add a new class library to the project and add the code below to it. This code uses the NUnit namespace, attributes, Assert, and Is. We will explain all of these in detail in further posts. For now, just build the project.




   1:  using System;


   2:  using NUnit.Framework;


   3:  namespace ClassLibrary1


   4:  {


   5:      [TestFixture]


   6:      public class CmpTest


   7:      {


   8:          [Test]


   9:          public void LargestOf3()


  10:          {


  11:              int[] numbers = new int[] { 8, 9, 7 };


  12:              Assert.That(Cmp.Largest(numbers), Is.EqualTo(9));


  13:          }


  14:      }


  15:  }



Run your tests



Now we have got our code, and our test cases. The next step is to run that test cases to test our code and that is the role of test runners. A test runner knows to look for the [TestFixture] attribute of a class and for the [Test] methods within it. The runner will run the tests, accumulate some statistics on which tests passed and failed, and report the results to you. There are many test runners, you can use the NUnit GUI which is installed by default with NUnit (will be located in the programs menu of the start menu).



Using NUnit GUI



In the NUnit GUI, select File > Open or press Ctrl + O. This would show the Open Project dialog. Browse to the folder which contains the assembly containing your tests and open it.

NUnit1


Now you can test your code by clicking the Run button.


NUnit2


When we run a selected test, the GUI will display a large, colored, status bar. If all the tests pass, the bar is bright green. If any test fails, the bar is red. If any test was skipped, the bar is yellow.



It is obvious that our test case here have been failed. Try to fix the code and run the test again until it succeed Smile

Sunday, October 16, 2011

Log4net Extended Tutorial

Logging is one of the most effective debugging and troubleshooting techniques although some engineers claim that it is not that helpful or it will slow the application. My experience with it is always positive.

I use log4net from the Apache Software Foundation as my logging layer for .Net applications. log4net is available here as a zip archive.

Hello World Example [uses BasicConfigurator]
  1. Download log4net from here.
  2. Open Visual Studio and create a new Console application project.
  3. Add to the project a reference to the \bin\net\2.0\release\log4net.dll assembly in the log4net distribution.
  4. Modify your Main() method like so:
   1:  using System;


   2:  namespace ConsoleApplication1


   3:  {


   4:      class Program


   5:      {


   6:          static void Main(string[] args)


   7:          {


   8:              log4net.Config.BasicConfigurator.Configure();


   9:              log4net.ILog log = log4net.LogManager.GetLogger(typeof(Program));


  10:   


  11:              log.Debug("Hello World!");


  12:              log.Info("Just info.");


  13:              log.Warn("careful this is a warning.");


  14:              log.Error("Bad news: Error occurred.");


  15:              log.Fatal("Here is the end.");


  16:          }


  17:      }


  18:  }



Compile and run the application, and you'll see output to the console like so:



log4net1



In the Hello World example we configured log4net in the most basic way possible just to get started. Using the BasicConfigurator (line 8) will cause log4net to output log entries to the console using the default layout. Line 9 requests a logger from the LogManager object.  Logger objects implement the ILog interface, which is what your application will use to instrument itself and percolate log entries.



Lines 11-15 use the logger to log a few statements with various severity levels.  log4net defines 5 such levels:




  • Debug: fine-grained statements concerning program state, typically used for debugging;


  • Info: informational statements concerning program state, representing program events or behavior tracking;


  • Warn: statements that describe potentially harmful events or states in the program;


  • Error: statements that describe non-fatal errors in the application; this level is used quite often for logging handled exceptions;


  • Fatal: statements representing the most severe of error conditions, assumedly resulting in program termination.



XML Configurator


In the previous example we used the BasicConfigurator. If we just changed the configurator to XmlConfigurator and run the application you will get the following output error:



log4net:ERROR XmlConfigurator: Failed to find configuration section 'log4net' in

the application's .config file. Check your .config file for the <log4net> and <


configSections> elements. The configuration section should look like: <section n


ame="log4net" type="log4net.Config.Log4NetConfigurationSectionHandler,log4net" /


>



This error resulted because XMLConfigurator relies on an XML document to supply configuration for log4net. The static Configure method have 10 overloads to accept the XML configuration from a file, stream, URI, or an XmlElement object. The parameterless overload of the method we used instructs log4net to load the XML from the application’s configuration file. Since our application doesn’t contain any configuration files (till now), the Configure method returned the above error.



To overcome this error, add Application Configuration File to the project and add the following XML configuration:





   1:  <configuration>  


   2:    <configSections>  


   3:      <section name="log4net" type="log4net.Config.Log4NetConfigurationSectionHandler, log4net"/>  


   4:    </configSections>  


   5:    


   6:    <log4net>  


   7:      <appender name="ConsoleAppender" type="log4net.Appender.ConsoleAppender">  


   8:        <layout type="log4net.Layout.SimpleLayout" />  


   9:      </appender>  


  10:    


  11:      <root>  


  12:        <level value="ALL" />  


  13:        <appender-ref ref="ConsoleAppender" />  


  14:      </root>  


  15:    </log4net>  


  16:  </configuration>  



Compile and run, you will see output changed to be like so:



log4net2



In addition to the Configure method, XmlConfigurator offers a static ConfigureAndWatch() method that accepts a FileInfo reference. ConfigureAndWatch() will monitor the XML configuration file and reconfigure log4net when a change is detected in this file.  This allows you to alter logging behavior while the application is running to fit your current troubleshooting requirements.



If we look at the application configurations file, the declaration of the log4net configuration section on line 3 is mandatory. The log4net configurations section [lines 6-15] consists of two sub-sections: appender and root. log4net appender is the place where your application log entries end up (Console in our example). We will talk about appenders later. The root logger controls the general behavior of log4net.  In this example, the root logger is told to send everything to the console appender.



Taming log4net Output


In the previous examples we were logging all types of severity levels. If you want to filter the logging output to fit your application’s life current phase (development, production) or troubleshooting needs, you can just change the value of <level /> XML element in your app.config.  The level value instructs the logger of the minimum level at which log entries should be processed. It can be: ALL (everything is enabled), DEBUG (identical to ALL), INFO (everything except DEBUG), WARN (warn, Error, and Fatal), ERROR (Error and Fatal), FATAL (only Fatal), OFF (logging is disabled).



The Structure of log4net



Before going further with log4net, let’s talk about its structure. log4net built using the layered approach, with four main components inside of the framework. These are Logger, Repository, Appender, and Layout.



The Logger is the main component with which your application interacts. It is also the component that generates the log messages.



The Repository is responsible for maintaining the logical organization of loggers inside the framework. Currently log4net only supported the hierarchical organization through log4net.Repository.Hierarchy namespace. If you want to extend log4net to implement new organization, you have to implement the log4net.Repository.ILoggerRepository interface or inherit class log4net.Repository.LoggerRepositorySkeleton. Almost all developers do not use any of these Repository classes; they only use the LogManager class to automatically manage the repositories and the loggers.



The Appender is used to define the output medium that log statements will go for it at the end of the day. As the name suggests, these components append themselves to the Logger component and relay the output to an output stream. You can append multiple appenders to a single logger. There are several appenders provided by the log4net framework. If you want to write your own appender, you can start by inheriting thelog4net.Appender.AppenderSkeleton class, which works as an adapter between your class and the IAppender interface. You can use Appender Filters to filter logging events sent from appenders before processing it.



The Layout component is used to display the final formatted output to the user. The output can be shown in multiple formats, depending upon the layout we are using. It can be linear or an XML file. The layout component works with an appender. There is a list of different layouts in the API documentation. You cannot use multiple layouts with an appender. To create your own layout, you need to inherit thelog4net.Layout.LayoutSkeleton class, which implements the ILayout interface.



Appenders



An appender is an object that persists your log messages someplace. In the table below a list of the appenders provided by log4net.













































































































































Appender Description
AdoNetAppender Appender that logs to a database.
AnsiColorTerminalAppender Appends logging events to the terminal using ANSI color escape sequences.
AspNetTraceAppender Appends log events to the ASP.NET TraceContext system.
BufferingForwardingAppender Buffers events and then forwards them to attached appenders.
ColoredConsoleAppender Appends logging events to the console colored.
ConsoleAppender Appends logging events to the console.
DebugAppender Appends log events to the Debug system.
EventLogAppender Writes events to the system event log.
ForwardingAppender This appender forwards logging events to attached appenders.
FileAppender Appends logging events to a file.
LocalSyslogAppender Logs events to a local syslog service.
MemoryAppender Stores logging events in an array.
NetSendAppender Logs entries by sending network messages using the NetMessageBufferSend native function.
OutputDebugStringAppender Appends log events to the OutputDebugString system.
RemoteSyslogAppender Logs events to a remote syslog daemon.
RemotingAppender Delivers logging events to a remote logging sink.
RollingFileAppender Appender that rolls log files based on size or date or both.
SmtpAppender Send an e-mail when a specific logging event occurs, typically on errors or fatal errors.
SmtpPickupDirAppender Send an email when a specific logging event occurs, typically on errors or fatal errors. Rather than sending via smtp it writes a file that another service, such as the IIS SMTP agent, can use to manage sending the messages.
TelnetAppender Appender that allows clients to connect via Telnet to receive log messages.
TraceAppender Appends log events to the Trace system.
UdpAppender Sends logging events as connectionless UDP datagrams to a remote host or multicast using the UdpClient class.


FileAppender and RollingFileAppender


These appenders write log messages to files. A typical configuration for the FileAppender might look like this:





   1:  <appender name="FileAppender" type="log4net.Appender.FileAppender">  


   2:      <file value="log.txt" />  


   3:      <appendToFile value="true" />  


   4:      <encoding value="utf-8" />  


   5:      <layout type="log4net.Layout.SimpleLayout" />  


   6:  </appender>  



Configuration attributes and its description are:




  • file: the full or relative path to the log file;


  • appendToFile: boolean indicating whether the log file should be appended (true) or overwritten (false).  If false, the file overwrite occurs during log4net initialization.  If unspecified, the log file is appended;


  • immediateFlush: boolean indicating whether to flush the log file TextWriter after each log message is written.  The default is true (flush each message after its written);


  • lockingModel: allows control over the log file locking strategy.  This can be either "log4net.Appender.FileAppender+MinimalLock" to allow for loose file locking or "log4net.Appender.FileAppender+ExclusiveLock" to lock the file during program execution. 



Keep in mind that the log file managed by FileAppender will be allowed to grow without bounds. The RollingFileAppender provides basic log file management, configurable size- or date-boxing of the log file, and limited rolling backups of the log file.





   1:  <appender name="RollingFileAppender" type="log4net.Appender.RollingFileAppender">  


   2:      <file value="log-file.txt" />  


   3:      <appendToFile value="true" />  


   4:      <rollingStyle value="Size" />  


   5:      <maxSizeRollBackups value="10" />  


   6:      <maximumFileSize value="1MB" />  


   7:      <staticLogFileName value="true" />  


   8:      <layout type="log4net.Layout.SimpleLayout" />  


   9:  </appender>



Configuration attributes and its description are:




  • rollingStyle: this controls how log files are "rolled," and can be one of the following values:


    • Once: the log file is rolled every time log4net is initialized (typically at application startup);


    • Size: the log file is rolled once it breaches a certain size;


    • Date: the log file is rolled based on the current date;


    • Composite: the log file is rolled based on size constraints and the current date;




  • maximumFileSize: the size cap on the log file.  This is an expression of size in the form of "#(KB|MB|GB)".  For instance, "100KB" or "10MB";


  • maxSizeRollBackups: the maximum number of rolled log file backups to maintain when rollingStyle is SIZE; when rollingStyle is COMPOSITE, this indicates the maximum number of roll-offs maintained per day; this property has no effect when rollingStyle is ONCE or DATE;


  • datePattern: the date pattern used to roll files based on date.  The value of this parameter needs to adhere to the format used by the SimpleDateFormatter class;


  • staticLogFileName: a bit of a misnomer - when true this setting indicates whether log4net should actively write logs to the configured file (log-file.txt in our example configuration) and maintain rolling backups by copy.  When false, this setting indicates that log4net will actively log to the latest roll-off file (e.g., log-file1.txt, log-file2.txt, log-file3.txt, etc);


  • countDirection: indicates how roll-off file numbering is managed.  When this parameter is >= 0, the newest log file will have the largest number; e.g., log-file.txt.5 will be newer than log-file.txt.4.  When countDirection < 0, the newest log file will have the lowest number; e.g., log-file.txt.1 will be newer than log-file.txt.2.  If unspecified, countDirection defaults to (-1);



Keep in mind that when using a file appender, the user running the logging process must have rights to create and/or modify the log file in order for log messages to be written properly.  In addition, log4net will create the log file if it does not exist, but it will not create directories in the log file path that do not already exist.  If log4net encounters a problem initializing the file appender (e.g., it cannot create the log file for security reasons), the log file will not be written but your application will continue to execute normally.



Using multiple appenders


You can use multiple appenders by specifying each appender you need under the root logger.



Layouts and patterns



A layout is just a template for your log messages.  Layouts are specified per-appender, and you can specify only one layout for an appender:





   1:  <appender name="ColoredConsoleAppender" type="log4net.Appender.ColoredConsoleAppender">  


   2:      <layout type="log4net.Layout.SimpleLayout" />  


   3:  </appender>  



The PatternLayout allows you to specify a printf-style template for your log entries using a "conversion pattern," and gives you the opportunity to decorate each entry with some valuable instance data. For instance, this configuration:





   1:  <appender name="ColoredConsoleAppender" type="log4net.Appender.ColoredConsoleAppender">  


   2:      <layout type="log4net.Layout.PatternLayout">  


   3:          <conversionPattern value="%date [%thread] %-5level %logger - %message%newline" />  


   4:      </layout>  


   5:  </appender>  



produces a log that appears like so:



log4net4



The conversion pattern string can include literal text and the following format expressions:















































































































expression value
%appdomain the friendly name of the appdomain from which the log entry was made
%date the local datetime when the log entry was made
%exception a formatted form of the exception object in the log entry, if the entry contains an exception; otherwise, this format expression adds nothing to the log entry
%file the file name from which the log entry was made; note that using %file has a significant performance impact and I don't recommend using it
%identity the user name of the active user logging the entry; this one is less reliable than %username; note that using %identity has a significant performance impact and I don't recommend using it
%level the severity level of the log entry (DEBUG,INFO, etc)
%line the source code line number from which the log entry was made; slow
%location some rudimentary call stack information, including file name and line number at which the log entry was made; using
%logger the name of the logger making the entry; more on this in a bit
%method the name of the method in which the log entry was made; also slow
%message the log message itself (don't forget this part!)
%newline the value of Environment.NewLine
%timestamp the milliseconds between the start of the application and the time the log entry was made
%type the full typename of the object from which the log entry was made
%username the Windows identity of user making the log entry; slow
%utcdate the UTC datetime when the log entry was made
%% a percent sign (%)


A common usage of the %logger expression is to identify the source class in the log entries. Give the class name to the logger like:



private static log4net.ILog Log = log4net.LogManager.GetLogger( System.Reflection.MethodBase.GetCurrentMethod().DeclaringType ); 



and the output will be something like:



ConsoleApplication1.Program [INFO]- this is an info message



Using this technique can help you control logging concerns of your objects. For example, add a new class “MyClass” to your ConsoleApplication and use the above approach in declaring your loggers. Add the following after the <root> section in your app.config :





   1:  <logger name="ConsoleApplication1">  


   2:        <level value="ALL" />  


   3:        <appender-ref ref="FileAppender" />  


   4:  </logger>  


   5:  <logger name="ConsoleApplication1.Program">  


   6:        <level value="ALL" />  


   7:        <appender-ref ref="ConsoleAppender" />  


   8:  </logger>  


   9:  <logger name="ConsoleApplication1.MyClass">  


  10:        <level value="ALL" />  


  11:  </logger>  



This way, the console output will display only the log statements from the Program class, the log file will contain the log statements from both Program class and MyClass class. Although MyClass doesn’t have an appender associated with it, the container namespace does and that appender who processes MyClass log statements. If you changed the level value to “OFF” for ConsoleApplication1.MyClass, the log file will not contain log statements from MyClass. When applying the previous technique keep into consideration the following:




  • Appenders accumulate through the hierarchy: if both the Program class and ConsoleApplication1 namespace are each configured to append to the console, any log from the Program class will show up twice in the console (once for the class logger and once for the namespace logger).


  • Specific logger levels deeper in the hierarchy overcome the general levels : if the Program class logging level is set to ALL and the ConsoleApplication1 namespace logging level is set to OFF, logs from the program class are still written to the appenders configured for ConsoleApplication1.



Log event context



Beside the expressions mentioned above, sometimes you need to log context information. Modify your console application to look so:





   1:  using System;


   2:  namespace ConsoleApplication1


   3:  {


   4:      class Program


   5:      {


   6:          private static log4net.ILog log = log4net.LogManager.GetLogger(System.Reflection.MethodBase.GetCurrentMethod().DeclaringType);


   7:          static void Main(string[] args)


   8:          {


   9:              log4net.Config.XmlConfigurator.Configure();


  10:              log4net.ThreadContext.Properties["myContext"] = "Logging from Main";


  11:              log.Info("Just info.");


  12:              Console.ReadLine();  


  13:          }


  14:      }


  15:  }



Now update the app.config to look like:





   1:  <?xml version="1.0" encoding="utf-8" ?>


   2:  <configuration>


   3:    <configSections>


   4:      <section name="log4net"


   5:        type="log4net.Config.Log4NetConfigurationSectionHandler, log4net"/>


   6:    </configSections>


   7:   


   8:    <log4net>


   9:   


  10:      <appender name="ConsoleAppender" type="log4net.Appender.ConsoleAppender">


  11:        <layout type="log4net.Layout.PatternLayout">


  12:          <conversionPattern value="%logger (%property{myContext}) [%level]- %message%newline" />


  13:        </layout>


  14:      </appender>


  15:   


  16:      <root>


  17:        <level value="ALL" />


  18:        <appender-ref ref="ConsoleAppender" />


  19:      </root>


  20:    </log4net>


  21:  </configuration>



Compile and run, you will got a log statement similar to:



ConsoleApplication1.Program (Logging from Main) [INFO]- Just info.



What we did here is that we added a property “myContext” to the ThreadContext static class and assigned a simple string value. This property processed by the appender through the %property{myContext} expression in the layout conversion pattern.




There are three hierarchy logging contexts available in log4net, where properties in the more granular contexts override property values in less granular contexts.



























Context Description
log4net.GlobalContext A global context shared across all application threads and app domains. If two threads set the same property on the GlobalContext, one value will overwrite the other.
log4net.ThreadContext Any properties set in this context are scoped to the calling thread. In other words, in this context two threads can set the same property to different values without stomping on each other.
log4net.ThreadLogicalContext This context behaves similarly to the ThreadContext, except that the scope is defined by logical thread boundaries. I'll be honest and say that I've never used the ThreadLogicalContext in my career, but if you're working with a custom thread pool algorithm or hosting the CLR, you may find some use for this one.


Calculated context values


Context property values don't have to be strings. You can set the value of a context property to any object reference; then the object's ToString can be used to obtain the needed context property when a logging event occurs. This technique could be used to log whatever state you want at the time of each logging event.



ThreadContext Stacks


ThreadContext and ThreadLogicalContext can store property values in stacks available via the Stacks static property of each class. Pushing a property value onto a stack returns an IDisposable that, when disposed, pops the property value off of the stack.  The logging output reflects the state of the context stack at each logging event; the stack is represented as a space-delimited list, with newer items appearing later in the list. Its like printing the current call stack in every log statement. check this example:





   1:  using System;


   2:  namespace ConsoleApplication1


   3:  {


   4:      class Program


   5:      {


   6:          private static log4net.ILog log = log4net.LogManager.GetLogger(System.Reflection.MethodBase.GetCurrentMethod().DeclaringType);


   7:          static void Main(string[] args)


   8:          {


   9:              log4net.Config.XmlConfigurator.Configure();


  10:              using (log4net.ThreadContext.Stacks["myContext"].Push("Main"))


  11:              {


  12:                  FirstAction();


  13:                  SecondAction();


  14:              }


  15:              Console.ReadLine();  


  16:          }


  17:   


  18:          static void FirstAction()


  19:          {


  20:              using (log4net.ThreadContext.Stacks["myContext"].Push("FirstAction"))


  21:              {


  22:                  UtilityRoutine();


  23:              }            


  24:          }


  25:   


  26:          static void SecondAction()


  27:          {


  28:              using (log4net.ThreadContext.Stacks["myContext"].Push("SecondAction"))


  29:              {


  30:                  UtilityRoutine();


  31:                  FirstAction();


  32:              }


  33:          }


  34:   


  35:          static void UtilityRoutine()


  36:          {


  37:              using (log4net.ThreadContext.Stacks["myContext"].Push("UtilityRoutine"))


  38:              {


  39:                  log.Info("this is an info message");


  40:              }


  41:          }  


  42:      }


  43:  }



Compile and run, you will get these log messages:

ConsoleApplication1.Program (Main FirstAction UtilityRoutine) [INFO]- this is an info message


ConsoleApplication1.Program (Main SecondAction UtilityRoutine) [INFO]- this is an info message


ConsoleApplication1.Program (Main SecondAction FirstAction UtilityRoutine) [INFO]- this is an info message




 



Filters



Filters are applied to individual appenders via the log4net configuration, and they help the appender determine whether a log event should be processed by the appender. The following configuration defines two file appenders, each with a unique filter applied:





   1:  <?xml version="1.0" encoding="utf-8" ?>  


   2:  <configuration>  


   3:    <configSections>  


   4:      <section name="log4net" type="log4net.Config.Log4NetConfigurationSectionHandler, log4net"/>  


   5:    </configSections>  


   6:    <log4net>  


   7:      <appender name="LogFileAppender" type="log4net.Appender.FileAppender">  


   8:        <file value="log.txt" />  


   9:        <filter type="log4net.Filter.LevelRangeFilter">  


  10:          <levelMin value="DEBUG" />  


  11:          <levelMax value="WARN" />  


  12:        </filter>  


  13:        <layout type="log4net.Layout.SimpleLayout" />  


  14:      </appender>  


  15:      <appender name="ErrorFileAppender" type="log4net.Appender.FileAppender">  


  16:        <file value="errors.txt" />  


  17:        <filter type="log4net.Filter.LevelRangeFilter">  


  18:          <levelMin value="ERROR" />  


  19:          <levelMax value="FATAL" />  


  20:        </filter>  


  21:        <layout type="log4net.Layout.SimpleLayout" />  


  22:      </appender>  


  23:      <root>  


  24:        <level value="DEBUG" />  


  25:        <appender-ref ref="LogFileAppender" />  


  26:        <appender-ref ref="ErrorFileAppender" />  


  27:      </root>  


  28:    </log4net>  


  29:  </configuration> 



The filter on the first appender will log statements with levels DEBUG, INFO, and WARN; the filter on the second appender will log statements with levels ERROR and FATAL. There are many filters available in log4net, we will review them quickly.



log4net.Filter.LoggerMatchFilter Filters log events based on the name of the logger object from which they are emitted. This filter can be configured using the following properties:




  • loggerToMatch: a string value to match against the message's logger name.  The match is made using the String.StartsWith method;


  • acceptOnMatch: a boolean value indicating whether a matching logger name results in accepting the message (true) or rejecting it (false).  This defaults to true, meaning that only matching logger names will be allowed into the appender.



log4net.Filter.LevelMatchFilter Filters log statements that match (or don’t match) a specific logging level. This filter can be configured using the following properties:




  • levelToMatch: the log level to match - either DEBUG, INFO, WARN, ERROR, or FATAL;


  • acceptOnMatch: a boolean value indicating whether to accept log levels matching the levelToMatch property (true), or reject log levels matching the levelToMatch property (false).  Defaults to true.



log4net.Filter.LevelRangeFilter Similar to the LevelMatchFilter, except that instead of filtering a single log level, this filters on an inclusive range of contiguous levels. This filter can be configured using the following properties:




  • levelMin: the minimum log level to match - either DEBUG, INFO, WARN, ERROR, or FATAL;


  • levelMax: the minimum log level to match - either DEBUG, INFO, WARN, ERROR, or FATAL;


  • acceptOnMatch: a boolean value indicating whether to accept log levels matching the levelToMatch property (true), or to punt filtering to the next filter in the chain (false).  Defaults to true.  Note that any log level outside of the [levelMin, levelMax] range is denied by this filter.



log4net.Filter.StringMatchFilter Filters log events based on a string or regular expression match against the log message. This filter can be configured using the following properties:




  • regexToMatch: a regular expression to match against the log message.  Note this regex is created with the Compiled option enabled for performance;


  • stringToMatch: a static string to match against the log message.  The match is made using the String.IndexOf method to see if the static string exists in the log message, which is a case-sensitive search.


  • acceptOnMatch: a boolean value indicating whether to accept log messages matching the string or regex (true), or to deny log messages matching the string or regex (false).  Defaults to true. 



log4net.Filter.PropertyFilter Filters log events based on a value or regular expression match against a specific context property.




  • key: the name of the property value to match;


  • regexToMatch: a regular expression to match against the specified property value.  Note this regex is created with the Compiled option enabled for performance;


  • stringToMatch: a static string to match against the specified property value.  The match is made using the String.IndexOf method to see if the static string exists in the property value, which is a case-sensitive search.


  • acceptOnMatch: a boolean value indicating whether to accept messages with a property value matching the string or regex (true), or to deny messages with a property value matching the string or regex (false).  Defaults to true.



log4net.Filter.DenyAllFilter This filter simply denies all filtering.  When this is used, it's always at the end of a filter chain to block unwanted log messages from the appender.



Lossy logging



If you want comprehensive log to be there in case of errors but you worry about the resources consumed by logging, you might use lossy logging.  Lossy logging gives the best of both worlds, under normal operation your application will not log any messages; however, if your application logs an error, a small batch of messages leading up to the error is placed into the log, giving you the error and a snapshot of system activity just before it happened.



Lets modify our code to be like:





   1:  using System;


   2:  namespace ConsoleApplication1


   3:  {


   4:      class Program


   5:      {


   6:          static log4net.ILog Log = log4net.LogManager.GetLogger(System.Reflection.MethodBase.GetCurrentMethod().DeclaringType);


   7:          static void Main( string[] args )


   8:          {


   9:              log4net.Config.XmlConfigurator.Configure();


  10:              for( int i = 0; i < 100; ++i )


  11:              {


  12:                  Log.DebugFormat( "this is debug msg #{0}", i );


  13:              }                


  14:              Log.Error( "error: an error occurred!" );           


  15:              Log.Warn( "warning: you've been warned" );


  16:              


  17:              Console.ReadLine();


  18:          }


  19:      }


  20:  }



Let's modify our app.config to look like:





   1:  <?xml version="1.0" encoding="utf-8" ?>


   2:  <configuration>


   3:    <configSections>


   4:      <section name="log4net" type="log4net.Config.Log4NetConfigurationSectionHandler, log4net"/>


   5:    </configSections>


   6:   


   7:    <log4net>


   8:      <appender name="ConsoleAppender" type="log4net.Appender.ConsoleAppender">


   9:        <layout type="log4net.Layout.SimpleLayout" />


  10:      </appender>


  11:   


  12:      <appender name="LossyConsoleAppender" type="log4net.Appender.BufferingForwardingAppender">


  13:        <bufferSize value="20" />


  14:        <lossy value="true"/>


  15:        <evaluator type="log4net.Core.LevelEvaluator">


  16:          <threshold value="ERROR" />


  17:        </evaluator>


  18:        <appender-ref ref="ConsoleAppender" />


  19:      </appender>


  20:   


  21:      <root>


  22:        <level value="DEBUG" />


  23:        <appender-ref ref="LossyConsoleAppender" />


  24:      </root>


  25:    </log4net>


  26:  </configuration>



Compile and run, you will see output like:



log4net5



The logging configuration defines two appenders, one very generic Console appender and a BufferingForwardingAppender.  As the name implies, the latter appender buffers log messages and forwards them in batches to one or more other appenders.  You can probably tell from the configuration XML that I've set this appender up with a 20-message buffer.  The lossy and evaluator parameters work together to define when the log message buffer is forwarded to the "base" appender.



The program issues a total of 102 log messages (100 DEBUG, one ERROR, and one WARN), but the console only contains 20 messages (19 DEBUG and 1 ERROR).  So what happened to the other 82 DEBUG and WARN messages?



When the BufferingForwardingAppender's lossy property is enabled, the appender will buffer log messages without forwarding them.  If the buffer fills up, the oldest messages are dropped from the buffer to make room for the new messages. 



The evaluator property determines when the appender forwards the messages from the buffer to its base appenders.  There is only one evaluator defined in log4net - the LevelEvaluator.  The LevelEvaluator triggers the forward when a log message is received that meets or exceeds the configured threshold.  The example above is configured so that an ERROR message triggers the appender to forward its buffer to the ConsoleAppender.



Lossy Appender Types log4net provides the following appenders that can operate “lossy” :



log4net.Appender.AdoNetAppender

log4net.Appender.RemotingAppender


log4net.Appender.SmtpAppender


log4net.Appender.SmtpPickupDirAppender


log4net.Appender.BufferingForwardingAppender



Configuring log4net Programmatically


Sometimes we are in the mood to code as quickly as possible without getting into configuration files. Normally, that happens when we are trying to test something. In that case, you have another way to do the configuration. All of the long configuration files that we saw in the previous section can be defined programmatically using a few lines of code. See the following code:





   1:  // using a FileAppender with a PatternLayout


   2:  log4net.Config.BasicConfigurator.Configure( new log4net.Appender.FileAppender(new log4net.Layout.PatternLayout("%d [%t]%-5p %c [%x] &lt;%X{auth}&gt; - %m%n"),"testfile.log"));


   3:   


   4:  // using a FileAppender with an XMLLayout


   5:  log4net.Config.BasicConfigurator.Configure( new log4net.Appender.FileAppender(new log4net.Layout.XMLLayout(),"testfile.xml"));


   6:   


   7:  // using a ConsoleAppender with a PatternLayout


   8:  log4net.Config.BasicConfigurator.Configure( new log4net.Appender.ConsoleAppender(new log4net.Layout.PatternLayout("%d [%t] %-5p %c [%x] &lt;%X{abc}&gt; - %m%n")));


   9:   


  10:  // using a ConsoleAppender with a SimpleLayout


  11:  log4net.Config.BasicConfigurator.Configure( new log4net.Appender.ConsoleAppender(new log4net.Layout.SimpleLayout()));



You can see that while it is easy to code here, you can't configure settings for individual loggers. All of the settings that are defined here are applied to the root logger.



Log4net Best Practices



1- Use a unique logger object for each type in your application and give it the class name. Like so:



static log4net.ILog Log = log4net.LogManager.GetLogger(System.Reflection.MethodBase.GetCurrentMethod().DeclaringType);



2- Whenever you catch an exception, log it.  Even if you just plan to throw it again, log it.  In addition, log4net knows how to format Exception objects, so don't try and build your own string from the exception data, just pass the exception to the logging statement. Like So:



Log.Error("An exception raised due to XYZ", e);



3- Log to mark the activity and steps of your code.



4- Check for null references before logging any property. Logging code is code, and it should be treated the same way.



5- If an argument to the log method is expensive to obtain, be sure to guard your log statement with a check of the appropriate Is*Enabled property



if( Log.IsDebugEnabled ){ /* log statement */ }



6- Before an object calls on a shared dependency, consider pushing a tag onto the log context stack.  This will allow you to determine the caller of the shared code that logged a particular message.



7- Whenever you use a formatted log statement, surround the format argument placeholders (the {}'s) with brackets or parentheses. This will mark the areas in each log message. This make the log scan a bit easier and makes empty or null formatting arguments more obvious. 



Suggested logging levels



INFO Level




  • The start and end of the method


  • The start and end of any major loops


  • The start of any major case/switch statements



DEBUG Level




  • Any parameters passed into the method


  • Any row counts from result sets I retrieve


  • Any datarows that may contain suspicious data when being passed down to the method


  • Any "generated" file paths, connection strings, or other values that could get mungled up when being "pieced together" by the environment.



ERROR Level




  • Handled exceptions


  • Invalid login attempts (if security is an issue)


  • Bad data that I have intercepted forreporting



FATAL Level




  • Unhandled exceptions.



 



In this post I tried to cover as much as possible about logging using log4net. Although logging is extremely useful, keep in mind that it is not free, it consumes resources and the more you log the less you can find. So be careful, and Good Luck.