public void Async_commands_that_are_canceled_are_still_logged()
{
var log = new StringWriter();
using (var context = new BlogContextNoInit())
{
context.Database.Log = log.Write;
context.Database.Connection.Open();
var cancellation = new CancellationTokenSource();
cancellation.Cancel();
var command = context.Database.ExecuteSqlCommandAsync("update Blogs set Title = 'No' where Id = -1", cancellation.Token);
Assert.Throws <AggregateException>(() => command.Wait());
Assert.True(command.IsCanceled);
context.Database.Connection.Close();
}
var logLines = log.ToString().Split(new[] { Environment.NewLine }, StringSplitOptions.None);
Assert.Equal(5, logLines.Length);
Assert.Equal("update Blogs set Title = 'No' where Id = -1", logLines[0]);
_resourceVerifier.VerifyMatch("CommandLogAsync", logLines[1], new AnyValueParameter(), "");
_resourceVerifier.VerifyMatch("CommandLogCanceled", logLines[2], new AnyValueParameter(), "");
}
public DbCommandLoggerTests()
{
using (var context = new BlogContextNoInit())
{
context.Database.Initialize(force: false);
}
}
public DbCommandLoggerTests()
{
using (var context = new BlogContextNoInit())
{
context.Database.Initialize(force: false);
}
}
public DatabaseLogFormatterTests()
{
using (var context = new BlogContextNoInit())
{
context.Database.Initialize(force: false);
}
}
public void The_command_formatter_to_use_can_be_changed()
{
var log = new StringWriter();
try
{
MutableResolver.AddResolver <Func <DbContext, Action <string>, DatabaseLogFormatter> >(
k => (Func <DbContext, Action <string>, DatabaseLogFormatter>)((c, w) => new TestDatabaseLogFormatter(c, w)));
using (var context = new BlogContextNoInit())
{
context.Database.Log = log.Write;
var blog = context.Blogs.Single();
Assert.Equal("Half a Unicorn", blog.Title);
}
}
finally
{
MutableResolver.ClearResolvers();
}
var logLines = log.ToString().Split(new[] { Environment.NewLine }, StringSplitOptions.None);
Assert.Equal(3, logLines.Length);
Assert.Equal(
"Context 'BlogContextNoInit' is executing command 'SELECT TOP (2) [c].[Id] AS [Id], [c].[Title] AS [Title] FROM [dbo].[Blogs] AS [c]'",
logLines[0]);
Assert.Equal(
"Context 'BlogContextNoInit' finished executing command",
logLines[1]);
}
public CommandInterceptionTests()
{
using (var context = new BlogContextNoInit())
{
context.Database.Initialize(force: false);
}
}
public CommandInterceptionTests()
{
using (var context = new BlogContextNoInit())
{
context.Database.Initialize(force: false);
}
}
private static void CreateContext(out WeakReference weakDbContext, out WeakReference weakStringWriter)
{
var log = new StringWriter();
var context = new BlogContextNoInit();
context.Database.Log = log.Write;
weakDbContext = new WeakReference(context);
weakStringWriter = new WeakReference(log);
}
public void Async_commands_that_are_canceled_are_still_intercepted()
{
var logger = new CommandLogger();
Interception.AddInterceptor(logger);
var cancellation = new CancellationTokenSource();
var cancellationToken = cancellation.Token;
try
{
using (var context = new BlogContextNoInit())
{
context.Database.Connection.Open();
cancellation.Cancel();
var command = context.Database.ExecuteSqlCommandAsync("update Blogs set Title = 'No' where Id = -1", cancellationToken);
try
{
command.Wait();
}
catch (AggregateException)
{
// Ignore
}
Assert.True(command.IsCanceled);
context.Database.Connection.Close();
}
}
finally
{
Interception.RemoveInterceptor(logger);
}
Assert.Equal(2, logger.Log.Count);
var executingLog = logger.Log[0];
Assert.Equal(CommandMethod.NonQueryExecuting, executingLog.Method);
Assert.True(executingLog.IsAsync);
Assert.Null(executingLog.Result);
Assert.Null(executingLog.Exception);
var executedLog = logger.Log[1];
Assert.Equal(CommandMethod.NonQueryExecuted, executedLog.Method);
Assert.True(executedLog.IsAsync);
Assert.Equal(0, executedLog.Result);
Assert.Null(executedLog.Exception);
Assert.True(executedLog.TaskStatus.HasFlag(TaskStatus.Canceled));
}
public void Command_trees_for_initialization_and_simple_query_and_update_commands_can_be_logged()
{
// Make sure that HistoryContext has been used to ensure test runs consistently regardless of
// whether or not other tests have run before it.
using (var initContext = new BlogContextNoInit())
{
ExtendedSqlAzureExecutionStrategy.ExecuteNew(
() =>
{
initContext.Database.Initialize(force: false);
});
}
var logger = new CommandTreeLogger();
DbInterception.Add(logger);
BlogContextLogAll context;
try
{
using (context = new BlogContextLogAll())
{
BlogContext.DoStuff(context);
}
}
finally
{
DbInterception.Remove(logger);
}
// Sanity check that we got tree creations logged
Assert.True(logger.Log.OfType <DbQueryCommandTree>().Any(t => t.DataSpace == DataSpace.CSpace));
Assert.True(logger.Log.OfType <DbQueryCommandTree>().Any(t => t.DataSpace == DataSpace.SSpace));
Assert.True(logger.Log.OfType <DbInsertCommandTree>().Any(t => t.DataSpace == DataSpace.SSpace));
#if !NET40
Assert.True(logger.Log.OfType <DbUpdateCommandTree>().Any(t => t.DataSpace == DataSpace.SSpace));
Assert.True(
logger.Log.OfType <DbUpdateCommandTree>()
.Any(
t => t.SetClauses.OfType <DbSetClause>()
.Any(
c => ((DbPropertyExpression)c.Property).Property.Name == "Title" &&
(string)((DbConstantExpression)c.Value).Value == "I'm a logger and I'm okay...")));
#endif
foreach (var interceptionContext in logger.LogWithContext.Select(t => t.Item2))
{
Assert.Contains(context, interceptionContext.DbContexts);
}
}
public void Command_trees_for_initialization_and_simple_query_and_update_commands_can_be_logged()
{
// Make sure that HistoryContext has been used to ensure test runs consistently regardless of
// whether or not other tests have run before it.
using (var initContext = new BlogContextNoInit())
{
ExtendedSqlAzureExecutionStrategy.ExecuteNew(
() =>
{
initContext.Database.Initialize(force: false);
});
}
var logger = new CommandTreeLogger();
DbInterception.Add(logger);
BlogContextLogAll context;
try
{
using (context = new BlogContextLogAll())
{
BlogContext.DoStuff(context);
}
}
finally
{
DbInterception.Remove(logger);
}
// Sanity check that we got tree creations logged
Assert.True(logger.Log.OfType<DbQueryCommandTree>().Any(t => t.DataSpace == DataSpace.CSpace));
Assert.True(logger.Log.OfType<DbQueryCommandTree>().Any(t => t.DataSpace == DataSpace.SSpace));
Assert.True(logger.Log.OfType<DbInsertCommandTree>().Any(t => t.DataSpace == DataSpace.SSpace));
#if !NET40
Assert.True(logger.Log.OfType<DbUpdateCommandTree>().Any(t => t.DataSpace == DataSpace.SSpace));
Assert.True(
logger.Log.OfType<DbUpdateCommandTree>()
.Any(
t => t.SetClauses.OfType<DbSetClause>()
.Any(
c => ((DbPropertyExpression)c.Property).Property.Name == "Title"
&& (string)((DbConstantExpression)c.Value).Value == "I'm a logger and I'm okay...")));
#endif
foreach (var interceptionContext in logger.LogWithContext.Select(t => t.Item2))
{
Assert.Contains(context, interceptionContext.DbContexts);
}
}
public void Simple_query_and_update_commands_can_be_logged()
{
var log = new StringWriter();
using (var context = new BlogContextNoInit())
{
context.Database.Log = log.Write;
BlogContext.DoStuff(context);
}
var logLines = log.ToString().Split(new[] { Environment.NewLine }, StringSplitOptions.None);
#if NET40
const int selectCount = 4;
const int updateCount = 0;
const int asyncCount = 0;
const int paramCount = 2;
const int imALoggerCount = 0;
const int transactionCount = 1;
const int connectionCount = 3;
#else
const int selectCount = 5;
const int updateCount = 1;
const int asyncCount = 2;
const int paramCount = 4;
const int imALoggerCount = 1;
const int transactionCount = 2;
const int connectionCount = 4;
#endif
Assert.Equal(selectCount, logLines.Count(l => l.ToUpperInvariant().StartsWith("SELECT")));
Assert.Equal(1, logLines.Count(l => l.ToUpperInvariant().StartsWith("INSERT")));
Assert.Equal(updateCount, logLines.Count(l => l.ToUpperInvariant().StartsWith("UPDATE")));
Assert.Equal(asyncCount, logLines.Count(l => _resourceVerifier.IsMatch("CommandLogAsync", l)));
Assert.Equal(paramCount, logLines.Count(l => l.StartsWith("-- @")));
Assert.Equal(1, logLines.Count(l => l.StartsWith("-- @") && l.Contains("'Throw it away...'")));
Assert.Equal(imALoggerCount, logLines.Count(l => l.StartsWith("-- @") && l.Contains("'I'm a logger and I'm okay...'")));
Assert.Equal(paramCount / 2, logLines.Count(l => l.StartsWith("-- @") && l.Contains("'1'")));
Assert.Equal(selectCount, logLines.Count(l => _resourceVerifier.IsMatch("CommandLogComplete", l, new AnyValueParameter(), "SqlDataReader", "")));
Assert.Equal(updateCount, logLines.Count(l => _resourceVerifier.IsMatch("CommandLogComplete", l, new AnyValueParameter(), "1", "")));
Assert.Equal(transactionCount, logLines.Count(l => _resourceVerifier.IsMatch("TransactionStartedLog", l, new AnyValueParameter(), "")));
Assert.Equal(transactionCount, logLines.Count(l => _resourceVerifier.IsMatch("TransactionRolledBackLog", l, new AnyValueParameter(), "")));
Assert.Equal(connectionCount, logLines.Count(l => _resourceVerifier.IsMatch("ConnectionOpenedLog", l, new AnyValueParameter(), "")));
Assert.Equal(connectionCount, logLines.Count(l => _resourceVerifier.IsMatch("ConnectionClosedLog", l, new AnyValueParameter(), "")));
}
public void Commands_that_result_in_exceptions_are_still_logged()
{
Exception exception;
var log = new StringWriter();
using (var context = new BlogContextNoInit())
{
context.Database.Log = log.Write;
exception = Assert.Throws<SqlException>(() => context.Blogs.SqlQuery("select * from No.Chance").ToList());
}
var logLines = log.ToString().Split(new[] { Environment.NewLine }, StringSplitOptions.None);
Assert.Equal(5, logLines.Length);
Assert.Equal("select * from No.Chance", logLines[0]);
_resourceVerifier.VerifyMatch("CommandLogFailed", logLines[2], new AnyValueParameter(), exception.Message, "");
}
public void Commands_that_result_in_exceptions_are_still_logged()
{
Exception exception;
var log = new StringWriter();
using (var context = new BlogContextNoInit())
{
context.Database.Log = log.Write;
exception = Assert.Throws <SqlException>(() => context.Blogs.SqlQuery("select * from No.Chance").ToList());
}
var logLines = log.ToString().Split(new[] { Environment.NewLine }, StringSplitOptions.None);
Assert.Equal(7, logLines.Length);
Assert.Equal("select * from No.Chance", logLines[1]);
_resourceVerifier.VerifyMatch("CommandLogFailed", logLines[3], new AnyValueParameter(), exception.Message, "");
}
public void Async_commands_that_result_in_exceptions_are_still_intercepted()
{
var logger = new CommandLogger();
DbInterception.Add(logger);
try
{
using (var context = new BlogContextNoInit())
{
var query = context.Blogs.SqlQuery("select * from No.Chance").ToListAsync();
Assert.Throws <AggregateException>(() => query.Wait());
Assert.True(query.IsFaulted);
}
}
finally
{
DbInterception.Remove(logger);
}
Assert.Equal(2, logger.Log.Count);
var executingLog = logger.Log[0];
Assert.Equal(CommandMethod.ReaderExecuting, executingLog.Method);
Assert.True(executingLog.IsAsync);
Assert.Null(executingLog.Result);
Assert.Null(executingLog.Exception);
var executedLog = logger.Log[1];
Assert.Equal(CommandMethod.ReaderExecuted, executedLog.Method);
Assert.True(executedLog.IsAsync);
Assert.Null(executedLog.Result);
Assert.IsType <SqlException>(executedLog.Exception);
Assert.True(executedLog.TaskStatus.HasFlag(TaskStatus.Faulted));
}
public void Simple_query_and_update_commands_can_be_logged()
{
var log = new StringWriter();
using (var context = new BlogContextNoInit())
{
context.Database.Log = log.Write;
BlogContext.DoStuff(context);
}
var logLines = log.ToString().Split(new[] { Environment.NewLine }, StringSplitOptions.None);
#if NET40
const int selectCount = 4;
const int updateCount = 0;
const int asyncCount = 0;
const int paramCount = 2;
const int imALoggerCount = 0;
#else
const int selectCount = 5;
const int updateCount = 1;
const int asyncCount = 2;
const int paramCount = 4;
const int imALoggerCount = 1;
#endif
Assert.Equal(selectCount, logLines.Count(l => l.ToUpperInvariant().StartsWith("SELECT")));
Assert.Equal(1, logLines.Count(l => l.ToUpperInvariant().StartsWith("INSERT")));
Assert.Equal(updateCount, logLines.Count(l => l.ToUpperInvariant().StartsWith("UPDATE")));
Assert.Equal(asyncCount, logLines.Count(l => _resourceVerifier.IsMatch("CommandLogAsync", l)));
Assert.Equal(paramCount, logLines.Count(l => l.StartsWith("-- @")));
Assert.Equal(1, logLines.Count(l => l.StartsWith("-- @") && l.Contains("'Throw it away...'")));
Assert.Equal(imALoggerCount, logLines.Count(l => l.StartsWith("-- @") && l.Contains("'I'm a logger and I'm okay...'")));
Assert.Equal(paramCount / 2, logLines.Count(l => l.StartsWith("-- @") && l.Contains("'1'")));
Assert.Equal(selectCount, logLines.Count(l => _resourceVerifier.IsMatch("CommandLogComplete", l, new AnyValueParameter(), "SqlDataReader", "")));
Assert.Equal(updateCount, logLines.Count(l => _resourceVerifier.IsMatch("CommandLogComplete", l, new AnyValueParameter(), "1", "")));
}
public void DatabaseLogFormatter_is_disposed_even_if_the_context_is_not()
{
var log = new StringWriter();
var context = new BlogContextNoInit();
context.Database.Log = log.Write;
var weakDbContext = new WeakReference(context);
var weakStringWriter = new WeakReference(log);
log = null;
context = null;
GC.Collect();
GC.WaitForPendingFinalizers();
Assert.False(weakDbContext.IsAlive);
DbDispatchersHelpers.AssertNoInterceptors();
// Need a second pass as the DatabaseLogFormatter is removed from the interceptors in the InternalContext finalizer
GC.Collect();
Assert.False(weakStringWriter.IsAlive);
}
public void Commands_that_result_in_exceptions_are_still_intercepted()
{
var logger = new CommandLogger();
DbInterception.Add(logger);
Exception exception;
try
{
using (var context = new BlogContextNoInit())
{
exception = Assert.Throws <SqlException>(() => context.Blogs.SqlQuery("select * from No.Chance").ToList());
}
}
finally
{
DbInterception.Remove(logger);
}
Assert.Equal(2, logger.Log.Count);
var executingLog = logger.Log[0];
Assert.Equal(CommandMethod.ReaderExecuting, executingLog.Method);
Assert.False(executingLog.IsAsync);
Assert.Null(executingLog.Result);
Assert.Null(executingLog.Exception);
var executedLog = logger.Log[1];
Assert.Equal(CommandMethod.ReaderExecuted, executedLog.Method);
Assert.False(executedLog.IsAsync);
Assert.Null(executedLog.Result);
Assert.Same(exception, executedLog.Exception);
}
public void Multiple_contexts_running_concurrently_can_use_interception()
{
var loggers = new ConcurrentBag <CommandLogger>();
const int executionCount = 5;
ExecuteInParallel(
() =>
{
using (var context = new BlogContextNoInit())
{
var logger = new CommandLogger(context);
DbInterception.Add(logger);
loggers.Add(logger);
try
{
BlogContext.DoStuff(context);
}
finally
{
DbInterception.Remove(logger);
}
var commandsUsed = new bool[Enum.GetValues(typeof(CommandMethod)).Length];
for (var i = 0; i < logger.Log.Count; i++)
{
var method = logger.Log[i].Method;
commandsUsed[(int)method] = true;
if (method.ToString().EndsWith("Executing"))
{
Assert.Equal(method + 1, logger.Log[i + 1].Method);
Assert.Same(logger.Log[i].Command, logger.Log[i + 1].Command);
}
}
// Check that expected command have log entries
Assert.True(commandsUsed[(int)CommandMethod.ReaderExecuting]);
Assert.True(commandsUsed[(int)CommandMethod.ReaderExecuted]);
Assert.True(commandsUsed[(int)CommandMethod.ReaderExecuting]);
Assert.True(commandsUsed[(int)CommandMethod.ReaderExecuted]);
#if !NET40
Assert.True(commandsUsed[(int)CommandMethod.NonQueryExecuting]);
Assert.True(commandsUsed[(int)CommandMethod.NonQueryExecuted]);
#endif
// Sanity check on command text
var commandTexts = logger.Log.Select(l => l.CommandText.ToLowerInvariant());
Assert.True(commandTexts.Any(c => c.StartsWith("select")));
Assert.True(commandTexts.Any(c => c.StartsWith("insert")));
#if !NET40
Assert.True(commandTexts.Any(c => c.StartsWith("update")));
#endif
// Sanity check on results
Assert.True(logger.Log.Where(l => l.Method == CommandMethod.NonQueryExecuted).All(l => l.Result != null));
Assert.True(logger.Log.Where(l => l.Method == CommandMethod.ReaderExecuted).All(l => l.Result != null));
}
}, executionCount);
// Check that each execution logged exactly the same commands.
Assert.Equal(executionCount, loggers.Count);
var firstLog = loggers.First().Log;
foreach (var log in loggers.Select(l => l.Log).Skip(1))
{
Assert.Equal(firstLog.Count, log.Count);
for (var i = 0; i < log.Count; i++)
{
Assert.Equal(firstLog[i].Method, log[i].Method);
Assert.Equal(firstLog[i].CommandText, log[i].CommandText);
if (firstLog[i].Result == null)
{
Assert.Null(log[i].Result);
}
else
{
Assert.Same(firstLog[i].Result.GetType(), log[i].Result.GetType());
}
}
}
}
public void Async_commands_that_are_canceled_are_still_intercepted()
{
var logger = new CommandLogger();
Interception.AddInterceptor(logger);
var cancellation = new CancellationTokenSource();
var cancellationToken = cancellation.Token;
try
{
using (var context = new BlogContextNoInit())
{
context.Database.Connection.Open();
cancellation.Cancel();
var command = context.Database.ExecuteSqlCommandAsync("update Blogs set Title = 'No' where Id = -1", cancellationToken);
try
{
command.Wait();
}
catch (AggregateException)
{
// Ignore
}
Assert.True(command.IsCanceled);
context.Database.Connection.Close();
}
}
finally
{
Interception.RemoveInterceptor(logger);
}
Assert.Equal(2, logger.Log.Count);
var executingLog = logger.Log[0];
Assert.Equal(CommandMethod.NonQueryExecuting, executingLog.Method);
Assert.True(executingLog.IsAsync);
Assert.Null(executingLog.Result);
Assert.Null(executingLog.Exception);
var executedLog = logger.Log[1];
Assert.Equal(CommandMethod.NonQueryExecuted, executedLog.Method);
Assert.True(executedLog.IsAsync);
Assert.Equal(0, executedLog.Result);
Assert.Null(executedLog.Exception);
Assert.True(executedLog.TaskStatus.HasFlag(TaskStatus.Canceled));
}
public void Async_commands_that_result_in_exceptions_are_still_intercepted()
{
var logger = new CommandLogger();
DbInterception.Add(logger);
try
{
using (var context = new BlogContextNoInit())
{
var query = context.Blogs.SqlQuery("select * from No.Chance").ToListAsync();
Assert.Throws<AggregateException>(() => query.Wait());
Assert.True(query.IsFaulted);
}
}
finally
{
DbInterception.Remove(logger);
}
Assert.Equal(2, logger.Log.Count);
var executingLog = logger.Log[0];
Assert.Equal(CommandMethod.ReaderExecuting, executingLog.Method);
Assert.True(executingLog.IsAsync);
Assert.Null(executingLog.Result);
Assert.Null(executingLog.Exception);
var executedLog = logger.Log[1];
Assert.Equal(CommandMethod.ReaderExecuted, executedLog.Method);
Assert.True(executedLog.IsAsync);
Assert.Null(executedLog.Result);
Assert.IsType<SqlException>(executedLog.Exception);
Assert.True(executedLog.TaskStatus.HasFlag(TaskStatus.Faulted));
}
public void Multiple_contexts_running_concurrently_can_use_interception()
{
var loggers = new ConcurrentBag<CommandLogger>();
const int executionCount = 5;
ExecuteInParallel(
() =>
{
using (var context = new BlogContextNoInit())
{
var logger = new CommandLogger(context);
DbInterception.Add(logger);
loggers.Add(logger);
try
{
BlogContext.DoStuff(context);
}
finally
{
DbInterception.Remove(logger);
}
var commandsUsed = new bool[Enum.GetValues(typeof(CommandMethod)).Length];
for (var i = 0; i < logger.Log.Count; i++)
{
var method = logger.Log[i].Method;
commandsUsed[(int)method] = true;
if (method.ToString().EndsWith("Executing"))
{
Assert.Equal(method + 1, logger.Log[i + 1].Method);
Assert.Same(logger.Log[i].Command, logger.Log[i + 1].Command);
}
}
// Check that expected command have log entries
Assert.True(commandsUsed[(int)CommandMethod.ReaderExecuting]);
Assert.True(commandsUsed[(int)CommandMethod.ReaderExecuted]);
Assert.True(commandsUsed[(int)CommandMethod.ReaderExecuting]);
Assert.True(commandsUsed[(int)CommandMethod.ReaderExecuted]);
#if !NET40
Assert.True(commandsUsed[(int)CommandMethod.NonQueryExecuting]);
Assert.True(commandsUsed[(int)CommandMethod.NonQueryExecuted]);
#endif
// Sanity check on command text
var commandTexts = logger.Log.Select(l => l.CommandText.ToLowerInvariant());
Assert.True(commandTexts.Any(c => c.StartsWith("select")));
Assert.True(commandTexts.Any(c => c.StartsWith("insert")));
#if !NET40
Assert.True(commandTexts.Any(c => c.StartsWith("update")));
#endif
// Sanity check on results
Assert.True(logger.Log.Where(l => l.Method == CommandMethod.NonQueryExecuted).All(l => l.Result != null));
Assert.True(logger.Log.Where(l => l.Method == CommandMethod.ReaderExecuted).All(l => l.Result != null));
}
}, executionCount);
// Check that each execution logged exactly the same commands.
Assert.Equal(executionCount, loggers.Count);
var firstLog = loggers.First().Log;
foreach (var log in loggers.Select(l => l.Log).Skip(1))
{
Assert.Equal(firstLog.Count, log.Count);
for (var i = 0; i < log.Count; i++)
{
Assert.Equal(firstLog[i].Method, log[i].Method);
Assert.Equal(firstLog[i].CommandText, log[i].CommandText);
if (firstLog[i].Result == null)
{
Assert.Null(log[i].Result);
}
else
{
Assert.Same(firstLog[i].Result.GetType(), log[i].Result.GetType());
}
}
}
}
public void Commands_that_result_in_exceptions_are_still_intercepted()
{
var logger = new CommandLogger();
DbInterception.Add(logger);
Exception exception;
try
{
using (var context = new BlogContextNoInit())
{
exception = Assert.Throws<SqlException>(() => context.Blogs.SqlQuery("select * from No.Chance").ToList());
}
}
finally
{
DbInterception.Remove(logger);
}
Assert.Equal(2, logger.Log.Count);
var executingLog = logger.Log[0];
Assert.Equal(CommandMethod.ReaderExecuting, executingLog.Method);
Assert.False(executingLog.IsAsync);
Assert.Null(executingLog.Result);
Assert.Null(executingLog.Exception);
var executedLog = logger.Log[1];
Assert.Equal(CommandMethod.ReaderExecuted, executedLog.Method);
Assert.False(executedLog.IsAsync);
Assert.Null(executedLog.Result);
Assert.Same(exception, executedLog.Exception);
}
public void Multiple_contexts_running_concurrently_can_log_command_trees_except_trees_for_cached_queries()
{
// Make sure no logs get initialization trees
using (var context = new BlogContextNoInit())
{
context.Database.Initialize(force: false);
}
// Run the test code once to log both update and query trees
using (var context = new BlogContextNoInit())
{
var logger = new CommandTreeLogger(context);
Interception.AddInterceptor(logger);
try
{
BlogContext.DoStuff(context);
}
finally
{
Interception.RemoveInterceptor(logger);
}
#if NET40
Assert.Equal(4, logger.Log.Count);
#else
Assert.Equal(5, logger.Log.Count);
#endif
Assert.True(logger.Log.OfType <DbQueryCommandTree>().Any(t => t.DataSpace == DataSpace.CSpace));
Assert.True(logger.Log.OfType <DbInsertCommandTree>().Any(t => t.DataSpace == DataSpace.SSpace));
#if !NET40
Assert.True(logger.Log.OfType <DbUpdateCommandTree>().Any(t => t.DataSpace == DataSpace.SSpace));
#endif
}
// Now run again multiple times concurrently--only update trees logged
var loggers = new ConcurrentBag <CommandTreeLogger>();
const int executionCount = 5;
ExecuteInParallel(
() =>
{
using (var context = new BlogContextNoInit())
{
var logger = new CommandTreeLogger(context);
Interception.AddInterceptor(logger);
loggers.Add(logger);
try
{
BlogContext.DoStuff(context);
}
finally
{
Interception.RemoveInterceptor(logger);
}
}
}, executionCount);
Assert.Equal(executionCount, loggers.Count);
foreach (var logger in loggers)
{
#if NET40
Assert.Equal(1, logger.Log.Count);
#else
Assert.Equal(2, logger.Log.Count);
#endif
Assert.False(logger.Log.OfType <DbQueryCommandTree>().Any(t => t.DataSpace == DataSpace.CSpace));
Assert.True(logger.Log.OfType <DbInsertCommandTree>().Any(t => t.DataSpace == DataSpace.SSpace));
#if !NET40
Assert.True(logger.Log.OfType <DbUpdateCommandTree>().Any(t => t.DataSpace == DataSpace.SSpace));
#endif
}
}
public void Async_commands_that_are_canceled_are_still_logged()
{
var log = new StringWriter();
using (var context = new BlogContextNoInit())
{
context.Database.Log = log.Write;
context.Database.Connection.Open();
var cancellation = new CancellationTokenSource();
cancellation.Cancel();
var command = context.Database.ExecuteSqlCommandAsync("update Blogs set Title = 'No' where Id = -1", cancellation.Token);
Assert.Throws<AggregateException>(() => command.Wait());
Assert.True(command.IsCanceled);
context.Database.Connection.Close();
}
var logLines = log.ToString().Split(new[] { Environment.NewLine }, StringSplitOptions.None);
Assert.Equal(5, logLines.Length);
Assert.Equal("update Blogs set Title = 'No' where Id = -1", logLines[0]);
_resourceVerifier.VerifyMatch("CommandLogAsync", logLines[1], new AnyValueParameter(), "");
_resourceVerifier.VerifyMatch("CommandLogCanceled", logLines[2], new AnyValueParameter(), "");
}
public void The_command_logger_to_use_can_be_changed()
{
var log = new StringWriter();
try
{
MutableResolver.AddResolver<Func<DbContext, Action<string>, DbCommandLogger>>(
k => (Func<DbContext, Action<string>, DbCommandLogger>)((c, w) => new TestDbCommandLogger(c, w)));
using (var context = new BlogContextNoInit())
{
context.Database.Log = log.Write;
var blog = context.Blogs.Single();
Assert.Equal("Half a Unicorn", blog.Title);
}
}
finally
{
MutableResolver.ClearResolvers();
}
var logLines = log.ToString().Split(new[] { Environment.NewLine }, StringSplitOptions.None);
Assert.Equal(3, logLines.Length);
Assert.Equal(
"Context 'BlogContextNoInit' is executing command 'SELECT TOP (2) [c].[Id] AS [Id], [c].[Title] AS [Title] FROM [dbo].[Blogs] AS [c]'",
logLines[0]);
Assert.Equal(
"Context 'BlogContextNoInit' finished executing command",
logLines[1]);
}
public void Multiple_contexts_running_concurrently_can_log_command_trees_except_trees_for_cached_queries()
{
// Make sure no logs get initialization trees
using (var context = new BlogContextNoInit())
{
context.Database.Initialize(force: false);
}
// Run the test code once to log both update and query trees
using (var context = new BlogContextNoInit())
{
var logger = new CommandTreeLogger(context);
Interception.AddInterceptor(logger);
try
{
BlogContext.DoStuff(context);
}
finally
{
Interception.RemoveInterceptor(logger);
}
#if NET40
Assert.Equal(4, logger.Log.Count);
#else
Assert.Equal(5, logger.Log.Count);
#endif
Assert.True(logger.Log.OfType<DbQueryCommandTree>().Any(t => t.DataSpace == DataSpace.CSpace));
Assert.True(logger.Log.OfType<DbInsertCommandTree>().Any(t => t.DataSpace == DataSpace.SSpace));
#if !NET40
Assert.True(logger.Log.OfType<DbUpdateCommandTree>().Any(t => t.DataSpace == DataSpace.SSpace));
#endif
}
// Now run again multiple times concurrently--only update trees logged
var loggers = new ConcurrentBag<CommandTreeLogger>();
const int executionCount = 5;
ExecuteInParallel(
() =>
{
using (var context = new BlogContextNoInit())
{
var logger = new CommandTreeLogger(context);
Interception.AddInterceptor(logger);
loggers.Add(logger);
try
{
BlogContext.DoStuff(context);
}
finally
{
Interception.RemoveInterceptor(logger);
}
}
}, executionCount);
Assert.Equal(executionCount, loggers.Count);
foreach (var logger in loggers)
{
#if NET40
Assert.Equal(1, logger.Log.Count);
#else
Assert.Equal(2, logger.Log.Count);
#endif
Assert.False(logger.Log.OfType<DbQueryCommandTree>().Any(t => t.DataSpace == DataSpace.CSpace));
Assert.True(logger.Log.OfType<DbInsertCommandTree>().Any(t => t.DataSpace == DataSpace.SSpace));
#if !NET40
Assert.True(logger.Log.OfType<DbUpdateCommandTree>().Any(t => t.DataSpace == DataSpace.SSpace));
#endif
}
}
