Use MiniProfiler with DevExpress XPO (ORM)

Question

I'm trying to setup my project so that MiniProfiler is able to profile XPO's SQL calls. This should have been a very simple endeavor, as MiniProfiler just wraps an ordinary connection but this simple approach doesn't work. Here's the code that should have worked:

protected void Button1_Click(object sender, EventArgs e) {
    var s = new UnitOfWork();
    IDbConnection conn = new ProfiledDbConnection(new SqlConnection(Global.ConnStr), MiniProfiler.Current);
    s.Connection = conn; 
    for (int i = 0; i < 200; i++) {
        var p = new Person(s) {
            Name = $"Name of {i}",
            Age = i,
        };
        if (i % 25 == 0)
            s.CommitChanges();
    }
    s.CommitChanges();
}

This code simply wraps a SqlConnection with a ProfiledDbConnection then sets the Session/UnitOfWork.Connectionproperty to this connection.

Everything compiles just fine but at runtime the following exception gets thrown:

DevExpress.Xpo.Exceptions.CannotFindAppropriateConnectionProviderException
  HResult=0x80131500
  Message=Invalid connection string specified: 'ProfiledDbConnection(Data Source=.\SQLEXPRESS;Initial Catalog=sample;Persist Security Info=True;Integrated Security=SSPI;)'.
  Source=<Cannot evaluate the exception source>
  StackTrace:
   em DevExpress.Xpo.XpoDefault.GetConnectionProvider(IDbConnection connection, AutoCreateOption autoCreateOption)
   em DevExpress.Xpo.XpoDefault.GetDataLayer(IDbConnection connection, XPDictionary dictionary, AutoCreateOption autoCreateOption, IDisposable[]& objectsToDisposeOnDisconnect)
   em DevExpress.Xpo.Session.ConnectOldStyle()
   em DevExpress.Xpo.Session.Connect()
   em DevExpress.Xpo.Session.get_Dictionary()
   em DevExpress.Xpo.Session.GetClassInfo(Type classType)
   em DevExpress.Xpo.XPObject..ctor(Session session)
   em WebApplication1.Person..ctor(Session s) na C:\Users\USER\source\repos\WebApplication2\WebApplication1\Person.cs:linha 11
   em WebApplication1._Default.Button1_Click(Object sender, EventArgs e) na C:\Users\USER\source\repos\WebApplication2\WebApplication1\Default.aspx.cs:linha 28
   em System.Web.UI.WebControls.Button.OnClick(EventArgs e)
   em System.Web.UI.WebControls.Button.RaisePostBackEvent(String eventArgument)
   em System.Web.UI.WebControls.Button.System.Web.UI.IPostBackEventHandler.RaisePostBackEvent(String eventArgument)
   em System.Web.UI.Page.RaisePostBackEvent(IPostBackEventHandler sourceControl, String eventArgument)
   em System.Web.UI.Page.RaisePostBackEvent(NameValueCollection postData)
   em System.Web.UI.Page.ProcessRequestMain(Boolean includeStagesBeforeAsyncPoint, Boolean includeStagesAfterAsyncPoint)

I was able to find this issue in DevExpress's Support Center: https://www.devexpress.com/Support/Center/Question/Details/Q495411/hooks-to-time-and-log-xpo-sql

But the answer is perfunctory and it just tells their customer to write a class implementing the IDataStore interface and refer to the DataStoreLoggersource code for an example... Since I don't have the sources as my subscription didn't include it I'm at a loss on how to implement this.

Answer 1

After 9 days I've come up with a low friction, albeit non-ideal solution, which consists of two new classes inheriting from SimpleDataLayerand ThreadSafeDataLayer:

ProfiledThreadSafeDataLayer.cs

using DevExpress.Xpo.DB;
using DevExpress.Xpo.Metadata;
using StackExchange.Profiling;
using System.Reflection;

namespace DevExpress.Xpo
{
    public class ProfiledThreadSafeDataLayer : ThreadSafeDataLayer
    {
        public MiniProfiler Profiler { get { return MiniProfiler.Current; } }

        public ProfiledThreadSafeDataLayer(XPDictionary dictionary, IDataStore provider, params Assembly[] persistentObjectsAssemblies) 
            : base(dictionary, provider, persistentObjectsAssemblies) { }

        public override ModificationResult ModifyData(params ModificationStatement[] dmlStatements) {
            if (Profiler != null) using (Profiler.CustomTiming("xpo", dmlStatements.ToSql(), nameof(ModifyData))) {
                return base.ModifyData(dmlStatements);
            }
            return base.ModifyData(dmlStatements);
        }

        public override SelectedData SelectData(params SelectStatement[] selects) {
            if (Profiler != null) using (Profiler.CustomTiming("xpo", selects.ToSql(), nameof(SelectData))) {
                return base.SelectData(selects);
            }
            return base.SelectData(selects);
        }
    }
}

ProfiledDataLayer.cs

using DevExpress.Xpo.DB;
using DevExpress.Xpo.Metadata;
using StackExchange.Profiling;

namespace DevExpress.Xpo
{
    public class ProfiledSimpleDataLayer : SimpleDataLayer
    {
        public MiniProfiler Profiler { get { return MiniProfiler.Current; } }

        public ProfiledSimpleDataLayer(IDataStore provider) : this(null, provider) { }

        public ProfiledSimpleDataLayer(XPDictionary dictionary, IDataStore provider) : base(dictionary, provider) { }

