Recent posts about LINQ and related topics - Page 1 by ThinqLinq

Custom Logging with Entity Framework EF6

Coming from LINQ to SQL, I’ve long been a fan of its logging simplicity where you just set the context.log to a stream (console.out) to see the stream of sql statements being issued to the database. Prior to EF6, this has been a rather frustrating omission that has finally been rectified with EF 6. Now, you can log SQL statements just as simply, but with a slightly different implementation. In EF, you set the DbContext’s Database.Log property to an Action delegate that takes a string as input parameter. Thus to log requests to the Diagnostics Trace implementation, you simply set the following:

context.Database.Log = Sub(val) Diagnostics.Trace.WriteLine(val)

This is fine as long as you are willing to accept the default logging implementation. If you want to customize the log output, things get a bit trickier. In my example, I only want to log the calling method and elapsed time that the query took to execute. I’m not as concerned in my current need for the SQL string, but that is easily included as I’ll point out below.

To start, I need to set the calling method from my code that I’ll be able to access in the logging implementation. Since the calling code is actually in ASP.Net Web API calls returning IQueryables, and the database is not being executed until long after my application code has completed. I need to explicitly identify the application calling method rather than the last method from the call stack which would otherwise be one of the Web API internal methods. To handle this and centralize my set-up logic for the context, I’ll create a factory method which configures the context and use that instead of relying on the context’s constructor. Thanks to partial classes, I can extend the generated entity class and include this new property and factory constructor. To make matters even easier, I’ll take advantage of the CallerMemberName attribute to automatically pull the member name from the method that is calling the factory.

Public Class NorthwindEfEntities

    Public Shared Function ContextFactory(<CallerMemberName> Optional memberName As String = "") As NorthwindEfEntities
        Dim context = New NorthwindEfEntities()
        context.CallingMethod = memberName
        context.Database.Log = Sub(val) Diagnostics.Trace.WriteLine(val)
        Return context
    End Function

    Public Property CallingMethod As String

End Class

Now, to create the context we call this new ContextFactory method, but don’t pass the memberName explicitly. The compiler will add that for us automatically.

    Public Function GetCustomers() As IQueryable(Of DTO.DtoCustomer)
        cn = NorhwindEfEntities.ContextFactory
        ' Do some amazing query and return it.
   End Function

Now that we’ve set up the logger, we need to customize the output that is generated. To do this, we need to add a new class that derives from DatabaseLogFormatter (in the System.Data.Entity.Infrastructure.Interception namespace). If you don’t have this namespace, you may need to upgrade to EF6 on order to access the logging functionality. Since the base class doesn’t have a default parameterless constructor, we need to make a new one and simply delegate to the base implementation. With that out of the way, we can supply our own logging. The base implementation gives us hooks to the following interception points.

Method Description
LogCommand Writes the SQL Statement to the action implementation prior to executing the statement
LogResult Writes when the SQL statement has completed
LogParameter Writes the parameter(s) used in the query
Executing/Executed Called before and after the database request is made
NonQueryExecuting/NonQueryExecuted Called for queries that don’t return results (insert/update/delete and non-result return stored procedures)
ReaderExecuting/ReaderExecuted Called for queries that return tabular data results (select)
ScalarExecuting/ScalarExecuted Called for queries that return single value results (user defined functions)
Write Base write implementation that each of the loggers use to format the output.

As stated before in our example, we want to write a log entry when the command completes including the calling method name and execution time. To do this we need to perform the following adjustments to the base implementation: 1) suppress logging the SQL statements in the LogCommand method by simply creating a noop and not delegating to the base implementation, and 2) replace the default result log information with our custom output in the LogResult method. To get the elapsed time, we directly leverage the Stopwatch property of the base class. Here then is our new custom formatter.

Imports System.Data.Entity.Infrastructure.Interception
Imports System.Data.Entity

Public Class CustomDbLogFormatter
    Inherits DatabaseLogFormatter

    Public Sub New(context As DbContext, writeAction As Action(Of String))
        MyBase.New(context, writeAction)
    End Sub

    Public Overrides Sub LogCommand(Of TResult)(command As Common.DbCommand, interceptionContext As DbCommandInterceptionContext(Of TResult))
        'MyBase.LogCommand(Of TResult)(command, interceptionContext)
    End Sub

    Public Overrides Sub LogResult(Of TResult)(command As Common.DbCommand, interceptionContext As DbCommandInterceptionContext(Of TResult))

        Dim context = interceptionContext.DbContexts.OfType(Of NorthwindEfEntities).FirstOrDefault()
        If context IsNot Nothing Then
            Trace.WriteLine(context.CallingMethod + " Completed in " + Stopwatch.ElapsedMilliseconds.ToString)
        End If
   
    End Sub
