MiniProfiler.Console.cs

using System;
using System.Collections.Generic;
using System.Data.Entity;
using System.Data.Entity.ModelConfiguration.Conventions;
using System.Linq;
using StackExchange.Profiling;
using StackExchange.Profiling.EntityFramework6;

namespace EffortTest
{
    public static class Program
    {
        public static void Main()
        {
            try
            {
                MiniProfilerEF6.Initialize();
                MiniProfiler.Settings.ProfilerProvider = new SingletonProfilerProvider();
                var mp = MiniProfiler.Start();
                using (mp.Step("Run"))
                    Run();
                MiniProfiler.Stop();
                Console.WriteLine(MiniProfiler.Current.RenderPlainText());
                var y = GetSqlTimings(mp).ToLookup(x => x.CommandString).ToDictionary(x => x.Key, x => x.ToList());
                foreach (var commandString in y.Keys.OrderBy(x => y[x].Sum(t => t.DurationMilliseconds)))
                {
                    var count = y[commandString].Count;
                    if (count > 1)
                    {
                        Console.WriteLine("DUPLICATES");
                        var sum = y[commandString].Sum(t => t.DurationMilliseconds);
                        Console.WriteLine(new string('*', 40));
                        Console.WriteLine("{0}ms for {1} query duplicates\n{2}", sum, count, commandString);
                    }
                    else
                    {
                        Console.WriteLine("UNIQUE");
                        var sum = y[commandString].Sum(t => t.DurationMilliseconds);
                        Console.WriteLine(new string('*', 40));
                        Console.WriteLine("{0}ms\n{1}", sum, commandString);
                    }
                }
            }
            catch (Exception e)
            {
                Console.WriteLine(e);
            }
        }

        private static IEnumerable<CustomTiming> GetSqlTimings(MiniProfiler mp)
        {
            foreach (var timing in mp.GetTimingHierarchy())
            {
                if (timing.HasCustomTimings == false) continue;

                foreach (var customTiming in timing.CustomTimings["sql"])
                {
                    yield return customTiming;
                }
            }
        }

        private static void Run()
        {
            using (var context = new CommunicationSamplesContext(@"Data Source=hmorder-db-dev\hmorderdev;Initial Catalog=CommunicationSamples;Integrated Security=True"))
            {
                for (int i = 0; i < 20; i++)
                {
                    using (MiniProfiler.Current.Step("Department " + i))
                    {
                        var i1 = i;
                        var department = context.Departments.AsQueryable().OrderBy(x => x.DepartmentId).Skip(() => i1).FirstOrDefault();
                        if (department != null)
                        {
                            Console.WriteLine("Department {0}: {1}", i, department);
                        }
                        else
                        {
                            Console.WriteLine("Department {0} not found", i);
                        }
                    }
                }
            }
        }
    }

    public class CommunicationSamplesContext : DbContext
    {
        public CommunicationSamplesContext(string nameOrConnectionString)
            : base(nameOrConnectionString)
        {
            Database.SetInitializer<CommunicationSamplesContext>(null);
        }

        protected override void OnModelCreating(DbModelBuilder modelBuilder)
        {
            modelBuilder.Conventions.Remove<PluralizingTableNameConvention>();
        }

        public DbSet<Department> Departments { get; set; }
    }

    public class Department
    {
        public int DepartmentId { get; set; }

        public Guid ModelKey { get; set; }

        public override string ToString()
        {
            return string.Format("DepartmentId: {0}, ModelKey: {1}", DepartmentId, ModelKey);
        }
    }
}

QueryObserver.cs

// assumes MiniProfiler.DefaultOptions.SqlFormatter = new SqlFormatters.SqlServerFormatter()
public class QueryObserver : IQueryObserver, IDisposable
{
    private readonly MiniProfiler _profiler;
    private readonly ILogger _logger;
    private IDisposable? _scope;

    public QueryObserver(ILogger logger)
    {
        _profiler = MiniProfiler.StartNew("query-observer");
        _logger = logger;
    }

    public void BeginQuery(object query)
    {
        _scope = _profiler.Step(query.GetType().Name);
    }

    public void EndQuery(object? result, Exception? ex)
    {
        _scope?.Dispose();
    }