        public override ModificationResult ModifyData(params ModificationStatement[] dmlStatements) {
            if (Profiler != null) using (Profiler.CustomTiming("xpo", dmlStatements.ToSql(), nameof(ModifyData))) {
                return base.ModifyData(dmlStatements);
            }
            return base.ModifyData(dmlStatements);
        }

        public override SelectedData SelectData(params SelectStatement[] selects) {
            if (Profiler != null) using (Profiler.CustomTiming("xpo", selects.ToSql(), nameof(SelectData))) {
                return base.SelectData(selects);
            }
            return base.SelectData(selects);
        }
    }
}

And the .ToSql() extension methods:

using DevExpress.Xpo.DB;
using System.Data;
using System.Linq;

namespace DevExpress.Xpo
{
    public static class StatementsExtensions
    {
        public static string ToSql(this SelectStatement[] selects) => string.Join("\r\n", selects.Select(s => s.ToString()));
        public static string ToSql(this ModificationStatement[] dmls) => string.Join("\r\n", dmls.Select(s => s.ToString()));
    }
}

USAGE

One of the ways to use the data layers above is to setup the XpoDefault.DataLayerproperty when setting up XPO for your application:

XpoDefault.Session = null;
XPDictionary dict = new ReflectionDictionary();
IDataStore store = XpoDefault.GetConnectionProvider(connectionString, AutoCreateOption.SchemaAlreadyExists);
dict.GetDataStoreSchema(typeof(Some.Class).Assembly, typeof(Another.Class).Assembly);
// It's here that we setup the profiled data layer
IDataLayer dl = new ProfiledThreadSafeDataLayer(dict, store); // or ProfiledSimpleDataLayer if not an ASP.NET app
XpoDefault.DataLayer = dl; 

RESULTS

Now you can view (some of - more on that later) XPO's database queries neatly categorized inside MiniProfiler's UI:

With the added benefit of detecting duplicate calls as follows :-) :

---

FINAL THOUGHTS

I've been digging around this for 9 days now. I've studied XPO's decompiled code with Telerik's JustDecompile and tried way too many different approaches to feed profiling data from XPO into MiniProfiler with as minimum friction as possible. I've tried to create a XPO Connection Provider, inheriting from XPO's MSSqlConnectionProvider and override the method it uses to execute queries but gave up since that method is not virtual (in fact it's private) and I would have to replicate the entire source code for that class which depends on many other source files from DevExpress. Then I've tried writing a Xpo.Session descendant to override all it's data manipulating methods, deferring the call to the base Session class method surrounded by a MiniProfiler.CustomTiming call. To my surprise none of those calls were virtual (the UnitOfWork class, which inherits from Session, seems more of a hack than a proper descendant class) so I ended up with the same problem I had with the connection provider approach. I've then tried hooking into other parts of the framework, even it's own tracing mechanism. This was fruitful, resulting in two neat classes: XpoNLogLogger and XpoConsoleLogger, but ultimately didn't allowed me to show results inside MiniProfiler since it provided already profiled and timed results which I found no way to include/insert into a MiniProfiler step/custom timing.

The Data Layer descendants solution shown above solves only part of the problem. For one it doesn't log direct SQL calls, stored procedure calls, and no Session methods, which can be expensive (after all it doesn't even log the hydrating of objects retrieved from the database). XPO implements two (maybe three) distinct tracing mechanisms. One logs SQL statements and results (rowcount, timings, parameters, etc.) using standard .NET tracing and the other log session methods and SQL statements (without results) using DevExpress' LogManager class. The LogManager is the only method that is not considered obsolete. The third method which is to mimic the DataStoreLogger class suffers from the same limitations of our own approach.

Ideally we should be able to just provide a ProfiledDbConnection to any XPO Sessionobject to get all of MiniProfiler's SQL profiling capabilities.

I'm still researching a way to wrap or to inherit some of XPO's framework classes to provide a more complete/better profiling experience with MiniProfiler for XPO based projects. I'll update this case if I find anything useful.

XPO LOGGING CLASSES

While researching this I've created two very useful classes:

XpoNLogLogger.cs

using DevExpress.Xpo.Logger;
using NLog;
using System;

namespace Simpax.Xpo.Loggers
{
    public class XpoNLogLogger: DevExpress.Xpo.Logger.ILogger
    {
        static Logger logger = NLog.LogManager.GetLogger("xpo");

        public int Count => int.MaxValue;

        public int LostMessageCount => 0;

        public virtual bool IsServerActive => true;

        public virtual bool Enabled { get; set; } = true;

        public int Capacity => int.MaxValue;

        public void ClearLog() { }

        public virtual void Log(LogMessage message) {
            logger.Debug(message.ToString());
        }

        public virtual void Log(LogMessage[] messages) {
            if (!logger.IsDebugEnabled) return;
            foreach (var m in messages)
                Log(m);
        }
    }
}

XpoConsoleLogger.cs

using DevExpress.Xpo.Logger;
using System;

namespace Simpax.Xpo.Loggers
{
    public class XpoConsoleLogger : DevExpress.Xpo.Logger.ILogger
    {
        public int Count => int.MaxValue;

        public int LostMessageCount => 0;

        public virtual bool IsServerActive => true;

        public virtual bool Enabled { get; set; } = true;

        public int Capacity => int.MaxValue;

        public void ClearLog() { }

        public virtual void Log(LogMessage message) => Console.WriteLine(message.ToString());

        public virtual void Log(LogMessage[] messages) {
            foreach (var m in messages)
                Log(m);
        }
    }
}

To use these classes just set XPO's LogManager.Transport as follows:

DevExpress.Xpo.Logger.LogManager.SetTransport(new XpoNLogLogger(), "SQL;Session;DataCache");