关于MTK平台的短信故障分析

2019独角兽企业重金招聘Python工程师标准>>>

主要是log分析

关键字的搜索：

cmt

eimscmt

一些解惑

Dear sir
1、这个retry的机制是modem侧实现的吗？怎么触发这个机制，是在收不到网络发来的RP_ACK吗？
->modem实现的。12s内没有收到网络RP-ACK就会触发这个机制。 
2、从log如何判断设备进行这个retry机制，是看发送SMS__RP_DATA吗？如果是，那又如何
判断这个SMS__RP_DATA是这次发送失败的retry而不是又发起了一次新的发送短信呢？
->简单的判断可以看如下例子，如果RP-DATA是由AT+CMGS发起的是属于首次发起的，如果RP-DATA前面的log并没有AT+CMGS则属于modem重传的
Type    Index    Time    Local Time    Module    Message    Comment    Time Different
SYS    45833    34146    17:25:59:985    NIL    [AT_I p21, s11]AT+CMGS=92, "00210006816650910008525230592753856253542c6253542c6253542c76845b5850a88fc77a0b67516751901a4f207edf6eda6eda6eda6eda6eda6eda6eda560e560e560e560e70e670e670e670e670e670e653065306530653065306"
        
OTA    45910    34156    17:25:59:985    SMS    [MS->NW]: SMS__RP_DATA (smi=0)        
OTA    48452    34185    17:26:00:185    SMS    [MS->NW]: SMS__CP_DATA (smi=0)        
OTA    49685    34200    17:26:00:185    SMS    [NW->MS]: SMS__CP_ACK (smi=0)        
OTA    68268    36794    17:26:13:185    SMS    [MS->NW]: SMS__RP_DATA (smi=0)        
3、log中哪里显示 2G还没有建好connection？
->查看modem log中PS TRACE Peer窗口的OTA信令，如果在2G时没有发起Channel Reques的则代表当前没有建好连接，无法提供SMS服务。

之前的分析结果

Dear sir
在4G发送短信的期间进行CSFB call是会打断SMS的流程，UE切到2G后没有收到网络的CP-DATA，就会认为发送失败并且进行重选，而重传的时候由于2G还没有建好connection也就被直接reject掉，所以最后上报MO SMS fail，但网络可能会仍然把异常的SMS发送给对端，这属于网络问题，手机的处理流程是正常的。
Type    Index    Time    Local Time    Module    Message    Comment    Time Different
PS    752915    82237    17:30:00:470    SMSAL - SMS    MSG_ID_SMS_SUBMIT        
OTA    752919    82237    17:30:00:470    SMS    [MS->NW]: SMS__RP_DATA (smi=0)        
OTA    756005    82278    17:30:00:670    SMS    [MS->NW]: SMS__CP_DATA (smi=0)        
OTA    757920    82293    17:30:00:670    EMM_NASMSG    [MS->NW] EMM_Extended_Service_Request(service type="MO_CSFB", CSFB response="CSFB_UNUSED")        
OTA    758401    82298    17:30:00:670    SMS    [NW->MS]: SMS__CP_ACK (smi=0)        
OTA    758709    82300    17:30:00:670    ERRC_CONN    [NW->MS] ERRC_RRCConnectionRelease(cause:[ReleaseCause_other], redirectInfo:[1])        
OTA    762762    82549    17:30:02:070    SMS    [MS->NW]: SMS__RP_DATA (smi=0)    retry    
PS    762764    82549    17:30:02:070    SMS - MM    MSG_ID_MMSMS_EST_REQ        
PS    762768    82549    17:30:02:070    MM - SMS    MSG_ID_MMSMS_EST_REJ    CM_MM_RR_NO_SERVICE    
PS    762772    82549    17:30:02:070    SMS - SMSAL    MSG_ID_SMS_SUBMIT_REPORT_NACK

二、判断手机状态是否可收到短信

