AutoMapper.Mapper.CreateMap報“System.NullReferenceException: 未將對象引用設置到對象的實例。”異常復現
Ⅰ.問題出現
國慶假期期間——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過來一份。 運維告知處理完畢後,問題未再復現。
此後的幾天,線上也沒有再發生類似事故。我也因此認為是文件版本問題所致,就不再關註。
Ⅱ.異常再次出現
誰知,就在上周末的兩天,這個異常又出現了,還是出現在9177節點。
那這回,就不能理解了。文件版本應該是一致了呀。
迅速聯系運維,幫忙回收一下站點的應用程序池。
誰知回收完後,問題依舊。
咨詢運維,為什麽只有這個節點報這個異常,運維披露10月5號也並未copy文件,只是重啟了一下iis。
那只好應急讓運維再重啟一下iis了。 此事暫時平息。
Ⅲ.排障
為了可以消停地過下個周末,決定今天把這個問題根治一下。
大家初步的分析是,AutoMapper.Mapper.CreateMap是靜態方法,多線程時可能會出現問題。
我也一直知道,AutoMapper建議把映射關系在程序啟動時做一次性初始化,而非在每次轉換對象時都做初始化。
我當時在用AutoMapper時,也並未重視這一點。就寫成了每次都是先創建映射接著轉換對象。
欠下的賬總是要還的。 系統此前沒出現這樣的異常,只能說時間不到。
就像墨菲定理說的,該發生的事情總會發生。 這不,不早不晚,就在國慶節和上周末兩個節假日出現了。
Ⅳ.異常復盤
有必要復現一下那個異常。當然,小概率問題,並不容易測出來。
好在,我有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分鐘。
過程中,
- 重新覆蓋了一下站點的文件,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次。
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壓測截圖:
AutoMapper.Mapper.CreateMap報“System.NullReferenceException: 未將對象引用設置到對象的實例。”異常復現