End Class

One step remains in order for this new logging implementation to take effect. We need to register the custom logger in our solution. To do this manually in code, we create a new class and derive from DbConfiguration. Then in the constructor, call the base class’s SetDatabaseLogFormatter to set the formatter to our new CustomDbLogFormatter. For more information on configuring the logging via your config file rather than in code, see AJ Vicker’s post today on EF 6.1 turning on SQL logging without recompiling your app.

Public Class LogConfiguration
    Inherits DbConfiguration

    Public Sub New()
        SetDatabaseLogFormatter(Function(context, action) New CustomDbLogFormatter(context, action))
    End Sub
End Class

Naturally, the value that we are outputting is just an example, you’re free to make your logging as complex as you want given these basic building blocks. For more details, make sure to read the EF team’s posts on the logging implementation.

Posted on - Comment
Categories: Entity Framework - VB Dev Center -

Logging ASP.Net WebApi elapsed time for IQueryables

I’ve recently been doing a fair amount of work with exposing queryable structures using ASP.Net Web API. In a nutshell, Web API allows you to expose not only the data from a service request, but also the query structure that can be extended. By default, the Web API scaffolding generates Get(id), Get, Post, Put and Delete methods. Of these, the most interesting, from a query perspective, is the Get method that returns a list of values:

    Public Function GetCustomers() As IEnumerable(Of Customer)
        Dim query = cn.Customers
        Return query
    End Function

By returning the default IEnumerable, the database will return everything that matches the service query definition and the consuming application isn’t able to customize this view to meet their needs. If you apply a couple changes, you can enable much greater service flexibility and allow customers to access your resources the way they want rather than just the way you originally intended. Of course with great power comes great responsibility. To make our GetCustomers method queryable, we simply change the output type from IEnumerable to IQueryable.

    Public Function GetCustomers() As IQueryable(Of Customer)
        Dim query = cn.Customers
        Return query
    End Function

In addition, we need to enable the query support for Web API in the Web Api Config’s Register method in the App_Start folder:

Public Module WebApiConfig
    Public Sub Register(ByVal config As HttpConfiguration)
        ' Web API configuration and services

        ' Web API routes
        config.MapHttpAttributeRoutes()

        config.Routes.MapHttpRoute(
            name:="DefaultApi",
            routeTemplate:="api/{controller}/{id}",
            defaults:=New With {.id = RouteParameter.Optional}
        )
        config.EnableQuerySupport()
        
    End Sub
End Module

Now, if we run the service, we can not only get the full list of Customers, but also add querying options like filter (where), orderby, top, skip, etc. For example, the following query gets the first two customers from London ordered by the Company Name. For a complete list of the various url query options, refer to the OData Query Specification URI Convention page.

http://localhost:17413/api/Customer?$filter=City%20eq%20'London'&$orderby=CompanyName&$top=2

Now, how does this fit with the question of logging the requests? If we were to use a traditional logging mechanism, we could just wrap the beginning and end of the service request with a timer and output the difference.

    Public Function GetCustomers() As IQueryable(Of DTO.DtoCustomer)
        Dim sw = New Stopwatch
        sw.Start()

        Dim query = cn.Customers
        sw.Stop()
        System.Diagnostics.Trace.WriteLine("GetCustomers completed in " + sw.ElapsedMilliseconds.ToString)

        Return query
    End Function

This outputs the result: “GetCustomers completed in 1”. Why is the time to execute so short? Remember that with LINQ, the database request is deferred until the results are iterated over (GetEnumerator). In the case of an IQueryable with WebAPI, the query isn’t executed until after our code has returned the base query and WebAPI has had a chance to add on any query parameters that the user supplied. We no longer have access to the query pipeline to hook into, right?

Adding tracing

Not exactly, Mike Wasson pointed out that there is a TraceWriter implementation that you can leverage and extend to hook into the Web API pipeline. For more information, see his article on Tracing in ASP.Net Web API.

