主要是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接收了短信。