    public void Dispose()
    {
        (string logStatement, bool hasDuplicates) = BuildResult();
        if (hasDuplicates)
        {
            _logger.Warning(
                "miniprofiler result",
                LogBase.CreateKeyword("details", logStatement));
        }
        else
        {
            _logger.Information(
                "miniprofiler result",
                LogBase.CreateKeyword("details", logStatement));
        }
    }

    private record TimingResult(
        string CommandString,
        int Count,
        decimal TotalDurationsMilliseconds)
    {
        public bool IsDuplicated => Count > 1;
    };

    private LogResult BuildResult()
    {
        StringBuilder builder = new();
        bool hasDuplicates = false;
        string result = _profiler.RenderPlainText();
        _ = builder.AppendLine(result);

        CustomTiming[] timings = GetSqlTimings(_profiler).ToArray();
        ILookup<string, CustomTiming> commandStrings =
            timings.ToLookup(x => RemoveParameters(x.CommandString));
        Dictionary<string, TimingResult> y = timings
            .ToLookup(x => RemoveParameters(x.CommandString))
            .ToDictionary(
            x => x.Key,
            x => new TimingResult(
                x.Key,
                x.Count(),
                x.Sum(t => t.DurationMilliseconds.GetValueOrDefault())));
        foreach ((string commandString, TimingResult timingResult) in
            y.Where(x => x.Value.IsDuplicated)
            .OrderByDescending(x => x.Value.TotalDurationsMilliseconds))
        {
            hasDuplicates = true;
            _ = builder.AppendLine("DUPLICATE");
            _ = builder.AppendLine(new string('*', 40));
            _ = builder.AppendLine(
                $"{timingResult.TotalDurationsMilliseconds:N2}ms for {timingResult.Count} query duplicates");
            _ = builder.AppendLine($"{ timingResult.CommandString}");
            _ = builder.AppendLine("--> QUERY INSTANCES:");
            foreach (CustomTiming item in commandStrings[commandString])
            {
                _ = builder.AppendLine($"{item.DurationMilliseconds:N2}ms");
                _ = builder.AppendLine($"{item.CommandString}");
            }
        }

        foreach ((string commandString, TimingResult timingResult) in
            y.Where(x => x.Value.IsDuplicated == false)
            .OrderByDescending(x => x.Value.TotalDurationsMilliseconds))
        {
            _ = builder.AppendLine("UNIQUE");
            _ = builder.AppendLine(new string('*', 40));
            _ = builder.AppendLine($"{timingResult.TotalDurationsMilliseconds:N2}ms");
            _ = builder.AppendLine($"{timingResult.CommandString}");
        }

        return new(builder.ToString(), hasDuplicates);
    }

    private enum ParseState
    {
        Undef,
        BeginsWithDeclare,
        MovedPastDeclare
    }

    private string RemoveParameters(string commandString)
    {
        string[] lines = commandString.Split(
            new string[] { Environment.NewLine, "\n" }, StringSplitOptions.RemoveEmptyEntries);

        StringBuilder builder = new();
        ParseState parseState = ParseState.Undef;
        foreach (string line in lines)
        {
            switch (parseState)
            {
                case ParseState.BeginsWithDeclare:
                    {
                        if (line[0] != ' ')
                        {
                            parseState = ParseState.MovedPastDeclare;
                        }
                    }
                    break;

                case ParseState.Undef:
                    {
                        if (line.StartsWith("DECLARE"))
                        {
                            parseState = ParseState.BeginsWithDeclare;
                        }
                        else
                        {
                            parseState = ParseState.MovedPastDeclare;
                        }
                    }
                    break;

                case ParseState.MovedPastDeclare:
                    break;

                default:
                    break;
            }

            if (parseState == ParseState.MovedPastDeclare)
            {
                _ = builder.AppendLine(line);
            }
        }

        return builder.ToString();
    }

    private static IEnumerable<CustomTiming> GetSqlTimings(MiniProfiler mp)
    {
        foreach (Timing timing in mp.GetTimingHierarchy())
        {
            if (timing.HasCustomTimings == false) continue;

            foreach (CustomTiming customTiming in timing.CustomTimings["sql"])
            {
                yield return customTiming;
            }
        }
    }

    private record LogResult(string LogStatement, bool HasDuplicates);
}