Error message here!

Hide Error message here!

忘记密码?

Error message here!

请输入正确邮箱

Hide Error message here!

密码丢失?请输入您的电子邮件地址。您将收到一个重设密码链接。

Error message here!

返回登录

Close

EF6学习笔记二十三:拦截器异常、耗时监控

张四海 2019-01-28 12:29:00 阅读数:182 评论数:0 点赞数:0 收藏数:0

要专业系统地学习EF推荐《你必须掌握的Entity Framework 6.x与Core 2.0》。这本书作者(汪鹏,Jeffcky)的博客:https://www.cnblogs.com/CreateMyself/

 上次一直在弄日志,从最开始简单的ctx.Database.Log 然后到自己写一个派生自DatabaseLogFormatter的类,来实现结构化日志输出。里面有很多方法可以供我们重写。

那么DatabaseLogFormater是继承自IDbCommandInterceptor接口,也就是拦截器。可以看到下面这个接口的方法就只有六个,很好理解。NonQuery拦截非查询操作,Reader拦截查询操作,Scalar拦截聚合操作。

那么我们就可使用拦截器来记录异常,在SQL语句执行之前开启计时,在执行完成关闭计时,把耗时的SQL语句记录下来。

其实DatabaseLogFormatter同样提供了以下六个方法,肯定我们只需要继承DatabaseLogFormatter这个类也可以实现异常或耗时情况的记录。

但是我没有去试。第一,因为DatabaseLogFormatter这个类的类名没有“拦截”的意思,那么我们通过继承DatabaseLogFormatter来实现拦截,在语义上就显得有点别扭吧。

第二,通过继承接口,那么我们可以通过接口的强制实现里面的方法,再用VS补全代码的功能,那么就能写很少的代码吧。

这篇博客,我分成这样几部分来说一下

1、通过拦截实现简单的异常记录(我们先很快的把东西搞出来,能够运行起来)

2、拦截代码里面要格外注意的一个问题

3,、贴出完整的异常和性能监控代码

4、记录我碰到的一个很不解的 问题(很遗憾,这个问题我没有解决)

实现简单的异常拦截

创建Error模型,用来记录异常信息,实现自己的拦截类,然后在EF的配置中进行注册

Error model

public class Error3
{
public int Id { get; set; }
public string Name { get; set; }
public DateTime AddTime { get; set; }
}
View Code

自己的拦截类

namespace _201901212.NLog
{
public class DatabaseInterceptorLogger : IDbCommandInterceptor
{
static readonly ConcurrentDictionary<DbCommand, DateTime> MStartTime = new ConcurrentDictionary<DbCommand, DateTime>();
public void NonQueryExecuted(DbCommand command, DbCommandInterceptionContext<int> interceptionContext)
{
Console.WriteLine("调用NonQueryExecuted");
Log(command, interceptionContext);
}
public void NonQueryExecuting(DbCommand command, DbCommandInterceptionContext<int> interceptionContext)
{
Console.WriteLine("调用NonQueryExecuting");
OnStart(command);
}
public void ReaderExecuted(DbCommand command, DbCommandInterceptionContext<DbDataReader> interceptionContext)
{
Console.WriteLine("调用ReaderExecuted");
Log(command, interceptionContext);
}
public void ReaderExecuting(DbCommand command, DbCommandInterceptionContext<DbDataReader> interceptionContext)
{
Console.WriteLine("调用ReaderExecuting");
OnStart(command);
}
public void ScalarExecuted(DbCommand command, DbCommandInterceptionContext<object> interceptionContext)
{
Console.WriteLine("调用ScalarExecuted");
Log(command, interceptionContext);
}
public void ScalarExecuting(DbCommand command, DbCommandInterceptionContext<object> interceptionContext)
{
Console.WriteLine("调用ScalarExecuting");
OnStart(command);
}
private static void Log<T>(DbCommand command, DbCommandInterceptionContext<T> interceptionContext)
{
Console.WriteLine("拦截结束");
// 打印SQL语句
 Console.WriteLine(command.CommandText);
if (interceptionContext.Exception != null)
{
using (EFDbContext ctx = new EFDbContext())
{
ctx.Errors3.Add(new Error3 { AddTime = DateTime.Now});
ctx.SaveChanges();
}
}
}
private static void OnStart(DbCommand command)
{
//Console.WriteLine("拦截开始");
 MStartTime.TryAdd(command, DateTime.Now);
}
}
}
View Code

在EF的配置中注册,这里我没有在上下文的构造函数中注册,而是写一个派生自DbConfiguration的类,独立出来好一点,不用频繁修改上下文类