2、RRC三个步骤建立正常
[MS->NW] ERRC_RRCConnectionRequest
[NW->MS] ERRC_RRCConnectionSetup
[MS->NW] ERRC_RRCConnectionSetupComplete

3、这份log没有副卡，所有不会有该问题
假设有副卡也就是看OTA没有进行CS业务
4、没有做Attach和TAU，所以没有该问题
至于流程是否完整请查看24.301里面5.5章节关于Attach和TAU的流程图介绍

三、信号质量不好网络未回复cp_ack

发送此现象的原因是手机已将CP_DATA（包含短信内容）发送给网络，网络未回复CP_DATA,重发,网络未回复CP_ACK,导致短信发送失败，网络已收到CP_DATA,有可能将CP_DATA转发给接收端，所以接收端能收到短信。手机端流程处理正常，网络原因，请知悉!

435101, 0, 93784728, 16:48:48:201 2016/12/30, MOD_SMSAL, MOD_SMS, MNSMS_SAP, MSG_ID_SMS_SUBMIT
437320, 0, 93786994, 16:48:48:201 2016/12/30, MOD_SMS, , TRACE_PEER, [MS->NW] [MO] SMS__CP_DATA (ti=1)
438160, 0, 93788190, 16:48:48:401 2016/12/30, MOD_SMS, , TRACE_PEER, [NW->MS] [MO] SMS__CP_ACK (ti=1)
438160, 0, 93788190, 16:48:48:401 2016/12/30, MOD_SMS, , TRACE_PEER, [NW->MS] [MO] SMS__CP_ACK (ti=1)
458528, 0, 93864754, 16:48:53:252 2016/12/30, MOD_SMS, , TRACE_PEER, [MS->NW] [MO] SMS__RP_DATA (rl_id=0)
460851, 0, 93867259, 16:48:53:452 2016/12/30, MOD_SMS, , TRACE_PEER, [MS->NW] [MO] SMS__CP_DATA (ti=2)
479798, 0, 93944285, 16:48:58:406 2016/12/30, MOD_SMS, MOD_SMSAL, MNSMS_SAP, MSG_ID_SMS_SUBMIT_REPORT_NACK
 

ECSQ: 15,25,1,1,1,-49,-464,7,17,38 看第1个参数和第7个参数。 第一个参数asu>20表示信号质量比较好。 第7个参数-464= -116<-95 强度也不是很好。
当前信号质量不是很好。
434921, 0, 93722645, 16:48:44:262 2016/12/30, MOD_NIL, , TRACE_INFO, [AT_R p20, s9]+ECSQ: 16,24,1,1,1,-47,-467,7,15,38
461837, 0, 93869352, 16:48:53:652 2016/12/30, MOD_NIL, , TRACE_INFO, [AT_U p19, s8]+ECSQ: 18,24,1,1,1,-44,-466,7,21,38

三、TIO不一致的问题

