Tuesday, June 18, 2013

OWIN with static files, exception handling and logging

As I wrote already in Self-host ASP.NET Web API and SignalR together, the OWIN configuration is done in Startup.Configuration():
public void Configuration(IAppBuilder app)
{
  // Configure WebApi
  var config = new HttpConfiguration();
  config.Routes.MapHttpRoute("API Default", "api/{controller}/{id}", new { id = RouteParameter.Optional });
  app.UseWebApi(config);

  // Configure SignalR
  app.MapHubs();
}
It looks, as if there are some features get activated with app.UseXXX() (or app.MapHubs(), respectively). But this is not completely true. When we look into the implementation of these "feature activating methods", they finally call
public IAppBuilder Use(object middleware, params object[] args)
{
  this._middleware.Add(AppBuilder.ToMiddlewareFactory(middleware, args));
  return (IAppBuilder) this;
}
This method adds the features to a list. During the request processing, every feature in this list will be checked, if it can handle the request. Therefore the order of the "feature activating methods" can be important. Not in the example above, since WebApi and SignalR do not compete for the same requests.

Microsoft.Owin.Diagnostics

The package Microsoft.Owin.Diagnostics contains one useful feature catching and displaying exceptions. For sure this shouldn't happen, but when it would be nice to know about. But as always you should consider to use it only during development.

To switch it on, simply add the following line at the beginning of Startup.Configuration():
app.UseShowExceptions(); 

Another feature in Microsoft.Owin.Diagnostics is
app.UseTestPage(); 
This displays the message Welcome to Katana to the client. You should place it at the very end of Configuration.Startup(). Otherwise your other features wouldn't never reached.

But anyway, this feature is useful only in hello world status. Later I would prefer to get HTTP 404 instead of this message.

Microsoft.Owin.StaticFiles

Like most of the other OWIN packages, also Microsoft.Owin.StaticFiles is in prerelease status. But this package is special, you even cannot find it in NuGet. To install it, you need to enter the following command in the Package Manager Console:
Install-Package Microsoft.Owin.StaticFiles -Version 0.20-alpha-20220-88 -Pre 
But probably the package is hidden since it doesn't work really. It has problems when you request more than one file in parallel. The solution is to use one of the nightly Katana builds (e.g. 0.24.0-pre-20624-416). Probably this is even more alpha than the hidden version. But is works better. Obviously there was some improvement between version 0.20 and 0.24.
You can get the nightly builds from a separate feed: http://www.myget.org/f/Katana.
After adding the package, just add one line to Startup.Configuration():
app.UseStaticFiles("StaticFiles");
The parameter specifies, in which directory the static files will be searched. Since I named it StaticFiles, you have to add a folder with this name to your project. And for every file you add to this folder you have to set in its properties that it will be copied to the output directory:

When you start the project, you can fire up the browser and enter http://localhost:8080/test.htm (without specifying the StaticFiles folder), and you get simply the page back.

Logging OWIN requests

Sometimes it would be interesting to see the incoming requests in a trace. This can be achieved with a custom feature. The constructor is quite simple. It just stores the reference to the next feature:
private readonly Func<IDictionary<string, object>, Task> _next; 