public class DBContextConfiguration:DbConfiguration
{
public DBContextConfiguration()
{
// 添加拦截器
DbInterception.Add(new DatabaseInterceptorLogger());
}
}
View Code

然后我们执行一段会报错的添加操作(时间类型字段的我给个数字+字母的字符串)

List<SqlParameter> paraList = new List<SqlParameter>
{
new SqlParameter{ ParameterName="@name",SqlDbType = System.Data.SqlDbType.NVarChar,Value = "来到地球"},
new SqlParameter{ ParameterName="@pagesize",SqlDbType = System.Data.SqlDbType.Int,Value=329}
};
ctx.Database.ExecuteSqlCommand(@"insert into tb_books(id,name,pagesize,addtime)values(newid(),@name,@pagesize,'ewr223')", paraList.ToArray());
ctx.SaveChanges();
View Code

 

简单的异常记录就完成了。

这里要注意两个问题。

第一,在操作数据时,EF会对模型做出验证

 public class Error2
{
public string Id { get; set; }
public string Name { get; set; }
public DateTime AddTime { get; set; }
}
View Code

 我添加一个空对象

 ctx.Errors2.Add(new Error2());
ctx.SaveChanges();
View Code

 

可以看到,根本就没有执行SQL语句,因为验证没有通过。因为Error2的主键是string类型,而不是int类型,主键一定要给它

那为什么上面我插入错误的时间值,验证通过了,而是在执行SQL语句的时候报错了。

EF的验证我没有去研究,现在只能记住,主键不是自增类型的,在添加如果不给主键值,那么就不能通过EF的验证。

第二个要注意的问题

我们在拦截中又构造了上下文对象,而且添加数据,那么会不会触发拦截?肯定的。所以就会出现这样的问题:当我判断Exception是否为null来添加Error时,如果在添加error时也报错了,那么就会一直循环下去!

我现在改成这样

private static void Log<T>(DbCommand command, DbCommandInterceptionContext<T> interceptionContext)
{
Console.WriteLine("拦截结束");
// 打印SQL语句
 Console.WriteLine(command.CommandText);
if (interceptionContext.Exception != null)
{
using (EFDbContext ctx = new EFDbContext())
{
// 我现在执行一个会报错的添加,datetime类型会报错,因为C#中datetime最小值为0001/1/1 0:00:00,而数据库中是1753/1/1 0:00:00
ctx.Errors3.Add(new Error3 ());
ctx.SaveChanges();
}
}
}
View Code

 完整的异常以及性能记录

private static void Log<T>(DbCommand command, DbCommandInterceptionContext<T> interceptionContext)
{
// timespan表示两个日期差
 DateTime startTime;
TimeSpan duration;
//ConcurrentDictionary类型 表示可由多个线程同时访问的键、值对的线程安全集合
MStartTime.TryRemove(command, out startTime);
if (startTime != default(DateTime))
{
duration = DateTime.Now - startTime;
}
else
{
duration = TimeSpan.Zero;
}
const int requestId = -1;
var parameters = new StringBuilder();
foreach (DbParameter param in command.Parameters)
{
parameters.AppendLine(param.ParameterName + " " + param.DbType + "=" + param.Value);
}
var message = interceptionContext.Exception == null
? $"Database call took{duration.TotalSeconds.ToString("N3")}" +
$" sec.RequestId{requestId}\r\n" +
$"Command:\r\n{parameters + command.CommandText}"
: $"EF Database call failed after {duration.TotalSeconds.ToString("N3")} " +
$"sec.RequestId{requestId}\r\n" +
$"Command:\r\n{parameters.ToString() + command.CommandText}" +
$"\r\nError:{interceptionContext.Exception}";
if (duration.TotalSeconds > 1 || message.Contains("EF Database call failed after"))
{
using (EFDbContext ctx = new EFDbContext())
{
Error err = new Error
{
TotalSeconds = (decimal)duration.TotalSeconds,
Active = true,
CommandType = Convert.ToString(command.CommandType),
CreateDate = DateTime.Now,
Exception = interceptionContext.Exception == null ? "" : interceptionContext.Exception.ToString(),
FileName = "",
InnerException = interceptionContext.Exception == null ? "" : Convert.ToString(interceptionContext.Exception.InnerException),
Parameters = parameters.ToString(),
Query = command.CommandText,
RequestId = 0
};
// 同样的语句造成的异常不必重复记录
if (ctx.Errors.Any(a => a.Parameters == err.Parameters && a.Query == err.Query))
{
return;
}
ctx.Errors.Add(err);
ctx.SaveChanges();
}
}
}
View Code

 现在记录一下,我碰到一个难以理解的问题。

