LowLevelDesign.NLog.Ext and ETW targets for NLog


UPDATE 2019.01.30: All the features described in this post, as well as some other improvements, are available in the official NLog.Etw package. Please use it in place of my custom package.

I really like the NLog library and I use it pretty often in my projects. Some time ago I wrote a post in which I showed you my preferred debug and production configuration. Other day I presented you a simple layout renderer for assembly versions. Today, I would like to inform you that all those goodies 😉 are available in my brand new LowLevelDesign.NLog.Ext Nuget package.

Additionally, you may find in it two ETW NLog targets. ETW (Event Tracing for Windows) is a very effective way of logging and its support in kernel makes it a great choice for verbose/trace/debug logs. Moreover, if you are using Windows Performance Toolkit in your performance analysis, providing your own ETW messages will help you correlate system events with methods in your application. ETW infrastructure is highly customizable (check Semantic Logging Application Block to see how your logs might look like and how they might be consumed:)).

Continue reading

Stopwatch vs. DateTime


.NET developers usually know they should measure code performance using a Stopwatch class from the System.Diagnostics namespace. From time to time though I see code where someone uses DateTime instances for this purpose. And it’s not very surprising as DateTime class is usually the one that comes to mind when you think of time in .NET. In today’s post I would like to show you the difference in accuracy of both those approaches and the price you need to pay using either of them. We will work on this sample code that does nothing but measure time :):

Continue reading

ASP.NET MVC bundles internals


The idea of minimizing and combining multiple script and style files into one file has been popular among web developers for quite some time. With the 4th version of ASP.NET MVC Microsoft introduced a mechanism (called bundles) that allow .NET developers to automate and control this process. Although bundles are quite easy to configure and use they might sometimes do not behave as expected. In this post I’m going to acquaint you with bundles internals and present you ways to troubleshoot problems they may generate.

Continue reading

Injecting code into .NET applications


Recently I have been playing with Function Evaluation available in .NET debugging API. This functionality allows a managed debugger to inject some arbitrary code while the debuggee is stopped. The injected code might be simply a call to the object’s ToString method or to a property getter. As a developer you profit from this service when you use Watch windows or when you run some code in the Immediate window in Visual Studio. In this post I will present you my MDbg plugin (includes a command: inject) that adopts the funceval API and an example diagnostics case in which I used it.

Continue reading

Configuring ASP.NET authentication log


Some time ago I wrote about ASP.NET Health Monitoring – a logging infrastructure provided by the .NET framework, easily configurable through web.config. In that post I was presenting heart beat and error events. Today I would like to show you how to collect ASP.NET authentication audit logs. There are special events groups registered in the global web.config for this purpose:

        <healthMonitoring>
            ...
            <eventMappings>
                ...
                <add name="All Audits" type="System.Web.Management.WebAuditEvent,System.Web,Version=4.0.0.0,Culture=neutral,PublicKeyToken=b03f5f7f11d50a3a"
                    startEventCode="0" endEventCode="2147483647" />
                <add name="Failure Audits" type="System.Web.Management.WebFailureAuditEvent,System.Web,Version=4.0.0.0,Culture=neutral,PublicKeyToken=b03f5f7f11d50a3a"
                    startEventCode="0" endEventCode="2147483647" />
                <add name="Success Audits" type="System.Web.Management.WebSuccessAuditEvent,System.Web,Version=4.0.0.0,Culture=neutral,PublicKeyToken=b03f5f7f11d50a3a"
                    startEventCode="0" endEventCode="2147483647" />
            </eventMappings>
        </healthMonitoring>

Though, using the All Audits set will cause your application to generate an audit event for each served request. If we then would store those events in a SQL Server database we might put a heavy load on the server. In this post I will show you how to reduce the number of audit events to login attempts and then store them safely in a database.

Continue reading

Diagnosing a collation issue in a MySql stored procedure


We are using Elmah on production to log problems in our web applications. Elmah logs are stored in a MySql table which structure is a slightly modified version of the elman_error table from the original Elmah script (I changed the engine to InnoDB and added partitioning over TimeUTC column):

