Month: October 2015 | thoean.com

Logging an exception and structured message data with ASP.NET 5

Once you started using ASP.NET 5 (aka. ASP.NET vNext), it’s surprisingly difficult to add a message that contains structured data to an exception. The LoggerExtensions either supports a flat message (which is probably good for a lot of cases), but it doesn’t support structured data for more sophisticated analysis.

Workaround

Let’s quickly look into a simple workaround, which is a 2-liner instead of a one-liner:

var values = new FormattedLogValues("Error during operation {Operation}..", myOperation);
logger.LogError(values, ex);

1 2	var values = new FormattedLogValues("Error during operation {Operation}..", myOperation); logger.LogError(values, ex);

Solution

The logging extensions only support structured log messages when FormattedLogValues are provided, but don’t provide an interface to do the formatting behind the scenes. This is what I actually want to do:

logger.LogError(ex, "Error during operation {Operation}..", myOperation);

1	logger.LogError(ex, "Error during operation {Operation}..", myOperation);

I have created a pull request to the aspnet/Logging repository, but as of late October 2015, this wasn’t accepted. For the time being, you can simply copy/paste my changes to your project and start using the simplified logging capabilities.

Background

Why am I so obsessed with structured data in messages? Probably simply because I got used to it. I started using Elasticsearch as a logging sink over a year ago, and I mostly look into analyzing fields instead of full text messages. The detailed story is long, and probably worth a few posts, but it’s mostly around analyzing numeric data like performance data, or in the case of errors, by looking into categories of errors (outside of a hard to read error numbers).

Service level tests with the .NET Execution Environment (DNX)

While writing a fairly simple RESTful service with ASP.NET 5, I started to leverage the ease of self-hosting with the .NET Execution Environment (DNX) by executing service-level tests as part of the automated build. I use Powershell for the build script. I first publish the service to a temporary directory, start it in a background thread, and perform the actual tests.

function Invoke-Build {
    dnu publish .\src\Service\project.json --out .\tmp\service --no-source --configuration Release --quiet
}

function Run-ServiceTests {
    # start the service in the background
    $cwd = Get-Location
    Start-Job -Name MyServiceName -ScriptBlock ({param($path)
        Set-Location -Path $path
        .\tmp\service\web.cmd
    }) -ArgumentList $cwd

    # wait until the service is started; instead of waiting for a random time, ping the service until it starts responding
    Start-Sleep -Seconds 5

    # run the service tests
    dnx -p .\test\ServiceTests\project.json test

    # stop the job and also write the output
    Get-Job -Name LabelPrintingService | Stop-Job
    Get-Job -Name LabelPrintingService | Receive-Job
}

Invoke-Build
Run-ServiceTests

function Invoke-Build {

dnu publish .\src\Service\project.json --out .\tmp\service --no-source --configuration Release --quiet

}

function Run-ServiceTests {

# start the service in the background

$cwd = Get-Location

Start-Job -Name MyServiceName -ScriptBlock ({param($path)

Set-Location -Path $path

.\tmp\service\web.cmd

}) -ArgumentList $cwd

# wait until the service is started; instead of waiting for a random time, ping the service until it starts responding

Start-Sleep -Seconds 5

# run the service tests

dnx -p .\test\ServiceTests\project.json test

# stop the job and also write the output

Get-Job -Name LabelPrintingService | Stop-Job

Get-Job -Name LabelPrintingService | Receive-Job

}

Invoke-Build

Run-ServiceTests

With these few lines of code I am able to validate the service’s health after every commit, and notably running these set of tests as part of a pull-request build before being merged to the main line.

One example where I used such a build script is the xUnit2NUnit web service. The source code can be found on github, and a description in a separate blog post.

Automated build for ASP.NET vNext hangs

I had an automated build with ASP.NET vNext correctly working for a few weeks until it suddenly stopped working. It was hanging with the last output message at:

removing Process DNX_HOME

My powershell script started with something like the following:

&{$Branch='dev';iex ((new-object net.webclient).DownloadString('https://raw.githubusercontent.com/aspnet/Home/dev/dnvminstall.ps1'))}
dnvm list
dnvm install 1.0.0-beta7 -arch x64 -runtime clr

&{$Branch='dev';iex ((new-object net.webclient).DownloadString('https://raw.githubusercontent.com/aspnet/Home/dev/dnvminstall.ps1'))}

dnvm list

dnvm install 1.0.0-beta7 -arch x64 -runtime clr

Internet search pointed me to an issue on ASP.NET and a few other sources, but double-installation or spaces in usernames weren’t my problem.

Running this set of commands works very nice when an environment is installed, it downloads the dnvm scripts, it lists the currently installed environments, and eventually ensures the required environment gets installed if not already available.

My build server went through some auto-cleanup process and had therefore no environments installed. If that’s the case, dnvm list will start in interactive mode, asking the user “It looks like you don’t have any runtimes installed. Do you want us to install a runtime to get you started?“. That prompt didn’t show up in my automated build output (using Jenkins), so it was hard to troubleshoot, especially since I didn’t expect any interactive mode in the dnvm commands.

Once found, the solution was really simple by just removing dnvm list, or if that’s interesting information as part of the build script, to move it after dnvm install.