In our example, we can output all of the tracing messages as follows. One thing to watch here is that the Kind and Operation are not set until the traceAction is executed, thus you need to execute the action prior to logging the details.

Imports System.Web.Http.Tracing Imports System.Diagnostics Public Class ServiceTracer Implements ITraceWriter Public Sub Trace(request As Net.Http.HttpRequestMessage,
category As String,
level As System.Web.Http.Tracing.TraceLevel,
traceAction As Action(Of TraceRecord)) Implements ITraceWriter.Trace

Dim rec = New TraceRecord(request, category, level) traceAction(rec) System.Diagnostics.Trace.WriteLine(String.Format("{0} - {1} {2} - {3}", category, level, rec.Kind, rec.Operation)) End Sub End Class

We then need to register this implementation with the WebAPI configuration (again in WebApiConfig):

Public Module WebApiConfig
    Public Sub Register(ByVal config As HttpConfiguration)
        ' Web API configuration and services

        ' Web API routes
        config.MapHttpAttributeRoutes()

        config.Routes.MapHttpRoute(
            name:="DefaultApi",
            routeTemplate:="api/{controller}/{id}",
            defaults:=New With {.id = RouteParameter.Optional}
        )
        config.EnableQuerySupport()
        config.Services.Replace(GetType(ITraceWriter), New ServiceTracer)

    End Sub
End Module

If we run our solution again and access our service, we should see the following in the output window:

System.Web.Http.Request - Info  Begin - 
System.Web.Http.Controllers - Info  Begin - SelectController
System.Web.Http.Controllers - Info  End - SelectController
System.Web.Http.Controllers - Info  Begin - CreateController
System.Web.Http.Controllers - Info  Begin - Create
System.Web.Http.Controllers - Info  End - Create
System.Web.Http.Controllers - Info  End - CreateController
System.Web.Http.Controllers - Info  Begin - ExecuteAsync
System.Web.Http.Action - Info  Begin - SelectAction
System.Web.Http.Action - Info  End - SelectAction
System.Web.Http.ModelBinding - Info  Begin - ExecuteBindingAsync
System.Web.Http.ModelBinding - Info  End - ExecuteBindingAsync
System.Web.Http.Filters - Info  Begin - OnActionExecutingAsync
System.Web.Http.Filters - Info  End - OnActionExecutingAsync
System.Web.Http.Action - Info  Begin - InvokeActionAsync
System.Web.Http.Action - Info  Begin - ExecuteAsync
System.Web.Http.Action - Info  End - ExecuteAsync
System.Net.Http.Formatting - Info  Begin - Negotiate
System.Net.Http.Formatting - Info  Begin - GetPerRequestFormatterInstance
System.Net.Http.Formatting - Info  End - GetPerRequestFormatterInstance
System.Net.Http.Formatting - Info  End - Negotiate
System.Web.Http.Action - Info  End - InvokeActionAsync
System.Web.Http.Filters - Info  Begin - OnActionExecutedAsync
System.Web.Http.Filters - Info  End - OnActionExecutedAsync
System.Web.Http.Controllers - Info  End - ExecuteAsync
System.Web.Http.Request - Info  End - 
System.Net.Http.Formatting - Info  Begin - WriteToStreamAsync
System.Net.Http.Formatting - Info  End - WriteToStreamAsync
System.Web.Http.Controllers - Info  Begin - Dispose
System.Web.Http.Controllers - Info  End - Dispose

Boy, that’s a lot of information, but not quite what we want. If you scan through this list, you can see that WebAPI essentially gives us hooks before and after each operation that it does, including selecting the controller from the request URI, serializing any input/body parameters, executing the service, getting the output formatter, formatting the output, and writing the response. In our case, all we want is to log which method was called and how long it took to execute. Instead of wrapping a stopwatch around the beginning and end of our query definition as we did before, we need to find the time difference between the beginning and end of the service request. Given the trace list above, we can see that we can catch the begin SelectAction operation and the corresponding End Dispose operation and log that.