网络有点异常，@10:43:17发送的SMS没有收到网络的RP-ACK，之后UE进行重传但是网络返回的RP-ACK带的TIO和UE发送不一样，也就是TIO unsync，这种情况是把它丢弃掉所以UE会上报SMS fail，而网络没有处理好这种异常的SMS流程仍然把SMS发送给对端。
这属于网络临时问题，手机处理流程正常。
Type    Index    Time    Local Time    Module    Message    Comment    Time Different
SYS (PCORE)    618494    4619233    10:43:17:075    NIL    [AT_I p22, s11]AT+CMGS=16, "0001000681665048000806540c8c0b4e86"
PS (PCORE)    618736    4619782    10:43:17:275    SMSAL - SMS    MSG_ID_SMS_SUBMIT
OTA (PCORE)    618738    4619784    10:43:17:275    SMS    [MS->NW] [MO] SMS__RP_DATA (rl_id=1)
OTA (PCORE)    618760    4619788    10:43:17:275    SMS    [MS->NW] [MO] SMS__CP_DATA (ti=1)    .001 .... = TIO: 1
OTA (PCORE)    619101    4620889    10:43:17:275    SMS    [NW->MS] [MO] SMS__CP_ACK (ti=1)
OTA (PCORE)    645114    4707446    10:43:22:755    ERRC_CONN    [NW->MS] ERRC_RRCConnectionRelease(cause:[ReleaseCause_other], redirectInfo:[0])
OTA (PCORE)    647395    4708551    10:43:22:955    SMS    [MS->NW] [MO] SMS__RP_DATA (rl_id=0)
OTA (PCORE)    649748    4710804    10:43:22:955    SMS    [MS->NW] [MO] SMS__CP_DATA (ti=2)
OTA (PCORE)    649785    4710808    10:43:22:955    EMM_NASMSG    [MS->NW] EMM_Uplink_NAS_Transport    .010 .... = TIO: 2
OTA (PCORE)    650491    4711746    10:43:23:155    EMM_NASMSG    [NW->MS] EMM_Downlink_NAS_Transport    .001 .... = TIO: 1
PS (PCORE)    650501    4711748    10:43:23:155    SMS    SMS: sms_find_cm_id_by_ti error: ti=1
OTA (PCORE)    652168    4717669    10:43:23:387    EMM_NASMSG    [NW->MS] EMM_Downlink_NAS_Transport    .001 .... = TIO: 1
PS (PCORE)    652178    4717670    10:43:23:387    SMS    SMS: sms_find_cm_id_by_ti error: ti=1
OTA (PCORE)    670222    4787696    10:43:27:875    ERRC_CONN    [NW->MS] ERRC_RRCConnectionRelease(cause:[ReleaseCause_other], redirectInfo:[0])
PS (PCORE)    670750    4787923    10:43:27:875    SMS    SMS:[RL_FSM]rl_id=0 , RL_FSM_SMCP_ERR_IND
PS (PCORE)    670754    4787924    10:43:27:875    SMS - SMSAL    MSG_ID_SMS_SUBMIT_REPORT_NACK
PS (PCORE)    793499    5614474    10:44:20:903    SMSAL - SMS    MSG_ID_SMS_SUBMIT
OTA (PCORE)    793501    5614476    10:44:20:903    SMS    [MS->NW] [MO] SMS__RP_DATA (rl_id=0)
OTA (PCORE)    795738    5616646    10:44:20:903    SMS    [MS->NW] [MO] SMS__CP_DATA (ti=3)
OTA (PCORE)    796518    5618041    10:44:21:111    SMS    [NW->MS] [MO] SMS__CP_ACK (ti=3)
OTA (PCORE)    815837    5693644    10:44:25:859    ERRC_CONN    [NW->MS] ERRC_RRCConnectionRelease(cause:[ReleaseCause_other], redirectInfo:[0])
OTA (PCORE)    818201    5694802    10:44:26:059    SMS    [MS->NW] [MO] SMS__RP_DATA (rl_id=0)
OTA (PCORE)    820547    5697863    10:44:26:264    SMS    [MS->NW] [MO] SMS__CP_DATA (ti=4)
OTA (PCORE)    820584    5697866    10:44:26:264    EMM_NASMSG    [MS->NW] EMM_Uplink_NAS_Transport    .100 .... = TIO: 4
OTA (PCORE)    821289    5698587    10:44:26:264    EMM_NASMSG    [NW->MS] EMM_Downlink_NAS_Transport    .011 .... = TIO: 3
OTA (PCORE)    821541    5700039    10:44:26:264    EMM_NASMSG    [NW->MS] EMM_Downlink_NAS_Transport    .011 .... = TIO: 3
PS (PCORE)    840471    5774885    10:44:31:176    SMS - SMSAL    MSG_ID_SMS_SUBMIT_REPORT_NACK
PS (PCORE)    874563    6065388    10:44:49:749    SMSAL - SMS    MSG_ID_SMS_SUBMIT
PS (PCORE)    922668    6235199    10:45:00:502    SMS - SMSAL    MSG_ID_SMS_SUBMIT_REPORT_NACK