CREATE TABLE IF NOT EXISTS `elmah_error` (
  `ErrorId` CHAR(36) NOT NULL ,
  `Application` VARCHAR(60) NOT NULL ,
  `Host` VARCHAR(50) NOT NULL ,
  `Type` VARCHAR(100) NOT NULL ,
  `Source` VARCHAR(60) NOT NULL ,
  `Message` VARCHAR(500) NOT NULL ,
  `User` VARCHAR(50) NOT NULL ,
  `StatusCode` INT(10) NOT NULL ,
  `TimeUtc` DATETIME NOT NULL ,
  `Sequence` INT(10) NOT NULL AUTO_INCREMENT ,
  `AllXml` TEXT NOT NULL ,
  PRIMARY KEY (`Sequence`, `TimeUtc`) ,
  INDEX `IX_ErrorId` (`ErrorId`(8) ASC) , -- UNIQUE can't be created if it does not include all partition columns
  INDEX `IX_ELMAH_Error_App_Time_Seql` (`Application`(10) ASC, `TimeUtc` DESC, `Sequence` DESC) ,
  INDEX `IX_ErrorId_App` (`ErrorId`(8) ASC, `Application`(10) ASC) )
ENGINE InnoDB DEFAULT CHARACTER SET latin2
partition by range columns(`TimeUtc`)
(
  partition before20130719 values less than ('2013-07-19 00:00')
);

Continue reading

Find a performance counter instance by a process ID


Performance Counters are a great feature of Windows which allow you to monitor applications and the whole system in a noninvasive manner. Which makes them even better is a fact that you can gather the performance data remotely. You can find some more information on using Performance Counters in my previous post: Diagnosing applications using Performance Counters. When diagnosing a faulting application I usually start with IO, Memory and CPU metrics available in the Process counter. The Process counter has a separate instance for each process that is running on your machine. By default, instance names are composed of the process name they represent and some identifier (in case there are multiple processes with the same name), eg. w3wp, w3wp#1, w3wp#2. As I’m mostly working with web applications hosted in IIS I often ran into problem which counter instance represents an application pool I want to monitor. So I wrote a simple Powershell script that will find the counter by process id:

function GetPidsFromPerfCounter([string]$ComputerName, [string]$pcounter, [int]$ProcessId, [string]$f) {
  # dump counter values
  typeperf -f CSV "$ComputerName$pcounter" -sc 1 -o $f -y | Out-Null
  # import and parse the CSV file
  $t = import-csv $f -Delimiter ","
  $t.psobject.Properties | select -skip 1 | ? { 
    if ($ProcessId -ge 0) { $_.value -eq $ProcessId } else { $true }
  } | % { "{1,6} => {0}" -f $_.Name,$_.Value } | Sort-Object
}

function Find-ProcessCounterByPid(
  [Parameter(Mandatory=$False,ValueFromPipeline=$True)][int]$ProcessId = -1,
  [Parameter(Mandatory=$False,ValueFromPipeline=$False)][string]$ComputerName = $null,
  [Parameter(Mandatory=$False,ValueFromPipeline=$False)][switch]$IncludeDotNet = $False
) {
  if (-not [String]::IsNullOrEmpty($ComputerName) -and -not $ComputerName.StartsWith("\\")) {
      $ComputerName = "\\" + $ComputerName
  }
  $f = [System.IO.Path]::GetTempFileName()
  
  # native counters
  GetPidsFromPerfCounter $ComputerName "\Process(*)\ID Process" $ProcessId $f
  
  # for .net counters we need to grap CLR Memory\ID Process
  if ($IncludeDotNet) {
    Write-Host "  ------- .NET PIDs ---------"
    GetPidsFromPerfCounter $ComputerName "\.NET CLR Memory(*)\Process ID" $ProcessId $f
  }
  
  del $f
}