public Logger(Func<IDictionary<string, object>, Task> next)
{
  if (next == null)
    throw new ArgumentNullException("next");
  _next = next;
}
The implementation isn't really complicated, too:
public Task Invoke(IDictionary<string, object> environment)
{
  string method = GetValueFromEnvironment(environment, OwinConstants.RequestMethod);
  string path = GetValueFromEnvironment(environment, OwinConstants.RequestPath);

  Console.WriteLine("Entry\t{0}\t{1}", method, path);

  Stopwatch stopWatch = Stopwatch.StartNew();
  return _next(environment).ContinueWith(t =>
  {
    Console.WriteLine("Exit\t{0}\t{1}\t{2}\t{3}\t{4}", method, path, stopWatch.ElapsedMilliseconds,
      GetValueFromEnvironment(environment, OwinConstants.ResponseStatusCode), 
      GetValueFromEnvironment(environment, OwinConstants.ResponseReasonPhrase));
    return t;
  });
}
First, it prints some data of the current request. The more interesting part is, that it then calls the succeeding features (return _next(environment)). And when the succeeding features were evaluated, it finally (ContinueWith) prints some response data. I added here also method and path, since otherwise it were difficult to find the corresponding entries. Maybe it would be even better to use some kind of unique id for this purpose. But in my projects, method and path are enough.
GetValueFromEnvironment is only a little helper, since in some cases the environment dictionary does not contains all values:
private static string GetValueFromEnvironment(IDictionary<string, object> environment, string key)
{
  object value;
  environment.TryGetValue(key, out value);
  return Convert.ToString(value, CultureInfo.InvariantCulture);
}
Since the Logger traces the beginning and the end of the processing, it should be activated quite at the beginning of Startup.Configuration():
app.Use(typeof(Logger));

Logging the Request Body

With POST requests, it can be very handy to log also the request body. For this, you have only to extend the Invoke method a little bit:
string requestBody;
Stream stream = (Stream)environment[OwinConstants.RequestBody];
using (StreamReader sr = new StreamReader(stream))
{
  requestBody = sr.ReadToEnd();
}
environment[OwinConstants.RequestBody] = new MemoryStream(Encoding.UTF8.GetBytes(requestBody));
The access to the request body is provided by a Stream. The only caveat with this stream is that it is not seekable. That means you can read it only once. And maybe the simple logging will not be enough for your requirements. Sometimes you will also process it afterwards...
Fortunately, this is no big issue: just replace the old stream with a new MemoryStream. For sure, this is not good idea with big request bodies. In such a case you will need a more sophisticated solution. But normally, it should be good enough. Moreover, you can use it only during development. In production you can disable it by configuration, par example.

Logging SignalR

With the Logger from above, you get a nice logging of the several SignalR requests (when it uses LongPolling instead of WebSockets):
10:51:18,181     11     Entry     GET     /signalr/negotiate
10:51:18,263     8      Exit      GET     /signalr/negotiate     82              
10:51:18,271     11     Entry     GET     /signalr/ping
10:51:18,275     8      Exit      GET     /signalr/ping          4               
10:51:18,540     11     Entry     GET     /signalr/connect
10:53:08,806     14     Exit      GET     /signalr/connect       110260          
10:53:08,826     11     Entry     GET     /signalr/poll
10:54:58,960     15     Exit      GET     /signalr/poll          110128          
10:54:58,969     11     Entry     GET     /signalr/poll
10:56:49,136     12     Exit      GET     /signalr/poll          110161          
The used Logger prints also timestamp and thread id (in the first 2 columns). It is easily to see, how SignalR waits for 110 seconds for an answer from the server (a notification). When it doesn't get one, it simply sends the next request.
You can also see that all requests (at least in this example) are handled by the same thread (11). But the response is created by other threads (8, 14, 15 and 12).

Summary

It is quite easy to add additional features to an OWIN host. And it is also not too hard to implement own features. Drawbacks of the whole stuff are (hopefully only at the moment):
  • the beta status of some packages
  • the lack of documentation
But for a real developer, the best documentation is the code, anyway.

You can find the source code at GitHub: https://github.com/Ritzlgrmft/OwinConfiguration.

2 comments:

  1. Thanks for the blog post! I found it while looking into this Tackoverflow problem. Unfortunately, the static file handling seems to be pretty buggy.

    ReplyDelete
    Replies
    1. In my project, I had no problems with StaticFiles after the upgrade to the version from the Katana Nightly Builds. Before that, it didn't really work.

      What I miss is the documentation. And I couldn't find something to configure the caching of some files. But I hope it will be released this autumn together with Visual Studio 2013.

      Delete