如果是添加操作,那么肯定是调用的NonQueryExecuting 和 NonQueryExecuted 方法

但是如果你的主键是Int类型,并且自增,那么它居然调用的是ReaderExecuting 和 ReaderExecuted方法

Error2 model  主键为string 类型

 public class Error2
{
public string Id { get; set; }
public string Name { get; set; }
public DateTime AddTime { get; set; }
}
View Code

 Error3  model  主键为int类型,EF默认自增

public class Error3
{
public int Id { get; set; }
public string Name { get; set; }
public DateTime AddTime { get; set; }
}
View Code

分别对这两张表进行添加,可以发现生成的SQL语句 是有区别的

 

可以发现,对主键为自增的表进行添加,多了一条select语句

SELECT [Id]
FROM [dbo].[tb_Errors3]
WHERE @@ROWCOUNT > 0 AND [Id] = scope_identity()
View Code

首先我们看一下这个scope_identity是什么意思

这个就是取到上一条记录的自增主键的值,除了这个还有@@identity,这两个都是取自增主键的值的,scope_identity()要好用一点,具体哪里好用,还涉及到SQL中作用域的问题。这个我就又没什么研究了。

那我们在数据库中执行看一下,看看scope_indentiy()和@identity

SET NOCOUNT ON; -- 开启时不返回受影响的行计数
insert into tb_Errors(createDate,Active,TotalSeconds,RequestId) values(getdate(),1,1,1);
select SCOPE_IDENTITY() as errorid from tb_Errors;
insert into tb_Errors(createDate,Active,TotalSeconds,RequestId) values(getdate(),1,1,1);
select SCOPE_IDENTITY() as errorid from tb_Errors;
insert into tb_Errors(createDate,Active,TotalSeconds,RequestId) values(getdate(),1,1,1);
select SCOPE_IDENTITY() as errorid from tb_Errors;
SET NOCOUNT OFF;
View Code

SET NOCOUNT ON;
insert into tb_Errors(createDate,Active,TotalSeconds,RequestId) values(getdate(),0,2,2);
select @@IDENTITY as errorid from tb_Errors;
insert into tb_Errors(createDate,Active,TotalSeconds,RequestId) values(getdate(),0,2,2);
select @@IDENTITY as errorid from tb_Errors;
insert into tb_Errors(createDate,Active,TotalSeconds,RequestId) values(getdate(),0,2,2);
select @@IDENTITY as errorid from tb_Errors;
SET NOCOUNT OFF;
View Code

好像没什么区别

如果主键为自增,那么我们也可以通过SQL语句为主键写入我们自己的值

-- 居然可以这样,手动为自增字段设置值
SET IDENTITY_INSERT tb_Errors ON;
insert into tb_Errors(ErrorId,createDate,Active,TotalSeconds,RequestId) values(1,getdate(),0,2,2);
select @@IDENTITY as errorid from tb_Errors;
insert into tb_Errors(ErrorId,createDate,Active,TotalSeconds,RequestId) values(2,getdate(),0,2,2);
select @@IDENTITY as errorid from tb_Errors;
insert into tb_Errors(ErrorId,createDate,Active,TotalSeconds,RequestId) values(3,getdate(),0,2,2);
select @@IDENTITY as errorid from tb_Errors;
SET IDENTITY_INSERT tb_Errors OFF;
View Code

行,我们还是回到上面的那个问题,难道是因为多的那条SELECT语句造成的问题?

那么我们执行原始SQL语句来看一下(我们发现原始SQL语句也会被拦截,毕竟就算是执行原始SQL语句,也是调用EF提供的方法)

ctx.Database.ExecuteSqlCommand(@"INSERT[dbo].[tb_Errors3]([Name], [AddTime])VALUES(NULL,'2020-2-20')
SELECT[Id] FROM[dbo].[tb_Errors3] WHERE @@ROWCOUNT > 0 AND[Id] = scope_identity()");
ctx.SaveChanges();
View Code

 

看到了吧,我执行SQL语句,它是调用的NonQueryExecuting和NonQueryExecuted,即使有select

这就真的让人搞不懂了!

 

版权声明
本文为[张四海]所创,转载请带上原文链接,感谢
https://www.cnblogs.com/jinshan-go/p/10329701.html

编程之旅,人生之路,不止于编程,还有诗和远方。
阅代码原理,看框架知识,学企业实践;
赏诗词,读日记,踏人生之路,观世界之行;

支付宝红包,每日可领