Logging in .NET with AOP using PostSharp

Here is a simple application that logs to console. Logging is programmed with Aspect Oriented Programming paradigm as an aspect using PostSharp. As a logger library I use log4net.

postsharp

Sample solution can be downloaded from here https://github.com/mchudinov/LoggingPostSharp. It is compatible with Visual Studio 2012, MonoDevelop 5, and Xamarin Studio 5.

1. Add PostSharp to the solution
The easiest way to add PostSharp to a solution is to do it in Visual Studio. Another way is to add the PostSharp NuGet package and configure project file manually.

Open solution context menu (right click mouse button) and use [Add PostSharp to project].

solution_properties

This will add all the necessary packages and references to the project and enable new building targets for PostSharp.

Here are the changes PostSharp makes in the solution.

  • PostSharp package is added to packages.config
<?xml version="1.0" encoding="utf-8"?>
<packages>
  <package id="PostSharp" version="4.0.34" targetFramework="net45" />
</packages>
  • Reference to PostSharp library is added to the solution file
  <ItemGroup>
    <Reference Include="PostSharp">
      <HintPath>..\packages\PostSharp.4.0.34\lib\net35-client\PostSharp.dll</HintPath>
      <Private>True</Private>
    </Reference>
    <Reference Include="System" />
  </ItemGroup>
  • And new build targets are added at the end of the project file.
<Import Project="..\packages\PostSharp.4.0.34\tools\PostSharp.targets" Condition="Exists('..\packages\PostSharp.4.0.34\tools\PostSharp.targets')" />
  <Target Name="EnsurePostSharpImported" BeforeTargets="BeforeBuild" Condition="'$(PostSharp30Imported)' == ''">
    <Error Condition="!Exists('..\packages\PostSharp.4.0.34\tools\PostSharp.targets')" Text="This project references NuGet package(s) that are missing on this computer. Enable NuGet Package Restore to download them.  For more information, see http://www.postsharp.net/links/nuget-restore." />
    <Error Condition="Exists('..\packages\PostSharp.4.0.34\tools\PostSharp.targets')" Text="The build restored NuGet packages. Build the project again to include these packages in the build. For more information, see http://www.postsharp.net/links/nuget-restore." />
  </Target>

Here is the whole csproj file from my simple console application with PostSharp

<?xml version="1.0" encoding="utf-8"?>
<Project DefaultTargets="Build" ToolsVersion="4.0" xmlns="http://schemas.microsoft.com/developer/msbuild/2003">
  <PropertyGroup>
    <Configuration Condition=" '$(Configuration)' == '' ">Debug</Configuration>
    <Platform Condition=" '$(Platform)' == '' ">x86</Platform>
    <ProjectGuid>{5DFE28F7-3DFC-4633-A97D-F55863E58767}</ProjectGuid>
    <OutputType>Exe</OutputType>
    <RootNamespace>LoggingPostSharp</RootNamespace>
    <AssemblyName>LoggingPostSharp</AssemblyName>
    <TargetFrameworkVersion>v4.5</TargetFrameworkVersion>
    <DontImportPostSharp>True</DontImportPostSharp>
  </PropertyGroup>
  <PropertyGroup Condition=" '$(Configuration)|$(Platform)' == 'Debug|x86' ">
    <DebugSymbols>true</DebugSymbols>
    <DebugType>full</DebugType>
    <Optimize>false</Optimize>
    <OutputPath>bin\Debug</OutputPath>
    <DefineConstants>DEBUG;</DefineConstants>
    <ErrorReport>prompt</ErrorReport>
    <WarningLevel>4</WarningLevel>
    <PlatformTarget>x86</PlatformTarget>
    <Externalconsole>true</Externalconsole>
  </PropertyGroup>
  <PropertyGroup Condition=" '$(Configuration)|$(Platform)' == 'Release|x86' ">
    <DebugType>full</DebugType>
    <Optimize>true</Optimize>
    <OutputPath>bin\Release</OutputPath>
    <ErrorReport>prompt</ErrorReport>
    <WarningLevel>4</WarningLevel>
    <PlatformTarget>x86</PlatformTarget>
    <Externalconsole>true</Externalconsole>
  </PropertyGroup>

  <ItemGroup>
    <Reference Include="PostSharp">
      <HintPath>..\packages\PostSharp.4.0.34\lib\net35-client\PostSharp.dll</HintPath>
      <Private>True</Private>
    </Reference>
    <Reference Include="System" />
  </ItemGroup>

  <ItemGroup>
    <Compile Include="Program.cs" />
    <Compile Include="Properties\AssemblyInfo.cs" />
  </ItemGroup>
  <ItemGroup>
    <None Include="packages.config" />
  </ItemGroup>

  <Import Project="$(MSBuildBinPath)\Microsoft.CSharp.targets" />
  <Import Project="..\packages\PostSharp.4.0.34\tools\PostSharp.targets" Condition="Exists('..\packages\PostSharp.4.0.34\tools\PostSharp.targets')" />
  <Target Name="EnsurePostSharpImported" BeforeTargets="BeforeBuild" Condition="'$(PostSharp30Imported)' == ''">
    <Error Condition="!Exists('..\packages\PostSharp.4.0.34\tools\PostSharp.targets')" Text="This project references NuGet package(s) that are missing on this computer. Enable NuGet Package Restore to download them.  For more information, see http://www.postsharp.net/links/nuget-restore." />
    <Error Condition="Exists('..\packages\PostSharp.4.0.34\tools\PostSharp.targets')" Text="The build restored NuGet packages. Build the project again to include these packages in the build. For more information, see http://www.postsharp.net/links/nuget-restore." />
  </Target>

