ASP.NET MVC: ActionFilter zum Loggen benutzen

Die neue "pre"-Preview 3 des MVC Frameworks (siehe hier für mehr Informationen) bringt einige Veränderungen  mit sich. Insbesondere wurden die ActionFilter erweitert. Aus dem alten "FilterExecutingContext" etc. wurde der "ActionExcetuingContext" usw.
Es gibt zudem 2 neue Methoden zum Überschreiben, welche kurz vor dem Rendern passieren. Hier die komplette Liste an Methoden, welche ein ActionFilter haben kann:

        public override void OnActionExecuting(ActionExecutingContext filterContext)
        {
            ActionExecutingContext contect = filterContext;
            string test = contect.ActionMethod.ToString();
        }

        public override void OnActionExecuted(ActionExecutedContext filterContext)
        {
            ActionExecutedContext context = filterContext;
            string test = context.ActionMethod.ToString();
        }

        public override void OnResultExecuting(ResultExecutingContext filterContext)
        {
            ResultExecutingContext context = filterContext;
            string test = context.ToString();
        }


        public override void OnResultExecuted(ResultExecutedContext filterContext)
        {
            ResultExecutedContext context = filterContext;
            string test = context.ToString();
        }

Die großartigste Neuerung: Man kann nun von diesen ActionFiltern auf die ViewDaten zugreifen und zwar in den folgenden Contexten:

• ResultExecutedContext
• ResultExecutingContext
• ActionExecutedContext Yeah!
</ul>

 

Durch diesen Zugriff können wir uns auch einen cleveren Logger implementieren, welcher das über Log4Net abspeichert.

Um die ViewDaten rekursiv durchzugehen nutze ich diesen "DumpObject Code" und die Konfiguration wie hier.

Die (momentan) recht einfache Logging-Funktion in unserm LogFilter:

namespace Mvc2.Filters
{
    public class LogAttribute : ActionFilterAttribute
    {
        private static readonly ILog log = LogManager.GetLogger(typeof(LogAttribute).Name);

        public override void OnActionExecuted(ActionExecutedContext filterContext)
        {
            ActionExecutedContext context = filterContext;
            
            StringBuilder logMessage = new StringBuilder();
            logMessage.AppendLine(context.ActionMethod.Name);
            
            if(context.Result.GetType() == typeof(RenderViewResult))
            {
                RenderViewResult viewResult = context.Result as RenderViewResult;
                logMessage.AppendLine("ActionResult: RenderViewResult");
                logMessage.AppendLine();
                logMessage.AppendLine(Dumper.DumpObject(viewResult.ViewData, 5));
            }
            logMessage.AppendLine();
            log.Info(logMessage.ToString());
        }

    }
}

Dieses ActionFilter Attribut können wir jetzt einfach auf unseren Controller oder direkt auf die ActionMethods setzen:

[Log]
public class EntryController : Controller
{...}

Das Ergebnis in der log.txt:

2008-04-17 20:41:02,204 [10] INFO  LogAttribute [(null)] - List
ActionResult: RenderViewResult

[ObjectToDump] AS Mvc2.Views.Entry.ListViewData = Mvc2.Views.Entry.ListViewData
+<EntryList>k__BackingField AS Mvc2.Helpers.PagedList`1[[Mvc2.Models.DataObjects.Entry, Mvc2, Version=1.0.0.0, Culture=neutral, PublicKeyToken=null]] = Mvc2.Helpers.PagedList`1[Mvc2.Models.DataObjects.Entry]
|+<TotalPages>k__BackingField AS System.Int32 = 2
|+<TotalCount>k__BackingField AS System.Int32 = 17
|+<PageIndex>k__BackingField AS System.Int32 = 1
|+<PageSize>k__BackingField AS System.Int32 = 10
+(System.Collections.Generic.List`1[[Mvc2.Models.DataObjects.Entry, Mvc2, Version=1.0.0.0, Culture=neutral, PublicKeyToken=null]])
|+_items AS Mvc2.Models.DataObjects.Entry[] = Mvc2.Models.DataObjects.Entry[]
||+[0] AS Mvc2.Models.DataObjects.Entry = Mvc2.Models.DataObjects.Entry
|||+_Id AS System.Guid = 797c70f0-f571-4969-80e8-d4a085445b6d
|||+_Title AS System.String = test
|||+_Url AS System.String = test
|||+_UserId AS System.Guid = cf2e5ccc-bd32-405d-bd54-eda112ebe06c
|||+_Link AS System.String = http...
|||+_Description AS System.String = tealkjdlsakj
|||+_CategoryId AS System.Guid = 7bd8028e-02c1-45f4-a0a6-403f5bf0ff0c
|||+_Date AS System.DateTime = 17.04.2008 15:48:53
|||+_EntryTags AS System.Data.Linq.EntitySet`1[[Mvc2.Models.DataObjects.EntryTag, Mvc2, Version=1.0.0.0, Culture=neutral, PublicKeyToken=null]] = System.Data.Linq.EntitySet`1[Mvc2.Models.DataObjects.EntryTag]
|||+_Category AS System.Data.Linq.EntityRef`1[[Mvc2.Models.DataObjects.Category, Mvc2, Version=1.0.0.0, Culture=neutral, PublicKeyToken=null]] = System.Data.Linq.EntityRef`1[Mvc2.Models.DataObjects.Category]
|||+PropertyChanging AS System.ComponentModel.PropertyChangingEventHandler = System.ComponentModel.PropertyChangingEventHandler
|||+(System.MulticastDelegate)
|||+(System.Delegate)
||+[1] AS Mvc2.Models.DataObjects.Entry = Mvc2.Models.DataObjects.Entry
|||+_Id AS System.Guid = 8e1554c1-47fa-4db5-af41-91c3fcf92fb3
|||+_Title AS System.String = EntryTitle
|||+_Url AS System.String = EntryTitle_13
|||+_UserId AS System.Guid = cf2e5ccc-bd32-405d-bd54-eda112ebe06c
|||+_Link AS System.String = http://.../
|||+_Description AS System.String = Blabla
|||+_CategoryId AS System.Guid = 16d09b0a-2157-43b7-a881-b536e90f7fbf
...

Das ist jetzt noch nicht die perfekte Lösung - allerdings zeigt es, wohin es gehen kann und was man damit wunderbares anstellen kann.

Ich hoffe ich schaff es in den nächsten Tagen eine verbesserte Version zu erstellen - RouteData, Parameters etc. müssen ja auch alle geloggt werden - und diese Darstellung ist noch etwas "unpraktisch". Aber prinzipiell cool ;)