Database Error Page: Remove ILogger-based interception.

- Made EF calls async
- Removed a slow, repeated DB existence check.
This commit is contained in:
Andrew Peters 2017-05-30 14:52:44 -07:00
parent 1b6993fb91
commit 2258eeae39
7 changed files with 140 additions and 186 deletions

View File

@ -1,98 +0,0 @@
// Copyright (c) .NET Foundation. All rights reserved.
// Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information.
using JetBrains.Annotations;
using Microsoft.EntityFrameworkCore;
using Microsoft.EntityFrameworkCore.Diagnostics;
using Microsoft.EntityFrameworkCore.Infrastructure;
using Microsoft.EntityFrameworkCore.Storage;
using Microsoft.Extensions.Logging;
using System;
using System.Collections.Generic;
using System.Linq;
using System.Threading;
namespace Microsoft.AspNetCore.Diagnostics.EntityFrameworkCore
{
public class DataStoreErrorLogger : ILogger
{
private static readonly AsyncLocal<DataStoreErrorLog> _log = new AsyncLocal<DataStoreErrorLog>();
public virtual DataStoreErrorLog LastError
{
get
{
return _log.Value;
}
}
public virtual void StartLoggingForCurrentCallContext()
{
// Because CallContext is cloned at each async operation we cannot
// lazily create the error object when an error is encountered, otherwise
// it will not be available to code outside of the current async context.
// We create it ahead of time so that any cloning just clones the reference
// to the object that will hold any errors.
_log.Value = new DataStoreErrorLog();
}
public virtual void Log<TState>(
LogLevel logLevel, EventId eventId, TState state, Exception exception, Func<TState, Exception, string> formatter)
{
if (exception != null
&& LastError != null
&& (eventId.Id == CoreEventId.SaveChangesFailed.Id
|| eventId.Id == CoreEventId.QueryIterationFailed.Id))
{
LastError.SetError(
(Type)((IReadOnlyList<KeyValuePair<string, object>>)state).Single(p => p.Key == "contextType").Value,
exception);
}
}
public virtual bool IsEnabled(LogLevel logLevel)
{
return true;
}
public virtual IDisposable BeginScope<TState>(TState state)
{
return NullScope.Instance;
}
private class NullScope : IDisposable
{
public static NullScope Instance = new NullScope();
public void Dispose()
{ }
}
public class DataStoreErrorLog
{
private Type _contextType;
private Exception _exception;
public virtual void SetError(Type contextType, Exception exception)
{
_contextType = contextType;
_exception = exception;
}
public virtual bool IsErrorLogged
{
get { return _exception != null; }
}
public virtual Type ContextType
{
get { return _contextType; }
}
public virtual Exception Exception
{
get { return _exception; }
}
}
}
}

View File

@ -1,27 +0,0 @@
// Copyright (c) .NET Foundation. All rights reserved.
// Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information.
using System;
using Microsoft.Extensions.Logging;
namespace Microsoft.AspNetCore.Diagnostics.EntityFrameworkCore
{
public class DataStoreErrorLoggerProvider : ILoggerProvider
{
private readonly DataStoreErrorLogger _logger = new DataStoreErrorLogger();
public virtual ILogger CreateLogger(string name)
{
return _logger;
}
public virtual DataStoreErrorLogger Logger
{
get { return _logger; }
}
public virtual void Dispose()
{
}
}
}

View File