You might now wonder why I haven’t used the Get-Counter cmdlet. Unfortunately there is some bug in it and it does not print counter instance indexes (the part coming after # in the instance name) which, in our case, is a core requirement. You can paste the above code into your Powershell module and make the GetPidsFromPerfCounter private. Then you can call Find-ProcessCounterByPid with no arguments – in which case the cmdlet will print all available counter instances:

PS Diagnostics> Find-ProcessCounterByPid
     0 => \\PECET\Process(_Total)\ID Process
     0 => \\PECET\Process(Idle)\ID Process
     4 => \\PECET\Process(System)\ID Process
   280 => \\PECET\Process(smss)\ID Process
   396 => \\PECET\Process(csrss)\ID Process
   404 => \\PECET\Process(svchost#5)\ID Process
   456 => \\PECET\Process(wininit)\ID Process
   464 => \\PECET\Process(csrss#1)\ID Process
   532 => \\PECET\Process(winlogon)\ID Process
   548 => \\PECET\Process(services)\ID Process
   572 => \\PECET\Process(lsass)\ID Process
   576 => \\PECET\Process(nvxdsync)\ID Process
   664 => \\PECET\Process(svchost)\ID Process
   700 => \\PECET\Process(nvvsvc)\ID Process
   724 => \\PECET\Process(nvSCPAPISvr)\ID Process
   752 => \\PECET\Process(nvvsvc#1)\ID Process
   768 => \\PECET\Process(svchost#1)\ID Process
   796 => \\PECET\Process(SkyDrive)\ID Process
   820 => \\PECET\Process(svchost#2)\ID Process
   860 => \\PECET\Process(dwm)\ID Process
   896 => \\PECET\Process(svchost#3)\ID Process
   912 => \\PECET\Process(chrome#11)\ID Process
   964 => \\PECET\Process(svchost#4)\ID Process
  1008 => \\PECET\Process(vpnui)\ID Process
  1148 => \\PECET\Process(vmware-authd)\ID Process
  1204 => \\PECET\Process(vpnagent)\ID Process
  1236 => \\PECET\Process(svchost#6)\ID Process
  1244 => \\PECET\Process(googledrivesync)\ID Process
  1384 => \\PECET\Process(spoolsv)\ID Process
  1420 => \\PECET\Process(svchost#7)\ID Process
  ...

or specify a concrete PID:

PS Diagnostics> Find-ProcessCounterByPid 768
   768 => \\PECET\Process(svchost#1)\ID Process

Additionally, if you are also interested in profiling .NET Applications, add -IncludeDotNet switch that will list .NET counters instance indexes, eg.:

PS Diagnostics> Find-ProcessCounterByPid -IncludeDotNet 5824
  5824 => \\PECET\Process(powershell)\ID Process
  ------- .NET PIDs ---------
  5824 => \\PECET\.NET CLR Memory(powershell)\Process ID

By adding -ComputerName switch you may also collect performance data from a remote machine. I hope you will find the script useful. If you have any ideas how to improve it drop me a comment 🙂

Be careful with varchars in Dapper!


In this post I will show you an interesting problem that we experienced when querying a SQL Server database with Dapper. I will use a simplified data model and a sample application so you could reproduce the issue on your own. Our sample table will look as follows:

create table Stats (
    StatsDay datetime not null,
    EventName varchar(100) not null,
    Item varchar(100) not null,
    Value int null,
    constraint PK_Stats primary key(Item,EventName,StatsDay)
)

Continue reading

Life of Exception in ASP.NET


In this post I’m going to show you the way ASP.NET (MVC) handles exceptions that occur in web applications. We will also examine different places where we can hook our own loggers. Our application will be a very basic ASP.NET MVC project with one controller and one view:

using System;
using System.Web;
using System.Web.Mvc;

[HandleError]
public class HomeController : Controller
{
    //
    // GET: /Home/
    public ActionResult Index()
    {
        return View();
    }
    
    public ActionResult Exception() {
        throw new Exception("test exception");
    }
}
@{
    ViewBag.Title = "test title";
}

<h2>Index page</h2>

<a href="@Url.Action("Exception")">throw exception</a>

Continue reading

Making elmah.axd a log viewer for multiple applications


Elmah is a great exception logger for web applications. Next to the exception data (stacktrace, exception message etc.) it collects detailed request and runtime information. If I also mention that it’s easy to install and highly configurable it comes with no surprise that it became an industrial logging standard for .NET web applications. Elmah gives you a great choice of places where you can send your logs, though a database is the one I consider most useful. What I also value in Elmah is its log viewer (elmah.axd) – it has a nice exception list and a great exception details screen – I wish the ASP.NET Yellow Screen of Death had that look :). The only thing I don’t really like in this viewer is a fact that by default it is bound to the application that has Elmah installed and is accessible only under hxxp://app-address/elmah.axd. If you do not secure access to this handler everyone can see detailed information on your code and environment – just have a look how many developers forget about it. In this post I will show you how to remove the elmah.axd handler from your application and how to create a separate ASP.NET application that would be a central Elmah log viewer for your applications.

Continue reading