For the solution, we need to set-up a list of TraceRecord objects that we can use to correlate the start and end operations. We’ll use a private items variable to track the start requests. In the write trace method, we can check the Kind and Operation to add the record for the Begin of the SelectAction operation. We also check for the End Dispose operation to write the timings. In the end method, we need to find the item based on the supplied RequestId. (Remember, WebAPI may have multiple service requests executing simultaneously with a single trace writer instance, so you have to take care to get the correct start and end.) The TraceRecord already has a convenient TimeStamp property which is set when the traceAction is executed.  We simply calculate the difference between the start and end timestamps to output the total execution time. After we output the log record, we make sure to remove the starting trace record from the items list to clean up after ourselves. Below is our revised implementation of the trace writer to log the total execution time for the request.

Public Class ServiceTracer Implements ITraceWriter Dim items As New List(Of TraceRecord) Public Sub Trace(request As Net.Http.HttpRequestMessage,
category As String,
level As System.Web.Http.Tracing.TraceLevel,
traceAction As Action(Of TraceRecord)) Implements ITraceWriter.Trace

Dim rec = New TraceRecord(request, category, level) traceAction(rec) WriteTrace(rec) End Sub Private Sub WriteTrace(rec As TraceRecord) If rec.Kind = TraceKind.Begin AndAlso rec.Operation = "SelectAction" Then items.Add(rec) End If If rec.Kind = TraceKind.End AndAlso rec.Operation = "Dispose" Then WriteServiceEnd(rec) End If End Sub Private Sub WriteServiceEnd(rec As TraceRecord) Dim start = items.Find(Function(r) r.RequestId = rec.RequestId) If rec.Request IsNot Nothing AndAlso start IsNot Nothing Then System.Diagnostics.Trace.WriteLine(String.Format("{0} - {1}: elapsedTime={2}", Now, rec.Request.RequestUri.PathAndQuery, (rec.Timestamp - start.Timestamp).TotalMilliseconds)) items.Remove(start) End If End Sub End Class

Posted on - Comment
Categories: Entity Framework -

Book Recommendations

I’m often asked to give book recommendations. While it’s been too long since I looked at beginner books, I have had some opportunity to benefit from some of the more intermediate-advanced books out there. When putting together the prizes for this year’s Atlanta Code Camp, we had the opportunity to hand pick books using some of the budget. I reflected a bit on the books that I’ve read and came up with the following list which should be a descent should read list for people interested in programming related topics. I’m sure that the list isn’t all inclusive and apologize to any of my author friends who may feel slighted by not being included here. I welcome you to add your favorites in the post comments if you see any glaring omissions. 

Without further ado, here’s my top recommended list:

General Programming Books
Design Patterns: Elements of Reusable Object-Oriented Software Design Patterns
by Erich Gamma
Also known as the Gang of Four (GOF) book, this is the book which defined a set of common code design patterns to give programmers a common language to understand and design object oriented programs.
Patterns of Enterprise Application Architecture
by Martin Fowler
Martin catalogs an extensive list of typical application architectures and how they fit together. Pair this with the GOF and you’ll be amazed how your applications can benefit from these patterns (and how often you used them without having a concrete name for them).
Test Driven Development: By Example Test Driven Development: By Example
by Kent Beck
If you’re not testing your code, it is invariably brittle for refactoring and subject to breaking as new enhancements are added. This book will get you up and running with TDD and show you why and how you should be doing it.
Clean Code: A Handbook of Agile Software Craftsmanship Clean Code: A Handbook of Agile Software Craftsmanship
by Robert C. Martin
From the man that brought us the SOLID Pricipals, Uncle Bob gives us this guide to building pride in the code you write resulting in more maintainable and understandable code.
Code Complete: A Practical Handbook of Software Construction, Second Edition Code Complete
by Steve McConnell
Steve includes examples from a number of programming languages along with case study results and metrics to help guide you toward building more quality code.
Refactoring: Improving the Design of Existing Code Refactoring: Improving the Design of Existing Code
by Martin Fowler
As the only author appearing twice on this list, Martin’s book offers excellent examples of how and when to improve an existing code base by refactoring it safely.  As a consultant, I’m typically brought in to work on an existing code base often in some state of disrepair (hence why I’m brought in). Unless you are careful when working on these code bases, you can risk breaking everything. Martin helps to show the right way to do it.
User Experience Books
Why Software Sucks...and What You Can Do About It Why Software Sucks...and What You Can Do About It
by David S. Platt
David uses humor and anecdotes to help developers understand why their applications are not as successful as they may have envisioned (hint: users don’t want to use your system, they want to HAVE used it).
About Face 3: The Essentials of Interaction Design About Face 3: The Essentials of Interaction Design
by Alan Cooper
Alan helped to pioneer the study of interaction design. While this book may be somewhat dated, many of the guiding principals he outlines are still pertinent to today’s applications.
Javascript Books
JavaScript: The Good Parts JavaScript: The Good Parts
by Douglas Crockford
Perhaps the most detailed discussion of the JavaScript language, Douglas points out the parts of JavaScript that you should, and perhaps more importantly should NOT use. A must read for anyone serious about JavaScript programming.
Secrets of the JavaScript Ninja Secrets of the JavaScript Ninja
by John Resig
From the person who brought us jQuery, John shares his experience along with valuable tricks and tips on how to improve your JavaScript programming.
jQuery in Action, Second Edition jQuery in Action, Second Edition
by Bear Bibeault
Good for people who know programming, and JavaScript, but haven’t dug into jQuery (beyond copying and pasting code from samples, forums, and documentation). In other words, this is good for anyone wanting to know and understand this essential JavaScript library.
.Net Books
C# in Depth, Second Edition C# in Depth, Second Edition
by Jon Skeet
Even though Jon doesn’t do C# at his day job at Google, he is one of the most knowledgeable people out there regarding the C# language as evidenced by the amount and quality of information in this book. No matter how long you’ve worked with C#, you will inevitably learn some helpful new tricks to improve your applications.
CLR via C#, Third Edition CLR via C#, Third Edition
by Jeffrey Richter
In working with the Microsoft product teams, Jeffrey definitely knows how .Net works under the covers and is able to share them in a understandable fashion. Each time you read through this book, you will find yourself picking up additional insights on how .Net works under the covers.
Effective C#  (Covers C# 4.0): 50 Specific Ways to Improve Your C# (2nd Edition) (Effective Software Development Series) Effective C# (Covers C# 4.0)
by Bill Wagner
While not digging under the covers of .Net as much, Bill’s practical examples show how to improve your C# code to accomplish many of the common tasks that you need to do.
Programming Entity Framework: Building Data Centric Apps with the ADO.NET Entity Framework Programming Entity Framework
by Julia Lerman
By far, this is THE book on the Entity Framework that you should read. This book only covers through version 4 of EF, but it will help you understand the fundamentals and helpful extensions to EF.
LINQ in Action LINQ in Action
by Fabrice Marguerie
I admit it, I am biased, but this is the best LINQ book out there.

 

If you would like to buy any of these directly from Amazon, I’ve set-up an associate account with the ability to buy any of these and any others I may add in the future. Head on over to Amazon and support these great authors. 

Posted on - Comment
Categories:

CodeLens for Visual Studio 2013 configuration

One of the new features of Visual Studio is the ability to automatically see statistics about your code while you are looking at it via a new feature called CodeLens. For example, you can see how many method calls are referencing your method, how many bugs and what tests are accessing the method.

image

While this information can be helpful when reviewing code, it sometimes gets in the way when writing it. For example, you can’t just click the 0 references line and start adding attributes and comments, you have to add them in a blank line above the CodeLens injected text (included as images here because you can’t copy and paste the CodeLens text).

image

If you don’t want the CodeLens information getting in the way, simply right click one of the tags and select CodeLens Options. Alternatively, in the Quick Launch window (Ctrl+Q), just type CodeLens to find the menu in config. From here, you can tweak which values are displayed inline with your code or disable CodeLens entirely to get it out of your way while writing code.

image

Posted on - Comment
Categories: C# - Visual Studio -

Rx for Windows Phone article now available

A couple of years ago I gave a presentation at the last MIX for doing asynchronous programming using Reactive Extensions (Rx) on the Windows Phone. The video of the presentation is still available for watching. Around the same time, I was approached by Code Magazine to write a similar article, which I was happy to oblige. It took a while but I was happy to see the article finally published in the Sep/Oct 2013 edition of Code Magazine.

In the article I demonstrate how to use Rx to build a dice rolling game (like Yhatzee) for the Windows Phone 7 or 8 and communicating with a service tier for rolling the dice (hiding the fact that you may be loading the results). While the particular solution was targeted to Windows Phone, the concepts are valid across the wide variety of platforms that Rx supports. Give the article a read and let me know what you thinq.

Posted on - Comment
Categories: C# - Rx - VB - WP7 -