@ -2,12 +2,16 @@
// Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information. // Licensed under the Apache License, Version 2.0. See License.txt in the project root for license information.
using System; using System;
using System.Collections.Generic;
using System.Diagnostics;
using System.Linq; using System.Linq;
using System.Threading;
using System.Threading.Tasks; using System.Threading.Tasks;
using Microsoft.AspNetCore.Builder; using Microsoft.AspNetCore.Builder;
using Microsoft.AspNetCore.Diagnostics.EntityFrameworkCore.Views; using Microsoft.AspNetCore.Diagnostics.EntityFrameworkCore.Views;
using Microsoft.AspNetCore.Http; using Microsoft.AspNetCore.Http;
using Microsoft.EntityFrameworkCore; using Microsoft.EntityFrameworkCore;
using Microsoft.EntityFrameworkCore.Diagnostics;
using Microsoft.EntityFrameworkCore.Infrastructure; using Microsoft.EntityFrameworkCore.Infrastructure;
using Microsoft.EntityFrameworkCore.Migrations; using Microsoft.EntityFrameworkCore.Migrations;
using Microsoft.EntityFrameworkCore.Storage; using Microsoft.EntityFrameworkCore.Storage;
@ -17,23 +21,36 @@ using Microsoft.Extensions.Options;
namespace Microsoft.AspNetCore.Diagnostics.EntityFrameworkCore namespace Microsoft.AspNetCore.Diagnostics.EntityFrameworkCore
{ {
/// <summary> /// <summary>
/// Captures synchronous and asynchronous database related exceptions from the pipeline that may be resolved using Entity Framework /// Captures synchronous and asynchronous database related exceptions from the pipeline that may be resolved using Entity Framework
/// migrations. When these exceptions occur an HTML response with details of possible actions to resolve the issue is generated. /// migrations. When these exceptions occur an HTML response with details of possible actions to resolve the issue is generated.
/// </summary> /// </summary>
public class DatabaseErrorPageMiddleware public class DatabaseErrorPageMiddleware : IObserver<DiagnosticListener>, IObserver<KeyValuePair<string, object>>
{ {
private static readonly AsyncLocal<DiagnosticHolder> _localDiagnostic = new AsyncLocal<DiagnosticHolder>();
private sealed class DiagnosticHolder
{
public void Hold(Exception exception, Type contextType)
{
Exception = exception;
ContextType = contextType;
}
public Exception Exception { get; private set; }
public Type ContextType { get; private set; }
}
private readonly RequestDelegate _next; private readonly RequestDelegate _next;
private readonly DatabaseErrorPageOptions _options; private readonly DatabaseErrorPageOptions _options;
private readonly ILogger _logger; private readonly ILogger _logger;
private readonly DataStoreErrorLoggerProvider _loggerProvider;
/// <summary> /// <summary>
/// Initializes a new instance of the <see cref="DatabaseErrorPageMiddleware"/> class /// Initializes a new instance of the <see cref="DatabaseErrorPageMiddleware" /> class
/// </summary> /// </summary>
/// <param name="next">Delegate to execute the next piece of middleware in the request pipeline.</param> /// <param name="next">Delegate to execute the next piece of middleware in the request pipeline.</param>
/// <param name="loggerFactory"> /// <param name="loggerFactory">
/// The <see cref="ILoggerFactory"/> for the application. This middleware both produces logging messages and /// The <see cref="ILoggerFactory" /> for the application. This middleware both produces logging messages and
/// consumes them to detect database related exception. /// consumes them to detect database related exception.
/// </param> /// </param>
/// <param name="options">The options to control what information is displayed on the error page.</param> /// <param name="options">The options to control what information is displayed on the error page.</param>
public DatabaseErrorPageMiddleware( public DatabaseErrorPageMiddleware(
@ -60,90 +77,84 @@ namespace Microsoft.AspNetCore.Diagnostics.EntityFrameworkCore
_options = options.Value; _options = options.Value;
_logger = loggerFactory.CreateLogger<DatabaseErrorPageMiddleware>(); _logger = loggerFactory.CreateLogger<DatabaseErrorPageMiddleware>();
_loggerProvider = new DataStoreErrorLoggerProvider(); DiagnosticListener.AllListeners.Subscribe(this);
#pragma warning disable CS0618 // Type or member is obsolete
loggerFactory.AddProvider(_loggerProvider);
#pragma warning restore CS0618 // Type or member is obsolete
} }
/// <summary> /// <summary>
/// Process an individual request. /// Process an individual request.
/// </summary> /// </summary>
/// <param name="context">The context for the current request.</param> /// <param name="httpContext">The HTTP context for the current request.</param>
/// <returns>A task that represents the asynchronous operation.</returns> /// <returns>A task that represents the asynchronous operation.</returns>
public virtual async Task Invoke(HttpContext context) public virtual async Task Invoke(HttpContext httpContext)
{ {
if (context == null) if (httpContext == null)
{ {
throw new ArgumentNullException(nameof(context)); throw new ArgumentNullException(nameof(httpContext));
} }
try try
{ {
_loggerProvider.Logger.StartLoggingForCurrentCallContext(); // Because CallContext is cloned at each async operation we cannot
// lazily create the error object when an error is encountered, otherwise
// it will not be available to code outside of the current async context.
// We create it ahead of time so that any cloning just clones the reference
// to the object that will hold any errors.
await _next(context); _localDiagnostic.Value = new DiagnosticHolder();
await _next(httpContext);
} }
catch (Exception ex) catch (Exception exception)
{ {
try try
{ {
if (ShouldDisplayErrorPage(_loggerProvider.Logger.LastError, ex, _logger)) if (ShouldDisplayErrorPage(exception))
{ {
var dbContextType = _loggerProvider.Logger.LastError.ContextType; var contextType = _localDiagnostic.Value.ContextType;
var dbContext = (DbContext) context.RequestServices.GetService(dbContextType); var context = (DbContext)httpContext.RequestServices.GetService(contextType);
if (dbContext == null) if (context == null)
{ {
_logger.LogError( _logger.LogError(Strings.FormatDatabaseErrorPageMiddleware_ContextNotRegistered(contextType.FullName));
Strings.FormatDatabaseErrorPageMiddleware_ContextNotRegistered(dbContextType.FullName));
} }
else else
{ {
var creator = dbContext.GetService<IDatabaseCreator>() as IRelationalDatabaseCreator; var relationalDatabaseCreator = context.GetService<IDatabaseCreator>() as IRelationalDatabaseCreator;
if (creator == null) if (relationalDatabaseCreator == null)
{ {
_logger.LogDebug(Strings.DatabaseErrorPage_NotRelationalDatabase); _logger.LogDebug(Strings.DatabaseErrorPage_NotRelationalDatabase);
} }
else else
{ {
var databaseExists = creator.Exists(); var databaseExists = await relationalDatabaseCreator.ExistsAsync();
var historyRepository = dbContext.GetService<IHistoryRepository>(); var migrationsAssembly = context.GetService<IMigrationsAssembly>();
var migrationsAssembly = dbContext.GetService<IMigrationsAssembly>(); var modelDiffer = context.GetService<IMigrationsModelDiffer>();
var modelDiffer = dbContext.GetService<IMigrationsModelDiffer>();
var appliedMigrations = historyRepository.GetAppliedMigrations();
var pendingMigrations
= (from m in migrationsAssembly.Migrations
where !appliedMigrations.Any(
r => string.Equals(r.MigrationId, m.Key,
StringComparison.OrdinalIgnoreCase))
select m.Key)
.ToList();
// HasDifferences will return true if there is no model snapshot, but if there is an existing database // HasDifferences will return true if there is no model snapshot, but if there is an existing database
// and no model snapshot then we don't want to show the error page since they are most likely targeting // and no model snapshot then we don't want to show the error page since they are most likely targeting
// and existing database and have just misconfigured their model // and existing database and have just misconfigured their model
var pendingModelChanges
= (migrationsAssembly.ModelSnapshot != null || !databaseExists)
&& modelDiffer.HasDifferences(migrationsAssembly.ModelSnapshot?.Model,
dbContext.Model);
if (!databaseExists && pendingMigrations.Any() var pendingModelChanges
|| pendingMigrations.Any() = (!databaseExists || migrationsAssembly.ModelSnapshot != null)
|| pendingModelChanges) && modelDiffer.HasDifferences(migrationsAssembly.ModelSnapshot?.Model, context.Model);
var pendingMigrations
= (databaseExists
? await context.Database.GetPendingMigrationsAsync()
: context.Database.GetMigrations())
.ToArray();
if (pendingModelChanges || pendingMigrations.Any())
{ {
var page = new DatabaseErrorPage var page = new DatabaseErrorPage
{ {
Model = new DatabaseErrorPageModel( Model = new DatabaseErrorPageModel(
dbContextType, ex, databaseExists, pendingModelChanges, pendingMigrations, contextType, exception, databaseExists, pendingModelChanges, pendingMigrations, _options)
_options)
}; };
await page.ExecuteAsync(context); await page.ExecuteAsync(httpContext);
return; return;
} }
@ -153,21 +164,26 @@ namespace Microsoft.AspNetCore.Diagnostics.EntityFrameworkCore
} }
catch (Exception e) catch (Exception e)
{ {
_logger.LogError(0, e, Strings.DatabaseErrorPageMiddleware_Exception); _logger.LogError(
eventId: 0,
exception: e,
message: Strings.DatabaseErrorPageMiddleware_Exception);
} }
throw; throw;
} }
} }
private static bool ShouldDisplayErrorPage(DataStoreErrorLogger.DataStoreErrorLog lastError, private bool ShouldDisplayErrorPage(Exception exception)
Exception exception, ILogger logger)
{ {
logger.LogDebug(Strings.FormatDatabaseErrorPage_AttemptingToMatchException(exception.GetType())); _logger.LogDebug(Strings.FormatDatabaseErrorPage_AttemptingToMatchException(exception.GetType()));
if (!lastError.IsErrorLogged) var lastRecordedException = _localDiagnostic.Value.Exception;
if (lastRecordedException == null)
{ {
logger.LogDebug(Strings.DatabaseErrorPage_NoRecordedException); _logger.LogDebug(Strings.DatabaseErrorPage_NoRecordedException);
return false; return false;
} }
@ -175,19 +191,62 @@ namespace Microsoft.AspNetCore.Diagnostics.EntityFrameworkCore
for (var e = exception; e != null && !match; e = e.InnerException) for (var e = exception; e != null && !match; e = e.InnerException)
{ {
match = lastError.Exception == e; match = lastRecordedException == e;
} }
if (!match) if (!match)
{ {
logger.LogDebug(Strings.DatabaseErrorPage_NoMatch); _logger.LogDebug(Strings.DatabaseErrorPage_NoMatch);
return false; return false;
} }
logger.LogDebug(Strings.DatabaseErrorPage_Matched); _logger.LogDebug(Strings.DatabaseErrorPage_Matched);
return true; return true;
} }
void IObserver<DiagnosticListener>.OnNext(DiagnosticListener diagnosticListener)
{
if (diagnosticListener.Name == DbLoggerCategory.Root)
{
diagnosticListener.Subscribe(this);
}
}
void IObserver<KeyValuePair<string, object>>.OnNext(KeyValuePair<string, object> keyValuePair)
{
switch (keyValuePair.Value)
{
case DbContextErrorEventData contextErrorEventData:
{
_localDiagnostic.Value.Hold(contextErrorEventData.Exception, contextErrorEventData.Context.GetType());
break;
}
case DbContextTypeErrorEventData contextTypeErrorEventData:
{
_localDiagnostic.Value.Hold(contextTypeErrorEventData.Exception, contextTypeErrorEventData.ContextType);
break;
}
}
}
void IObserver<DiagnosticListener>.OnCompleted()
{
}
void IObserver<DiagnosticListener>.OnError(Exception error)
{
}
void IObserver<KeyValuePair<string, object>>.OnCompleted()
{
}
void IObserver<KeyValuePair<string, object>>.OnError(Exception error)
{
}
} }
} }

View File

@ -4,6 +4,7 @@
using Microsoft.AspNetCore.Diagnostics.EntityFrameworkCore; using Microsoft.AspNetCore.Diagnostics.EntityFrameworkCore;
using Microsoft.AspNetCore.Http; using Microsoft.AspNetCore.Http;
// ReSharper disable once CheckNamespace
namespace Microsoft.AspNetCore.Builder namespace Microsoft.AspNetCore.Builder
{ {
/// <summary> /// <summary>

View File

@ -5,6 +5,7 @@ using System;
using Microsoft.AspNetCore.Diagnostics.EntityFrameworkCore; using Microsoft.AspNetCore.Diagnostics.EntityFrameworkCore;
using Microsoft.Extensions.Options; using Microsoft.Extensions.Options;
// ReSharper disable once CheckNamespace
namespace Microsoft.AspNetCore.Builder namespace Microsoft.AspNetCore.Builder
{ {
/// <summary> /// <summary>

View File

@ -4,6 +4,7 @@
using Microsoft.AspNetCore.Diagnostics.EntityFrameworkCore; using Microsoft.AspNetCore.Diagnostics.EntityFrameworkCore;
using Microsoft.AspNetCore.Http; using Microsoft.AspNetCore.Http;
// ReSharper disable once CheckNamespace
namespace Microsoft.AspNetCore.Builder namespace Microsoft.AspNetCore.Builder
{ {
/// <summary> /// <summary>

View File

@ -16,5 +16,22 @@
"TypeId": "public class Microsoft.AspNetCore.Diagnostics.EntityFrameworkCore.DatabaseErrorPageMiddleware", "TypeId": "public class Microsoft.AspNetCore.Diagnostics.EntityFrameworkCore.DatabaseErrorPageMiddleware",
"MemberId": "public .ctor(Microsoft.AspNetCore.Http.RequestDelegate next, System.IServiceProvider serviceProvider, Microsoft.Extensions.Logging.ILoggerFactory loggerFactory, Microsoft.Extensions.Options.IOptions<Microsoft.AspNetCore.Builder.DatabaseErrorPageOptions> options)", "MemberId": "public .ctor(Microsoft.AspNetCore.Http.RequestDelegate next, System.IServiceProvider serviceProvider, Microsoft.Extensions.Logging.ILoggerFactory loggerFactory, Microsoft.Extensions.Options.IOptions<Microsoft.AspNetCore.Builder.DatabaseErrorPageOptions> options)",
"Kind": "Removal" "Kind": "Removal"
},
{
"TypeId": "public class Microsoft.AspNetCore.Diagnostics.EntityFrameworkCore.DataStoreErrorLogger : Microsoft.Extensions.Logging.ILogger",
"Kind": "Removal"
},
{
"TypeId": "public class Microsoft.AspNetCore.Diagnostics.EntityFrameworkCore.DataStoreErrorLogger+DataStoreErrorLog",
"Kind": "Removal"
},
{
"TypeId": "public class Microsoft.AspNetCore.Diagnostics.EntityFrameworkCore.DataStoreErrorLoggerProvider : Microsoft.Extensions.Logging.ILoggerProvider",
"Kind": "Removal"
},
{
"TypeId": "public class Microsoft.AspNetCore.Diagnostics.EntityFrameworkCore.DatabaseErrorPageMiddleware",
"MemberId": "public virtual System.Threading.Tasks.Task Invoke(Microsoft.AspNetCore.Http.HttpContext context)",
"Kind": "Removal"
} }
] ]