</Project>

All these changes can be made manually without PostSharp Extension.

2. Ceate Log aspect and use it
I use OnMethodBoundaryAspect class that controls any other method execution on boundaries: entry to the method, success exit and exception. This is called advices in the aspect oriented programming terminology.

Here is my simple class-aspect that logs data on entry, exit and exception. Method DisplayObjectInfo prints arguments to any other method that uses Log aspect.

[Serializable]
class LogAttribute : OnMethodBoundaryAspect
{
	static readonly ILog log = LogManager.GetLogger(typeof(MainClass));
	public override void OnEntry(MethodExecutionArgs args)
	{
		log.InfoFormat("Entering {0}.{1}.", args.Method.DeclaringType.Name, args.Method.Name);
		log.Debug(DisplayObjectInfo(args));
	}

	public override void OnExit(MethodExecutionArgs args)
	{
		log.DebugFormat("Leaving {0}.{1}. Return value {2}", args.Method.DeclaringType.Name, args.Method.Name, args.ReturnValue);
	}

	public override void OnException(MethodExecutionArgs args)
	{
		log.ErrorFormat("Exception {0} in {1}", args.Exception, args.Method);
		args.FlowBehavior = FlowBehavior.Continue;
	}

	static string DisplayObjectInfo(MethodExecutionArgs args)
	{
		StringBuilder sb = new StringBuilder();
		Type type = args.Arguments.GetType();
		sb.Append("Method " + args.Method.Name );
		sb.Append("\r\nArguments:");
		FieldInfo[] fi = type.GetFields();
		if (fi.Length > 0)
		{
			foreach (FieldInfo f in fi)
			{
				sb.Append("\r\n " + f + " = " + f.GetValue(args.Arguments));
			}
		}
		else
			sb.Append("\r\n None");

		return sb.ToString();
	}
}

OnException advice puts the whole adviced method into try-catch block.
Note this line
args.FlowBehavior = FlowBehavior.Continue;
in OnException advice. This will continue execution after the exception is caught OUT of method boundary. If you need that execution continues right after the exception is thrown then try-catch block must be written explicitly (not by the aspect).

Using this aspect is trivial:

public static void Main(string[] args)
{
	Echo("Echo Me");
	Console.WriteLine("After");
	Console.ReadLine();
}

[Log]
static void Echo(string str)
{
	Console.WriteLine(str);
	throw new Exception("except me!");
}

3. Add log4net as it is described in this post Logging in .NET Mono on Linux and Windows

4. Compile and run application
Note that “After” is written to the log. It means that execution continues after the exception is thrown and without explicit try-catch block. It means that
args.FlowBehavior = FlowBehavior.Continue; option works.

output

5. Mono on Linux
Applications that uses PostSharp version 4 can not be build on Linux with Mono version 3 (.NET 4.5). Compiler complains about absence of Microsoft.Common.CurrentVersion.targets file. But Mono application that was compiled on Windows runs on Linux just fine!
Here is console output from the same application on my lovely Mint 17 running Mono 3.2.8

2014-10-29