• AutoMapper.Mapper.CreateMap报“System.NullReferenceException: 未将对象引用设置到对象的实例。”异常复现


    >>Agenda:

    >>Ⅰ.国庆假期问题出现

    >>Ⅱ.双休日异常再次出现

    >>Ⅲ.排障

    >>Ⅳ.异常复盘

    >>Ⅴ.修复后监测

    >>Ⅵ.结束

    Ⅰ.国庆假期问题出现TOP

    国庆假期期间——10月5号——发现支付中心频繁报异常“System.NullReferenceException: 未将对象引用设置到对象的实例。”,通过分析异常堆栈信息,代码出现在QRCodeService的GetQRCode方法里如下第8行代码:

     1 /// <summary>
     2 /// 扫码支付 获取支付码
     3 /// </summary>
     4 /// <param name="reqModel"></param>
     5 /// <returns></returns>
     6 public ResponseModelBase GetQRCode(QRCodeRequestModel reqModel)
     7 {
     8     AutoMapper.Mapper.CreateMap<QRCodeRequestModel, QRCodeRequestDTO>();
     9     var reqDto = AutoMapper.Mapper.Map<QRCodeRequestDTO>(reqModel);
    10     if (reqDto.valid_minutes == 0)
    11     {
    12         reqDto.valid_minutes = 20;//默认设置为20分钟
    13     }
    14 
    15     if (string.IsNullOrEmpty(reqModel.order_no))
    16     {
    17         throw new ResponseErrorException("未获取订单ID,请重新检查订单信息");
    18     }
    19     if (reqModel.pay_money <= 0)
    20     {
    21         throw new ResponseErrorException("订单价格有误,请重新验证该订单");
    22     }
    23     if (string.IsNullOrEmpty(reqModel.goods_name))
    24     ......
    25     ......
    26 }

    异常日志:

     1 2017/10/5 14:03:40    [GetQRCode_140340241_DCB85]请求支付中心参数:{"biz_system":"5","goods_name":"W17720171005140403733142/qdrpayment3577421317952512T/","merchant_id":"102573307097-102125439412","notify_url":"http://papi1.shenbianhui.cn//OrderPayBack/BackResult","order_no":"DD2017100500470030","order_time":"20171005140340","pay_channel":"12","pay_money":"30000","remark":"","return_url":"http://120.55.16.195/pay/returnYimeiCallBack.do","sign":"de101b203758cbbe7f83ce04f20d6fb1","third_pay_platform":"61","valid_minutes":"10"}
     2 2017/10/5 14:03:40    [GetQRCode_140340241_DCB85]支付中心验签通过。
     3 2017/10/5 14:03:40    [GetQRCode_140340241_DCB85]获取二维码进入
     4 2017/10/5 14:03:40    [GetQRCode_140340241_DCB85]系统异常:System.NullReferenceException: 未将对象引用设置到对象的实例。
     5    在 AutoMapper.TypeMapFactory.<>c__DisplayClass3_0.<MapDestinationPropertyToSource>b__0(IMemberConfiguration _)
     6    在 System.Linq.Enumerable.Any[TSource](IEnumerable`1 source, Func`2 predicate)
     7    在 AutoMapper.TypeMapFactory.CreateTypeMap(Type sourceType, Type destinationType, IProfileConfiguration options, MemberList memberList)
     8    在 AutoMapper.ConfigurationStore.<>c__DisplayClass80_0.<CreateTypeMap>b__0(TypePair tp)
     9    在 System.Collections.Concurrent.ConcurrentDictionary`2.GetOrAdd(TKey key, Func`2 valueFactory)
    10    在 AutoMapper.ConfigurationStore.CreateMap[TSource,TDestination](String profileName, MemberList memberList)
    11    在 PaymentService.QRCodeService.GetQRCode(QRCodeRequestModel reqModel)
    12    在 PaymentPlatform.QRCode.GetQRCode.MyBiz(String requestJson)
    13    在 PaymentPlatform.QRCode.HandlerBase.ProcessRequest(HttpContext context)

    从第9行有ConcurrentDictionary,难不成是并发导致的?当时系统TPS并发在50以上。

    系统运行数月来,以前从未遇到这样的问题呢。

    进一步排查,这个异常出现之后,后面所有对这个接口的请求处理都报这个异常。另外,三个负载节点中,只有其中的9177节点接连报这个异常。

    直觉怀疑,随着线上每周一两次的发版,会不会是3个节点AutoMapper.DLL版本不一致呢。为了将影响减到最低,紧急联系运维,将9177节点的站点文件删掉,从其他节点copy过来一份。 运维告知处理完毕后,问题未再复现。

    此后的几天,线上也没有再发生类似事故。我也因此认为是文件版本问题所致,就不再关注。

    Ⅱ.双休日异常再次出现TOP

    谁知,就在上周末的两天,这个异常又出现了,还是出现在9177节点。

    那这回,就不能理解了。文件版本应该是一致了呀。

    迅速联系运维,帮忙回收一下站点的应用程序池。

    谁知回收完后,问题依旧。

    咨询运维,为什么只有这个节点报这个异常,运维披露10月5号也并未copy文件,只是重启了一下iis。

    那只好应急让运维再重启一下iis了。 此事暂时平息。

    Ⅲ.排障TOP

    为了可以消停地过下个周末,决定今天把这个问题根治一下。

    大家初步的分析是,AutoMapper.Mapper.CreateMap是静态方法,多线程时可能会出现问题。

    其实我也一直知道,AutoMapper建议把映射关系在程序启动时做一次性初始化,而非在每次转换对象时都做初始化。

    只不过我当时在用AutoMapper时,并未重视这一点。就写成了每次都是先创建映射接着转换对象。

    欠下的账总是要还的。 系统此前没出现这样的异常,只能说时间不到。

    就像墨菲定理说的,该发生的事情总会发生。 这不,不早不晚,就在国庆节和上周末两个节假日出现了。

    Ⅳ.异常复盘TOP

    有必要复现一下那个异常。当然,小概率问题,并不容易测出来。

    好在,我有JMeter。

    在项目里新建了AutoMapperTest.ashx文件,ProcessRequest方法体如下:

    public void ProcessRequest(HttpContext context)
    {
        context.Response.ContentType = "text/plain";
        
        LogHelperUtil logHelper = new LogHelperUtil("", LogType.HFAgentPayService);
        LogHelper.Write("[AutoMapperTest]");
        
        Thread.Sleep(new Random().Next(1, 100));
        
        try
        {
            QRCodeRequestModel reqModel = new QRCodeRequestModel();
    
            AutoMapper.Mapper.CreateMap<QRCodeRequestModel, QRCodeRequestDTO>();
            var reqDto = AutoMapper.Mapper.Map<QRCodeRequestDTO>(reqModel);
    
            Thread.Sleep(new Random().Next(100, 1000));
            context.Response.Write(JsonConvert.SerializeObject(reqDto));
        }
        catch (Exception ex)
        {
            logHelper.Write("[AutoMapperTestException]" + ex.ToString());
            context.Response.Write(ex.ToString());
        }
    }

    发布到测试环境。

    接下来,创建JMeter的测试计划,模拟1000个线程数来压测这个ashx。

    持续执行了20分钟。

    过程中,如下两件事,使得那个诡异的bug终于从洞里钻出来了:

    • 重新覆盖了一下站点的文件,AutoMapper.Mapper.CreateMap语句出现如下异常,在11:08:08这一秒出现了160次。
    2017/10/17 11:08:08	[AutoMapperTestException]System.InvalidOperationException: 集合已修改;可能无法执行枚举操作。
       在 System.Collections.Generic.List`1.Enumerator.MoveNextRare()
       在 System.Linq.Enumerable.Any[TSource](IEnumerable`1 source, Func`2 predicate)
       在 AutoMapper.TypeMapFactory.CreateTypeMap(Type sourceType, Type destinationType, IProfileConfiguration options, MemberList memberList)
       在 AutoMapper.ConfigurationStore.<>c__DisplayClass80_0.<CreateTypeMap>b__0(TypePair tp)
       在 System.Collections.Concurrent.ConcurrentDictionary`2.GetOrAdd(TKey key, Func`2 valueFactory)
       在 AutoMapper.ConfigurationStore.CreateMap[TSource,TDestination](String profileName, MemberList memberList)
       在 PaymentPlatform.Test.AutoMapperTest.ProcessRequest(HttpContext context)
    • 中午找运维手动回收了一下应用程序池,AutoMapper.Mapper.CreateMap语句出现如下异常,和节假日出现的异常一样!这个异常在12:02:04~12:03:17之间出现了43351次。   默认情况下,iis会在每间隔固定时间29小时回收appPool,如果此时正好有许多请求在访问此接口,那么必然也会引发AutoMapper的这个异常。这大概就能解释为什么线上出现这个bug了。
    2017/10/17 12:02:04	[AutoMapperTestException]System.NullReferenceException: 未将对象引用设置到对象的实例。
       在 AutoMapper.TypeMapFactory.<>c__DisplayClass3_0.<MapDestinationPropertyToSource>b__0(IMemberConfiguration _)
       在 System.Linq.Enumerable.Any[TSource](IEnumerable`1 source, Func`2 predicate)
       在 AutoMapper.TypeMapFactory.CreateTypeMap(Type sourceType, Type destinationType, IProfileConfiguration options, MemberList memberList)
       在 AutoMapper.ConfigurationStore.<>c__DisplayClass80_0.<CreateTypeMap>b__0(TypePair tp)
       在 System.Collections.Concurrent.ConcurrentDictionary`2.GetOrAdd(TKey key, Func`2 valueFactory)
       在 AutoMapper.ConfigurationStore.CreateMap[TSource,TDestination](String profileName, MemberList memberList)
       在 PaymentPlatform.Test.AutoMapperTest.ProcessRequest(HttpContext context)

    贴上JMeter压测截图:

     贴上IIS应用程序池的回收配置:

    Ⅴ.修复后监测TOP

    正如第《Ⅲ.排障》节所说,解决方案就是在全局的Application_Start时,定义所有的AutoMapper类型映射。这样,就保证了映射关系的一次性初始化。后续代码不需再定义,只关注对象转换就可以了。

    发布到测试环境。

    再次启动JMeter测试计划,14分钟内,无论在压测过程中更新文件,还是回收站点应用程序池,都未出现那些并发请求所带来的AutoMapper创建类型映射的异常。

    Ⅵ.结束 TOP

    再次强调,你应该尽量统一管理AutoMapper的映射定义并且只做一次性初始化。

    在博客园的一篇AutoMapper的《AutoMapper 最佳实践》文章中介绍:

    虽然AutoMapper并不强制要求在程序启动时一次性提供所有配置,但是这样做有如下好处:
    a) 可以在程序启动时对所有的配置进行严格的验证(后文详述)。
    b) 可以统一指定DTO向Entity映射时的通用行为(后文详述)。
    c) 逻辑内聚:新增配置时方便模仿以前写过的配置;对项目中一共有多少DTO以及它们与实体的映射关系也容易有直观的把握。

  • 相关阅读:
    memcached事故
    总算会用sphinx生成文档了
    python tip
    抓包工具wireshark
    狗日的用户体验
    python tip
    pymmseg
    memcached事故
    windwos序列号
    7z fromat on ubuntu&replace my fujishu electric fan
  • 原文地址:https://www.cnblogs.com/buguge/p/7682095.html
Copyright © 2020-2023  润新知