zoukankan      html  css  js  c++  java
  • 巧用CurrentThread.Name来统一标识日志记录

    ▄︻┻┳═一Agenda:

    ▄︻┻┳═一巧用CurrentThread.Name来统一标识日志记录

    ▄︻┻┳═一巧用CurrentThread.Name来统一标识日志记录(续)

    ▄︻┻┳═一巧用CurrentThread.Name来统一标识日志记录(完结篇)

    ▄︻┻┳═一asp.net拦截器

    ▄︻┻┳═一巧用CurrentThread.Name来统一标识日志记录(java-logback篇)


    先看下面的日志:

    2017/5/21 18:00:01	[OrderQuery_180001914_C72FF]请求支付中心参数:{"order_no":"KB201705210000165","sign":"e6c3559cd4b36458b180f15bfcd9b5a5"}
    2017/5/21 18:00:01	[OrderQuery_180001914_C72FF]支付中心验签通过。
    2017/5/21 18:00:01	[OrderQuery_180001914_C72FF]进入统一订单查询服务类...
    2017/5/21 18:00:02	[OrderQuery_180001914_C72FF]支付中心支付结果是NotPay,接下来直接从上游渠道[QingdaoCITIC]查
    2017/5/21 18:00:02	[180002CITIC648]请求报文:<xml><mch_id><![CDATA[102540884712]]></mch_id><nonce_str>......<sign><![CDATA[***]]></sign></xml>
    2017/5/21 18:00:02	[OrderQuery_180002492_C6E22]请求支付中心参数:{"order_no":"KB201705210000157","sign":"472086c6ec01fa1360e779c2517389bc"}
    2017/5/21 18:00:02	[JSPay_102157155_D0F3F]请求支付中心参数:{"order_no":"20170623Test7715",... ...,"merchant_id":"m20170613000000973"}
    2017/5/21 18:00:02	[JSPay_102157155_D0F3F]支付中心验签通过。
    2017/5/21 18:00:02	[180002CITIC648]响应报文:<xml><appid><![CDATA[wx290ce4878c943699]]></appid>
    <charset><![CDATA[UTF-8]]></charset>
    <mch_id><![CDATA[102540884712]]></mch_id>
    <nonce_str><![CDATA[DF44F363-BA23-443B-97DF-73D2DA72]]></nonce_str>
    <result_code><![CDATA[0]]></result_code>
    <sign><![CDATA[***]]></sign>
    <sign_type><![CDATA[MD5]]></sign_type>
    <status><![CDATA[0]]></status>
    <trade_state><![CDATA[NOTPAY]]></trade_state>
    <trade_state_desc><![CDATA[订单未支付]]></trade_state_desc>
    <version><![CDATA[2.0]]></version>
    </xml>
    2017/5/21 18:00:02	[OrderQuery_180001914_C72FF]渠道处理结果:{"pay_status":5,"pay_status_notmatched":"NOTPAY","pay_money":0.0,"ThirdPayNo":null,"StatusIsSuccess":true,"ReturnCodeIsSuccess":true,......}
    2017/5/21 18:00:02	[OrderQuery_180001914_C72FF]订单支付结果更新完成。
    2017/5/21 18:00:02	[JSPay_102157155_D0F3F]支付中心响应结果:{"pay_url":"http://***.com/QRCode/JSPayPage.ashx?tokenId=***","status":"SUCCESS","return_code":"0","return_time":"20170623102157","sign":...}
    2017/5/21 18:00:03	[OrderQuery_180001914_C72FF]支付中心响应结果:{"order_no":"KB201705210000165","pay_status":"5","status":"SUCCESS","return_code":"0","return_message":"未支付","return_time":"20170521180002","sign":...}

     即,应用程序对每一次请求的处理过程所记录的日志统一打了一个标识。 这样,在系统运维过程中进行排障时,尤其在并发请求的情况下,即使日志记录得你中有我我中有你,也很容易就可以查到处理某次请求的来龙去脉,进而帮助我们快速定位原因。

    的确是这样的,我对这种日志记录实现方式屡试不爽。

    我这个项目是一个webapi站点,提供支付接口,供下游系统调用。

    本文要说的是我是如何实现这种统一标识日志记录的。

    最初的方式,也是多数程序员可以想到的常规的实现方式,是每次请求的最开始处定义一个LogFlag,日志helper类里在持久化日志时把加上这个LogFlag。 由于程序是分层的,比如web入口层、通信服务层、bll层、渠道通信层。那么,就需要逐层传递这个LogFlag。为此我用到了两种实现方式,一是靠构造器传参,一是定义public属性。

    /* 通过构造器传参来传递LogFlag */
    public class QRCodeService
    {
        private readonly LogHelperUtil _logHelperUtil;
        public QRCodeService(string logFlag)
        {
            _logHelperUtil = new LogHelperUtil(logFlag);
        }
        
        ... ...
    
    }
    /* 通过封装属性来传递LogFlag */ public interface IThirdPay { string LogFlag { set; get; } ... ... }

    程序里本身已经有LogHelper.cs类,为了实现这种统一标识日志的方式,避免修改原LogHelper类代码,我重新定义了一个代理类LogHelperUtil.cs:

    public class LogHelperUtil
    {
        private readonly string _LOG_FLAG;
    
        public string LOG_FLAG { get { return _LOG_FLAG; } }
    
        public LogHelperUtil(string log_flag)
        {
            _LOG_FLAG = log_flag;
            if (string.IsNullOrEmpty(_LOG_FLAG))
                _LOG_FLAG = string.Format("[{0}LOG{1}]", DateTime.Now.ToString("HHmmssfff"), new Random().Next(9999));
    
        }
        public void WriteLog(string format, params object[] args)
        {
            LogHelper.Write(_LOG_FLAG + format, args);
        }
    }

    WebApi接口层用的Asp.Net框架,每个对外接口都是一个一般处理程序文件(.ashx)。我为这每个一般处理程序的类抽象出一个基类,封装了标准的处理请求的逻辑,并定义了抽象方法MyBiz(string requestJson)。每个子类职责单一,只需关注获取并返回自己本身的处理结果数据。

    public abstract class HandlerBase : IHttpHandler
    {
        protected readonly LogHelperUtil _logHelperUtil;
        public HandlerBase()
        {
            string logFlag = string.Format("[{0}_{1:HHmmssfff}_{2}]", this.GetType().Name, DateTime.Now, Guid.NewGuid().ToString().Replace("-", "").Substring(0, 5).ToUpper());
            _logHelperUtil = new LogHelperUtil(logFlag);
        }
    
        public bool IsReusable
        {
            get { return false; }
        }
    
        public void ProcessRequest(HttpContext context)
        {
            context.Response.ContentType = "application/json"; 
    
            Stopwatch watch = new Stopwatch();
            string requestJson = string.Empty;
            watch.Start();
            try
            {
                using (var stream = new StreamReader(context.Request.InputStream))
                {
                    requestJson = stream.ReadToEnd();
                    if (string.IsNullOrEmpty(requestJson))
                    {
                        throw new ResponseErrorException("请求支付中心参数为空");
                    }
    
                    _logHelperUtil.WriteLog("请求支付中心参数:{0}", requestJson);
                    
                    //伪代码:验签
    
                    ResponseModelBase responseModel = MyBiz(requestJson);
                    _logHelperUtil.WriteLog("支付中心响应结果:{0}", JsonConvert.SerializeObject(responseModel));
                    
                    context.Response.Write(JsonConvert.SerializeObject(responseModel));
                    watch.Stop();
                    
                    //伪代码:记录本次请求的duration
                }
            }
            catch (Exception ex)
            {
                if (ex is ResponseErrorException)
                {
                    _logHelperUtil.WriteLog(ex.Message);
                }
                else
                {
                    _logHelperUtil.WriteLog("系统异常:{0}", ex.ToString());
                }
                var responseModel = new ResponseModelBase
                {
                    status = PayResponseConstant.Failed,
                    return_code = "1",
                    return_message = ex.Message,
                };
                context.Response.Write(JsonConvert.SerializeObject(responseModel));
                watch.Stop();
                
                //伪代码:记录本次请求的duration
            }
        }
    
        protected abstract ResponseModelBase MyBiz(string requestJson);
    }

    接下来说子类,即每个一般处理程序的.cs类的逻辑,职责当然就是重写MyBiz了,如下:

    上面所引用的QRCodeService类的构造器提供了logFlag参数,从而把这个LogFlag传递到Service层。 当然,我上文说的,另一种方式是借助属性来实现这个LogFlag的传递,我上一篇博客《多类继承情况下适应变化设计一例》里也有谈及LogFlag这方面的重构。

    这样编码后,就实现了统一标识日志记录了。

    我们每个人的认知都有他的局限性,在一次跟java组的云龙沟通中,我向他展示日志文件里井然有序的日志,他跟我说用线程号就可以实现,log4j里设置一下就实现了。 他这么一说线程,可以说是醍醐灌顶。于是,我也要利用Thread.CurrentThread.Name来实现。

    我大概的盘算了一下,要改用当前线程Name的方式的话,可以说web层、service层、渠道通信层里的每个类文件都要做变动。 我是喜欢接受这样重构挑战的,所以,在完成工作既定任务后,我终于鼓足勇气来做这次比较大的重构。 去掉构造器里的logFlag参数,不用的LogFlag属性也去掉。这样地给程序做了一次大的瘦身,代码整洁了不少。

    web层一般处理程序的基类HandlerBase.cs调整如下:

    public abstract class HandlerBase : IHttpHandler
    {
        protected readonly LogHelperUtil _LogHelperUtil;
        public HandlerBase()
        {
            Thread.CurrentThread.Name = string.Format("[{0}_{1:HHmmssfff}_{2}]", this.GetType().Name, DateTime.Now, Guid.NewGuid().ToString().Replace("-", "").Substring(0, 5).ToUpper());
            _LogHelperUtil = new LogHelperUtil();
        }
    
        ... ...
    
    }

     LogHelperUtil的变化不大,一是去掉了LOG_FLAG属性,一是取消了给字段_LOG_FLAG赋默认值,一是——最重要的——在记日志时加上当前线程名:

    public class LogHelperUtil
    {
        private readonly string _LOG_FLAG;
    
        //public string LOG_FLAG { get { return _LOG_FLAG; } }
    
        public LogHelperUtil(string log_flag = "")
        {
            _LOG_FLAG = log_flag;
            //if (string.IsNullOrEmpty(_LOG_FLAG))
            //    _LOG_FLAG = string.Format("[{0}LOG{1}]", DateTime.Now.ToString("HHmmssfff"), new Random().Next(9999));
    
        }
        public void WriteLog(string format, params object[] args)
        {
            LogHelper.Write(System.Threading.Thread.CurrentThread.Name + _LOG_FLAG + format, args);
        }
    }

    然而,要出事的节奏O(∩_∩)O~ O(∩_∩)O~ O(∩_∩)O~ ————

    发布到准生产环境,经过持续观察,发现,很多的日志都没有获取到当前线程名。很奇怪————

    ————两天前的夜晚打的这篇草稿该发布一下了,不能再拖延了,后续如何定位问题并解决问题,下回分解。

  • 相关阅读:
    LeetCode 32. 最长有效括号(Longest Valid Parentheses)
    LeetCode 141. 环形链表(Linked List Cycle)
    LeetCode 160. 相交链表(Intersection of Two Linked Lists)
    LeetCode 112. 路径总和(Path Sum)
    LeetCode 124. 二叉树中的最大路径和(Binary Tree Maximum Path Sum)
    LightGBM新特性总结
    sql service 事务与锁
    C#泛型实例详解
    C# 中的委托和事件(详解)
    C# DateTime日期格式化
  • 原文地址:https://www.cnblogs.com/buguge/p/7087353.html
Copyright © 2011-2022 走看看