四、4G小区切换的情况下很容易收不到网络端的RP_ACK

在关机前REF收到的5页长短信是连续发送过来，而DUT只收到其中两条，@10:13:07:800网络让DUT做切换，之后新的cell并没有给发送剩余的SMS，这是网络问题，应该是基站并没有很好处理好收短信遇到切换的场景。
DUT:
Type    Index    Time    Local Time    Module    Message    Comment    Time Different
OTA (PCORE)    37469    938890    10:13:06:577    SMS    [NW->MS] [MT] SMS__CP_DATA (ti=14)    Message part number: 3    
OTA (PCORE)    37470    938890    10:13:06:577    SMS    [MS->NW] [MT] SMS__CP_ACK (ti=14)        
PS (PCORE)    37539    938899    10:13:06:577    SMS - SMSAL    MSG_ID_SMS_DELIVER        
PS (PCORE)    37889    940294    10:13:06:577    SMSAL - SMS    MSG_ID_SMS_DELIVER_REPORT_ACK        
OTA (PCORE)    37893    940295    10:13:06:577    SMS    [MS->NW] [MT] SMS__CP_DATA (ti=14)        
OTA (PCORE)    38316    941463    10:13:06:798    SMS    [NW->MS] [MT] SMS__CP_ACK (ti=14)        
OTA (PCORE)    41349    953511    10:13:07:600    SMS    [NW->MS] [MT] SMS__CP_DATA (ti=14)    Message part number: 1    
PS (PCORE)    41419    953520    10:13:07:600    SMS - SMSAL    MSG_ID_SMS_DELIVER        
PS (PCORE)    41676    954451    10:13:07:600    SMSAL - SMS    MSG_ID_SMS_DELIVER_REPORT_ACK        
PS (PCORE)    42645    957993    10:13:07:800    ERRC_MOB    [RPT] A4 enter condition pci[395] (mn[-390]+ofn[0]+ocn[0]-hys[4])=-394 > thresh[-404] rslt=1        
OTA (PCORE)    42656    957994    10:13:07:800    ERRC_MOB    [MS->NW] ERRC_MeasurementReport[9] eventA4 ncell[38400/395] rslt[-390][-17]        
OTA (PCORE)    42914    958943    10:13:07:800    ERRC_CONN    [NW->MS] ERRC_RRCConnectionReconfiguration(measCfg:[0],mobCtrlInfo:[1],dedInfoNASList:[0],radioresCfgDed:[1],secCfgHO:[1])        
OTA (PCORE)    48374    966699    10:13:08:420    ERRC_MOB    [MS->NW] ERRC_MeasurementReport[18] eventA2 pcell[38400/395] rslt[-393][-26]        
OTA (PCORE)    59148    1037165    10:13:12:900    ERRC_CONN    [NW->MS] ERRC_RRCConnectionRelease(cause:[ReleaseCause_other], redirectInfo:[0])        

如何从mdlog看出来接收的信息对应哪张SIM卡。
打开mdlog之后，搜索SMSAL，可以找到MSG_ID_SMS_DELIVER 这样的数据（这是接收短信）
Source和Destination列就是module名称。比如：SMS、SMSAL 这样指的就是卡1
SMS_2, SMSAL_2 指的就是卡2

例如这份log:中批-1-600-w29-log3-10.14@mdlog1@MDLog1_2017_0507_101802 看到的
5488, 0, 1239252, 10:18:40:667 2017/05/07, MOD_SMS, MOD_SMSAL, MNSMS_SAP, MSG_ID_SMS_DELIVER
这就可以看出来是卡1接收了短信。
 

转载于:https://my.oschina.net/u/2829875/blog/822149