通話故障總結

通常分析方法;網絡

AT層須要搜下以下命令:app

ATD+numberdom

AT+CHUPide

AT+ESRVCC測試

+ECPIfetch

+ESIPCPIui

AT+CLCCthis

Modem層的分析方法:spa

對於這種通話自動掛斷問題,首先得肯定CC流程是否完整。debug

若是CC流程不完整,就須要查看它的承載RR層

//這個流程就是通話的大體流程。setup就是發起通話.
OTA (PCORE)    1125225    738141903    11:20:39:844    CC    [NW->MS] CC__SETUP        
OTA (PCORE)    1125419    738142144    11:20:39:844    CC    [MS->NW] CC__CALL_CONFIRMED        
OTA (PCORE)    1125725    738153299    11:20:40:550    RRM_TDD    [MS->NW] RR__MEASUREMENT_REPORT        
OTA (PCORE)    1125765    738156615    11:20:40:786    RRM_TDD    [NW->MS] RR__ASSIGNMENT_COMMAND        
//到alerting,就是鈴聲開始響
OTA (PCORE)    1125854    738159798    11:20:40:990    CC    [MS->NW] CC__ALERTING        
OTA (PCORE)    1126976    738231482    11:20:45:513    RRM_TDD    [MS->NW] RR__MEASUREMENT_REPORT        
//這裏connect接通
OTA (PCORE)    1127489    738270247    11:20:47:977    CC    [MS->NW] CC__CONNECT        
OTA (PCORE)    1127668    738277273    11:20:48:393    CC    [NW->MS] CC__CONNECT_ACKNOWLEDGE        
OTA (PCORE)    1137630    738313973    11:20:50:833    RRM_TDD    [MS->NW] RR__MEASUREMENT_REPORT    
//掛斷,釋放CC鏈接    
OTA (PCORE)    1139853    738331359    11:20:51:839    CC    [NW->MS] CC__DISCONNECT        
OTA (PCORE)    1139870    738331362    11:20:51:839    CC    [MS->NW] CC__RELEASE        
OTA (PCORE)    1140312    738335109    11:20:52:039    CC    [NW->MS] CC__RELEASE_COMPLETE        
//釋放CC鏈接的承載RR鏈接
OTA (PCORE)    1140996    738336982    11:20:52:239    RRM_TDD    [NW->MS] RR__CHANNEL_RELEASE        

若是CC流程完整,可是報告是自動掛斷,那麼就看網絡是否下發了 CC__DISCONNECT 或者RR__CHANNEL_RELEASE,若是有,就說明可能網絡或者對端的問題。
若是CC流程不完整,沒有下發CC__DISCONNECT 或者RR__CHANNEL_RELEASE,那麼就說明是RR鏈接中斷了,須要在通話中斷的地方(RR__MEASUREMENT_REPORT再也不出現的附近)
來查看RR層哪裏出現了問題。
通常如下兩種狀況比較常見:
//N200 錯誤
PS    547587    839036    15:32:11:525    LISR2HISR_CTIRQ1 - RRM_2    MSG_ID_LAPDM_RR_REL_IND    N200 error    
//RLF 錯誤
PS    850942    752647    15:36:22:230    L1_2 - RRM_2    MSG_ID_LAPDM_RR_ERROR_IND    raido link failure    

這兩種一般都是由信號質量差致使的,信號質量須要查看
547310, 917659, 838713, 15:32:09:725 2017/02/06, MOD_MPAL_2, MOD_RRM_2, RRM_MPAL_SAP, MSG_ID_MPAL_RR_SERV_DEDI_MEAS_IND

    Local_Parameter --> Len = 32, Addr = 0xF259BA8C
        mpal_rr_serv_dedi_meas_ind_struct = (struct)
            ref_count = 0x01
            lp_reserved = 0xf2
            msg_len = 0x0020
            rlac_full_in_quarter_dbm = 0xfe64
            rlac_sub_in_quarter_dbm = 0xfe65 //信號強度不該小於-105
            rxqual_full_avg = 0x07
            rxqual_sub_avg = 0x05 //信號質量不該小於-4
 

接通和掛斷的時間點()

一、MO未接通自動掛掉

在modem log中看到

[MS->NW] MM__CM_SERVICE_REQUEST
[MS->NW] RR__CHANNEL_REQUEST
[MS->NW] RR__CHANNEL_REQUEST
[NW->MS] RR__SI_2TER (ARFCN[60], TC[5])
[NW->MS] RR__IMMEDIATE_ASSIGNMENT
[NW->MS] RR__SI_6 (ARFCN[60], TC[255])
[MS->NW] RR__CLASSMARK_CHANGE
[NW->MS] MM__ABORT
[MS->NW] RR__MEASUREMENT_REPORT
[NW->MS] RR__CHANNEL_RELEASE

MM_ABORT在協議TS 24.008 4.3.5中

二、接到來電,未接聽自動掛斷的

從log看測試機和配合機都是收到了網絡發來的disconnect命令,掛斷case都爲爲44 requested circuit/channel not available,未網絡故障。
測試機:
398601, 0, 330658970, 14:47:47:752 2017/01/09, MOD_CC, , TRACE_PEER, [NW->MS] CC_DISCONNECT
398616, 0, 330658973, 14:47:47:752 2017/01/09, MOD_CC, , TRACE_PEER, [MS->NW] CC
RELEASE
398939, 0, 330662434, 14:47:47:960 2017/01/09, MOD_CC, , TRACE_PEER, [NW->MS] CC
RELEASE_COMPLETE
配合機:
374430, 0, 329598595, 14:47:48:782 2017/01/09, MOD_CC, , TRACE_PEER, [NW->MS] CC
DISCONNECT
374446, 0, 329598598, 14:47:48:782 2017/01/09, MOD_CC, , TRACE_PEER, [MS->NW] CC
RELEASE
374770, 0, 329605952, 14:47:49:386 2017/01/09, MOD
CC, , TRACE_PEER, [NW->MS] CC__RELEASE_COMPLETE

三、關於mtk平臺SRVCC的log實例

Hi sir
從log看來,手機帶的SRVCC的能力都是正常的,手機SRVCC 都是成功的,可是SRVCC 成功後網絡每次都下發了CC disconnect,應該是網絡問題,建議和對比機多作下對比測試,謝謝



Type    Index    Time    Local Time    Module    Message    Comment    Time Different
SYS    2241900    1942053    16:52:20:105    NIL    [AT_I p20, s10]ATD13903022925;
        
SYS    2765855    1950976    16:53:04:575    NIL    [AT_I p20, s10]ATD13903022925;
        
SYS    3095384    1954764    16:53:23:575    NIL    [IMSP_AT_I s21]AT+ESRVCCTFR=1,1,0,0,2,0,2,"13903022925",,        
SYS    3095418    1954764    16:53:23:575    NIL    [IMSP_AT_R s21]+ESRVCCTFR: 1, 1        
SYS    3240633    1972861    16:54:54:155    NIL    [AT_I p20, s10]ATD13903022925;
        
OTA    3491911    1976931    16:55:14:355    ERRC_CONN    [NW->MS] ERRC_MobilityFromEUTRACommand(CSFB:[0],purpose:[MobilityFromEUTRACommand_r8_IEs_purpose_handover_selected],targetRAT:[Handover_targetRAT_Type_geran])        
OTA    3492866    1976957    16:55:14:580    RRM    [NW->MS] RR__PHYSICAL_INFORMATION        
OTA    3492870    1976957    16:55:14:580    RRM    [MS->NW] RR__HANDOVER_COMPLETE        
SYS    3494267    1976983    16:55:14:780    NIL    [IMSP_AT_I s21]AT+ESRVCCTFR=1,1,0,0,3,0,2,"13903022925",,        
SYS    3494288    1976983    16:55:14:780    NIL    [IMSP_AT_R s21]+ESRVCCTFR: 1, 1        
OTA    3496629    1977026    16:55:14:980    CC    [NW->MS] CC__DISCONNECT        
OTA    3496642    1977026    16:55:14:980    CC    [MS->NW] CC__RELEASE        
OTA    3497024    1977105    16:55:15:380    CC    [NW->MS] CC__RELEASE_COMPLETE        
SYS    3605943    1979077    16:55:25:200    NIL    [AT_I p20, s10]ATD13903022925;
        
OTA    3609752    1979134    16:55:25:400    ESM    [NW->MS] ESM_MSG_ACTIVATE_DEDICATED_EPS_BEARER_CONTEXT_REQUEST (PTI:0, EBI:7)        
OTA    3609969    1979134    16:55:25:400    ESM    [MS->NW] ESM_MSG_ACTIVATE_DEDICATED_EPS_BEARER_CONTEXT_ACCEPT (PTI:0, EBI:7)        
OTA    3627337    1979420    16:55:26:800    ESM    [NW->MS] ESM_MSG_MODIFY_EPS_BEARER_CONTEXT_REQUEST (PTI:0, EBI:7)        
OTA    3627556    1979420    16:55:26:800    ESM    [MS->NW] ESM_MSG_MODIFY_EPS_BEARER_CONTEXT_ACCEPT (PTI:0, EBI:7)        
SYS    4177787    1996523    16:56:52:365    NIL    [AT_I p20, s10]ATD13903022925;
        
SIP    139        16:57:10:522        [MS->NW]INVITE sip:[2409:8019:8430:4500:0000:0000:0000:0008]:9900;Hpt=8fa2_16;CxtId=3;TRC=ffffffff-ffffffff SIP/2.0        
SIP    140        16:57:10:689        [NW->MS]SIP/2.0 100 Trying        
SIP    141        16:57:11:212        [NW->MS]SIP/2.0 200 OK        
SIP    142        16:57:11:245        [MS->NW]ACK sip:[2409:8019:8430:4500:0000:0000:0000:0008]:9900;Hpt=8fa2_16;CxtId=3;TRC=ffffffff-ffffffff SIP/2.0        
OTA    4547843    2000758    16:57:13:565    ERRC_CONN    [NW->MS] ERRC_MobilityFromEUTRACommand(CSFB:[0],purpose:[MobilityFromEUTRACommand_r8_IEs_purpose_handover_selected],targetRAT:[Handover_targetRAT_Type_geran])        
SYS    4550218    2000803    16:57:13:765    NIL    [IMSP_AT_I s21]AT+ESRVCCTFR=1,1,0,0,3,0,2,"13903022925",,        
SYS    4550239    2000803    16:57:13:765    NIL    [IMSP_AT_R s21]+ESRVCCTFR: 1, 1        
OTA    4552643    2000842    16:57:13:965    RRM    [MS->NW] RR__MEASUREMENT_REPORT        
OTA    4552688    2000845    16:57:13:965    CC    [NW->MS] CC__DISCONNECT        
SIP    143        16:57:17:039        [NW->MS]BYE sip:+8613903029925@[2409:8809:84F0:136D:CF50:041A:F6BE:D958]:50001 SIP/2.0        
SYS    4742879    2004164    16:57:30:570    NIL    [AT_I p20, s10]ATD13903022925;
        
OTA    5051207    2007543    16:57:47:570    ERRC_CONN    [NW->MS] ERRC_MobilityFromEUTRACommand(CSFB:[0],purpose:[MobilityFromEUTRACommand_r8_IEs_purpose_handover_selected],targetRAT:[Handover_targetRAT_Type_geran])        
OTA    5052151    2007569    16:57:47:570    RRM    [NW->MS] RR__PHYSICAL_INFORMATION        
OTA    5052155    2007569    16:57:47:570    RRM    [MS->NW] RR__HANDOVER_COMPLETE        
SYS    5053538    2007595    16:57:47:775    NIL    [IMSP_AT_I s21]AT+ESRVCCTFR=1,1,0,0,3,0,2,"13903022925",,        
SYS    5053559    2007595    16:57:47:775    NIL    [IMSP_AT_R s21]+ESRVCCTFR: 1, 1        
OTA    5056032    2007641    16:57:47:975    CC    [NW->MS] CC__DISCONNECT        
OTA    5056045    2007641    16:57:47:975    CC    [MS->NW] CC__RELEASE        

From: <sip:+8613903029925@gd.ims.mnc000.mcc460.3gppnetwork.org>;tag=qaeKX9Y5TSH813
To: <tel:13903022925;phone-context=ims.mnc000.mcc460.3gppnetwork.org>;tag=y2454z3k
CSeq: 44 INVITE
Allow: INVITE,ACK,CANCEL,BYE,UPDATE,REFER,NOTIFY,MESSAGE,PRACK,OPTIONS
Contact: <sip:[2409:8019:8430:4500:0000:0000:0000:0008]:9900;Hpt=8fa2_16;CxtId=3;TRC=ffffffff-ffffffff>;+g.3gpp.icsi-ref="urn%3Aurn-7%3A3gpp-service.ims.icsi.mmtel"
Require: precondition,100rel
User-Agent: VoLTE/WFC UA
RSeq: 1
P-Early-Media: gated
Feature-Caps: *;+g.3gpp.srvcc;+g.3gpp.mid-call;+g.3gpp.srvcc-alerting
Recv-Info: g.3gpp.state-and-event-info
Content-Length: 547
Content-Type: application/sdp

v=0

四、能夠查看cs的鏈接狀態

自動掛斷是因爲在手機發出[MS->NW] CC__CONNECT,網絡尚未迴應CC__CONNECT_ACKNOWLEDGE的狀況下發生的,請問此問題的復現機率多大,請在同一地點一樣的時刻作對比機測試,同時觀察復現率
Type    Index    Time    Local Time    Module    Message    Comment    Time Different
OTA (PCORE)    221930    8071266    08:29:37:055    EMM_NASMSG    [NW->MS] EMM_CS_Service_Notification(paging identity="TMSI_PAGING_TYPE")        
OTA (PCORE)    225351    8082440    08:29:37:626    RRM_TDD    [MS->NW] RR__PAGING_RESPONSE        
OTA (PCORE)    228739    8118606    08:29:40:125    CC    [NW->MS] CC__SETUP        
OTA (PCORE)    228933    8118825    08:29:40:125    CC    [MS->NW] CC__CALL_CONFIRMED        
OTA (PCORE)    229300    8132778    08:29:41:032    CC    [MS->NW] CC__ALERTING        
OTA (PCORE)    230902    8261717    08:29:49:280    CC    [MS->NW] CC__CONNECT        
PS (PCORE)    232038    8349260    08:29:54:887    L1HISR - RRM_TDD    MSG_ID_LAPDM_RR_ERROR_IND
232038, 0, 8349260, 08:29:54:887 2017/01/22, MOD_L1HISR, MOD_RRM_TDD, L1HISR_GAS_SAP, MSG_ID_LAPDM_RR_ERROR_IND
...
            error_cause = ERROR_TIMER_EXPD_N200_ABNORMAL_REL (enum 2)
            channel_type = FACCH (enum 25)
...        
PS (PCORE)    232243    8350003    08:29:54:887    RATCM    [RATCM] cs_conn_state = RATCM_CS_IDLE, ps_conn_state = RATCM_PS_IDLE   

5.切換失敗形成自動掛斷

出現該問題的緣由是UE切換失敗形成的。


PS    547310    838713    15:32:09:725    MPAL_2 - RRM_2    MSG_ID_MPAL_RR_SERV_DEDI_MEAS_IND    rxqual_sub_avg = 0x05    
//網絡要求UE進行切換
OTA    547379    838752    15:32:09:925    RRM_2    [NW->MS] RR__HANDOVER_COMMAND        
PS    547395    838764    15:32:10:125    RRM_2    [RMC] Target_arfcn = 656, F_O = 1169239, E_O = 7924        
PS    547449    838841    15:32:10:525    MPAL_2 - RRM_2    MSG_ID_MPAL_RR_HANDOVER_FAIL_IND        
PS    547460    838841    15:32:10:525    RRM_2 - LAPDM_2    MSG_ID_RR_LAPDM_RECON_REQ        
//切換失敗,緣由是T3124計時器超時,說明是網絡沒有迴應形成的切換失敗。
OTA    547461    838841    15:32:10:525    RRM_2    [MS->NW] RR__HANDOVER_FAILURE    Abnormal release, timer expired (3)    
//從新鏈接old channel,但old channel也沒有迴應,因而出現了N200 error,RR鏈接斷開。
PS    547557    838998    15:32:11:325    MPAL_2 - RRM_2    MSG_ID_MPAL_RR_SERV_DEDI_MEAS_IND    rxqual_sub_avg = 0x07    
PS    547587    839036    15:32:11:525    LISR2HISR_CTIRQ1 - RRM_2    MSG_ID_LAPDM_RR_REL_IND    N200 error    

六、RLF發生後MS端發起重連的實例

第二組:
//一樣是信號質量差,但第二組是因爲RLF形成的通話中斷。根據協議,RLF發生後會嘗試進行call reestablishment,故耗費了幾秒鐘去找合適的小區重建call。
此題中未找到合適的小區,故上報ecpi 較晚。
Type    Index    Time    Local Time    Module    Message    Comment    Time Different
OTA    853907    376621    14:15:01:760    RRM    [MS->NW] RR__MEASUREMENT_REPORT        
//信號質量差致使Radio Link Failure錯誤
PS    853957    376629    14:15:01:760    LISR2HISR_CTIRQ1 - RRM    MSG_ID_LAPDM_RR_ERROR_IND        
//channel斷開
PS    853973    376629    14:15:01:760    RRM - MPAL    MSG_ID_RR_MPAL_DEDICATED_CHANNEL_DISCONNECT_REQ        
PS    854034    376638    14:15:01:760    MPAL - RRM    MSG_ID_MPAL_RR_DEDICATED_CHANNEL_DISCONNECT_CNF        
PS    854042    376638    14:15:01:760    RRM - RATCM    MSG_ID_RATCM_GAS_CONN_LOSS_IND        
PS    854079    376638    14:15:01:760    RRM    [RMC] Radio Link Trigger reselection!        
PS    854161    376638    14:15:01:760    RATCM - MM    MSG_ID_MM_RATCM_CONN_LOSS_IND        
PS    854163    376638    14:15:01:760    MM    CM rej because RADIO LINK FAILURE        
//嘗試重建call
PS    854165    376638    14:15:01:760    MM    MM new State: MM_WAIT_FOR_REESTABLISH        
PS    854180    376639    14:15:01:760    CC    ENTER RE-ESTABLISHMENT MODE        
OTA    854635    376696    14:15:01:960    RRM    [NW->MS] RR__SI_2 (ARFCN[123], TC[1])        
OTA    855148    376782    14:15:02:560    RRM    [NW->MS] RR__SI_2 (ARFCN[648], TC[1])        
OTA    855763    376884    14:15:02:960    RRM    [NW->MS] RR__SI_2TER (ARFCN[120], TC[5])        
OTA    856755    377047    14:15:03:760    RRM    [NW->MS] RR__SI_4 (ARFCN[118], TC[7])        
OTA    857287    377141    14:15:04:360    RRM    [NW->MS] RR__SI_2 (ARFCN[118], TC[1])        
PS    860562    377377    14:15:05:560    RRM    [RMC] RMC do reselection, num_of_top_six[6]!        
//沒有合適小區進行重建call,放棄重建,報告通話中斷。
PS    860588    377377    14:15:05:560    MM    MM new State: MM_IDLE_NO_CELL_AVAILABLE        
PS    860603    377377    14:15:05:560    CC - CSM    MSG_ID_MNCC_REL_CNF        
PS    860655    377377    14:15:05:560    L4C - CSM    MSG_ID_L4CCSM_CC_ABORT_CALL_REQ    
//ECPI上報通話中斷    
SYS    860714    377377    14:15:05:560    NIL    [IMSP_U]+ECPI: 1,133,,,,,"",,"",2165        
OTA    861247    377422    14:15:05:760    RRM    [NW->MS] RR__SI_4 (ARFCN[115], TC[7])        
OTA    861293    377516    14:15:06:245    RRM    [NW->MS] RR__SI_2 (ARFCN[115], TC[1])        
OTA    861570    377659    14:15:06:955    MM    [MS->NW] MM__LOCATION_UPDATING_REQUEST (LU type: MM_NORMAL_LU)     

七、涉及call狀態機,AP和Modem的同步(協議24.008)

發出connect或收到connect消息,mt或mo進入active狀態

發出disconnect要等收到網絡的cc_release才進入idle狀態

主叫的響鈴與被叫是否創建起鏈接無關,好比被叫沒信號的時候,主叫聽到"您撥打的號碼沒法接通",主叫就是在響鈴狀態。
被叫可否創建起鏈接只會影響主叫能不能進入cc_connect狀態。即最終接通電話的狀態。

八、關於paging類型(確認協議)

Spec25.331中有詳細定義,RRC_PAGING_TYPE1/RRC_PAGING_TYPE2均可以用來傳輸paging,網絡會根據當前UE 的狀態選擇使用:
8.1.2.1章節中:
RRC_PAGING_TYPE1 is used to transmit paging information to selected UEs in idle mode, CELL_PCH or URA_PCH state
using the paging control channel (PCCH).
8.1.11.1章節中:
RRC_PAGING_TYPE2 is used to transmit dedicated paging information to one UE in connected mode in CELL_DCH ,
CELL_FACH or CELL_PCH (FDD and 1.28 Mcps TDD only) state.
即:
RRC_PAGING_TYPE1用於idle態,CELL_PCH or URA_PCH 態,PCCH
RRC_PAGING_TYPE2用於CELL_DCH, CELL_FACH or CELL_PCH,DCCH

PAGING有不少的類型,分爲CS域和PS域兩大類,CS域包括被叫通話,短信,彩信等,PS域主要就是數據業務相關的:

OTA    1546750    487939    14:53:13:455    ERRC_CEL    [NW->MS] PAGING, PagingRecordList[KAL_TRUE], SIB Modification[KAL_FALSE], ETWS[KAL_FALSE], CMAS[KAL_FALSE]
此次收到的CS域的通話被叫:        
PS    1546760    487939    14:53:13:455    ERRC_CEL    [PAGING] Rx Paging for UE with S-TMSI: mmec[10100100b], m-tmsi:[11101100b 10001100b 00111101b 00000101b]        
PS    1546761    487939    14:53:13:455    ERRC_CEL    [PAGING] ueid matched?[KAL_TRUE]: sim_status[ENASAS_SIM_VALID], ueid sel[PagingUE_Identity_s_TMSI_selected], stmsi_valid in SIM[KAL_TRUE]        
PS    1546762    487939    14:53:13:455    ERRC_CEL    [CEL_DI/LV] send PAGING_IND to EMM on [ENASAS_CN_DOMAIN_CS] with STMSI(mmec/mtmsi)[164/236,140,61,5]        
PS    1546786    487939    14:53:13:455    EMM_ERRCIF    [EMM ERRCIF] Receive CS STMSI paging    
CSFB成功到2G:    
OTA    1548216    487953    14:53:13:455    EMM_NASMSG    [MS->NW] EMM_Extended_Service_Request(service type="MT_CSFB", CSFB response="CSFB_ACCEPTED_BY_UE")        
OTA    1551824    488129    14:53:14:255    RRM    [MS->NW] RR__PAGING_RESPONSE
OTA    1556048    489224    14:53:19:855    RRM    [NW->MS] RR__SI_6 (ARFCN[76], TC[255])                
OTA    1557308    490474    14:53:26:055    RRM    [MS->NW] RR__MEASUREMENT_REPORT        
臨時發生了ERROR_TIMER_EXPD_N200_ABNORMAL_REL的RR鏈接錯誤,致使沒法繼續,失敗,與後面的LU無關,此通常爲臨時網絡問題:
PS    1557338    490537    14:53:26:455    LISR2HISR_CTIRQ1 - RRM    MSG_ID_LAPDM_RR_ERROR_IND
...
            error_cause = ERROR_TIMER_EXPD_N200_ABNORMAL_REL (enum 2)
            channel_type = SDCCH (enum 23)
...
        
PS    1602843    493569    14:53:41:615    ERRC_MOB    [MRM] store scell: earfcn[37900] pci[87] rsrp[-433] rsrq[-50] cell_off[0] cell_state[0]        
PS    1602991    493571    14:53:41:615    ERRC_MOB    [MRM] store scell: earfcn[37900] pci[87] rsrp[-433] rsrq[-49] cell_off[0] cell_state[0]    
第二次,這是是一個PS域屬於業務相關的paging:
OTA    1603090    493571    14:53:41:615    ERRC_CEL    [NW->MS] PAGING, PagingRecordList[KAL_TRUE], SIB Modification[KAL_FALSE], ETWS[KAL_FALSE], CMAS[KAL_FALSE]        
PS    1603102    493571    14:53:41:615    ERRC_CEL    [PAGING] Rx Paging for UE with S-TMSI: mmec[10100100b], m-tmsi:[11101100b 10001110b 00111101b 00000101b]        
PS    1603103    493571    14:53:41:615    ERRC_CEL    [PAGING] ueid matched?[KAL_TRUE]: sim_status[ENASAS_SIM_VALID], ueid sel[PagingUE_Identity_s_TMSI_selected], stmsi_valid in SIM[KAL_TRUE]        
PS    1603104    493571    14:53:41:615    ERRC_CEL    [CEL_DI/LV] send PAGING_IND to EMM on [ENASAS_CN_DOMAIN_PS] with STMSI(mmec/mtmsi)[164/236,142,61,5]        
PS    1603105    493571    14:53:41:615    ERRC - EMM    MSG_ID_EMM_ERRC_PAGE_IND
創建起主要是完成PS域相關的網絡須要:        
OTA    1603727    493576    14:53:41:615    ERRC_CONN    [MS->NW] ERRC_RRCConnectionRequest        
PS    1609305    493633    14:53:41:815    ERRC_MOB    [MRM] store scell: earfcn[37900] pci[87] rsrp[-438] rsrq[-52] cell_off[0] cell_state[0]        
本此時刻應該網絡因爲CS域的被叫的paging下來,可是網絡沒有發下來,此時手機駐網信號良好,且有其餘paging下來,因此判斷此爲網絡問題:

對比機:
一次在副卡上被叫,且是GSM網絡,與測試機不一樣,沒有對比的意義:
OTA    1530330    488178    14:53:12:480    RRM_2    [NW->MS] RR__SI_2QUATER (ARFCN[628], TC[5])        
OTA    1530437    488334    14:53:13:420    RRM_2    [NW->MS] RR__PAGING_REQUEST_TYPE_1        
OTA    1530440    488334    14:53:13:420    RRM_2    [MS->NW] RR__PAGING_RESPONSE        
OTA    1531692    488606    14:53:14:620    CC_2    [NW->MS] CC__SETUP        
OTA    1531801    488607    14:53:14:620    CC_2    [MS->NW] CC__CALL_CONFIRMED        
OTA    1532169    488795    14:53:15:620    CC_2    [MS->NW] CC__ALERTING        
OTA    1535911    493198    14:53:37:620    CC_2    [MS->NW] CC__CONNECT        
OTA    1536051    493276    14:53:38:020    CC_2    [NW->MS] CC__CONNECT_ACKNOWLEDGE        
OTA    1719339    521945    14:56:01:420    CC_2    [NW->MS] CC__DISCONNECT        
OTA    1719355    521945    14:56:01:420    CC_2    [MS->NW] CC__RELEASE        
OTA    1719671    521985    14:56:01:620    CC_2    [NW->MS] CC__RELEASE_COMPLETE    

九、測試機未收到paging

判斷paging是不是本身的看ueid匹配

從log看被叫沒收到尋呼是網絡臨時緣由致使,且持續了兩分鐘左右,在16:43:45以後能夠恢復。
這種網絡問題表現爲:當被叫與網絡沒同步上,網絡端會在不通知手機的狀況下分離手機的信息,致使網絡不會給被叫發尋呼,而手機也不會知道本身被分離。直到手機從新同步到網絡才能恢復。

此Log中被叫測試機行爲符合這種狀況,16:40:45到16:43:41之間手機正常執行收監聽尋呼,測量鄰區等操做。但就是收不到本身的尋呼。
而在16:43被叫測試機主動撥出電話,觸發了從新同步到網絡的動做,因此在此以後網絡會認爲手機註冊正常,會爲手機發送尋呼。

1. 被叫測試機一直在正常監聽尋呼信道,而且能收到信道上的尋呼數據,只是沒有收到發給本身的尋呼。以下:
1678231, 2446027, 5262103, 16:40:40:835 2017/03/02, MOD_EMAC, MOD_ERRC, ERRC_EMAC_SAP, MSG_ID_ERRC_EMAC_PAGING_IND //收到paging, 檢查UEID後發現不是發給本身的paging
1678287, 2446027, 5262103, 16:40:40:835 2017/03/02, MOD_ERRC_CEL, , TRACE_GROUP_2, [PAGING] ueid matched?[KAL_FALSE]: sim_status[ENASAS_SIM_VALID], ueid sel[PagingUE_Identity_s_TMSI_selected],
1696178, 2451403, 5267479, 16:41:07:595 2017/03/02, MOD_EMAC, MOD_ERRC, ERRC_EMAC_SAP, MSG_ID_ERRC_EMAC_PAGING_IND //以後的兩分鐘也是這樣
1722064, 2459339, 5275415, 16:41:47:395 2017/03/02, MOD_EMAC, MOD_ERRC, ERRC_EMAC_SAP, MSG_ID_ERRC_EMAC_PAGING_IND
1753709, 2470454, 5284887, 16:42:34:755 2017/03/02, MOD_EMAC, MOD_ERRC, ERRC_EMAC_SAP, MSG_ID_ERRC_EMAC_PAGING_IND
1794245, 2483254, 5296919, 16:43:34:915 2017/03/02, MOD_EMAC, MOD_ERRC, ERRC_EMAC_SAP, MSG_ID_ERRC_EMAC_PAGING_IND

2. 16:43:41測試機主動撥出電話,觸發RA過程,手機會從新同步到網絡。
1800054, 2485195, 5298179, 16:43:41:200 2017/03/02, MOD_ERRC_CONN, , TRACE_PEER, [MS->NW] ERRC_RRCConnectionRequest
1800586, 2485205, 5298188, 16:43:41:200 2017/03/02, MOD_ERRC_CONN, , TRACE_PEER, [NW->MS] ERRC_RRCConnectionSetup
1801119, 2485206, 5298189, 16:43:41:200 2017/03/02, MOD_EMM_NASMSG, , TRACE_PEER, [MS->NW] EMM_Extended_Service_Request(service type="MO_CSFB", CSFB response="CSFB_UNUSED")
1801141, 2485206, 5298189, 16:43:41:200 2017/03/02, MOD_ERRC_CONN, , TRACE_PEER, [MS->NW] ERRC_RRCConnectionSetupComplete
3. 以後手機可收到本身的paging,以下在16:44:00收到ps域的paging:
1854434, 1320223, 5302039, 16:44:00:330 2017/03/02, MOD_ERRC_CEL, , TRACE_PEER, [NW->MS] PAGING, PagingRecordList[KAL_TRUE], SIB Modification[KAL_FALSE], ETWS[KAL_FALSE], CMAS[KAL_FALSE]

我看對比機這個時間點好像也駐留了[37900/87]這個小區啊,具體駐留哪一個小區怎麼看?

能夠搜索cell camp on as serving這條消息做爲時間點參考,16:40:47對比機重選到了[37900/386],在這個小區收到的paging。以下:

//對比機原本在[37900/87]
1278684, 572987, 1534646, 16:40:47:550 2017/03/02, MOD_ERRC_MOB, , TRACE_GROUP_1, [MRM] Serv cell: earfcn[37900] pci[87] srxlev[101], squal[16], hps[0]
1278687, 572987, 1534646, 16:40:47:550 2017/03/02, MOD_ERRC_MOB, , TRACE_GROUP_1, [CJDG] SERV[37900/87] Srxlev[101] Squal[16] R[-367] qdb

//[37900/386]信號稍好了些,知足重選標準,選到了[37900/386]
1278692, 572987, 1534646, 16:40:47:550 2017/03/02, MOD_ERRC_MOB, , TRACE_GROUP_1, [CJDG] LCell[37900/386] Srx[124] Squ[36] R[-364] RESEL[P, State[ERRC_MOB_CJDG_CELL_STATUS_CND] Tresel_cnt[1235] S_Prio[R higher]]

因此對比機是在 [37900/386] 收到的paging:
1279156, 573022, 1534662, 16:40:47:550 2017/03/02, MOD_ERRC_SYS, , TRACE_PEER, [NW->MS] SystemInformationBlockType1 (EARFCN[37900], PCI[386])
1279361, 573022, 1534662, 16:40:47:550 2017/03/02, MOD_ERRC_CEL, , TRACE_GROUP_1, [CEL_DI/LV] cell camp on as serving: earfcn[37900]/pci[386], is_csg_cell[KAL_FALSE]
1283101, 573515, 1535151, 16:40:49:980 2017/03/02, MOD_ERRC_CEL, , TRACE_PEER, [NW->MS] PAGING, PagingRecordList[KAL_TRUE], SIB Modification[KAL_FALSE], ETWS[KAL_FALSE], CMAS[KAL_FALSE]

十、SAT命令失敗致使打不出電話

SAT命令沒被正常 fetch 致使的 撥號前modem下 call control 給卡時,卡返回 busy,最終致使沒法打不出電話。
而fetch SAT命令涉及到開機部分。目前 log 不完善,沒法定位問題。
請貴司抓取從開機到發生問題的完整 mtklog(必須包含開機部分)。

貴司要的分析log 和緣由敝司都更新在下面了,貴司能夠慢慢看。

//ATD因call control 下給卡時,卡返回 sat busy 而停止了:
SYS (PCORE)    85982    346462800    14:11:32:830    NIL    [AT_I p21, s10]ATD120;
        
PS (PCORE)    86240    346462817    14:11:32:830    ATCI    command: ATD120;

PS (PCORE)    86280    346462834    14:11:32:830    CSM - SIM    MSG_ID_SAT_CALL_CTRL_BY_SIM_REQ        
PS (PCORE)    86282    346462834    14:11:32:830    SIM    sim_al_envelope()        
PS (PCORE)    86283    346462834    14:11:32:830    SIM    SIM_ENVELOPE : length: 28        
PS (PCORE)    86284    346462834    14:11:32:830    SIM    APDU_tx 0: 80 C2 00 00 16 D4 14 82 02 82 81 86 03 81 21 F0        
PS (PCORE)    86285    346462834    14:11:32:830    SIM    APDU_tx 1: 13 09 64 F0 10 25 61 62 D3 60 2F 00 F2 F2 F2 F2        
PS (PCORE)    86431    346463127    14:11:32:830    SIM    SIM: SIM_SAT_CMD_BUSY        
PS (PCORE)    86432    346463127    14:11:32:830    SIM    ENVELOPE: send 22 bytes recv 0 bytes => 93 00                

PS (PCORE)    86435    346463127    14:11:32:830    CSM - L4C    MSG_ID_L4CCSM_CC_CALL_SETUP_CNF        
PS (PCORE)    86443    346463127    14:11:32:830    CSM - L4C    MSG_ID_L4CCSM_CC_CALL_INFO_IND        
PS (PCORE)    86449    346463127    14:11:32:830    L4C - CSM    MSG_ID_L4CCSM_CC_ABORT_CALL_REQ        
PS (PCORE)    86478    346463127    14:11:32:830    CSM - CC    MSG_ID_MNCC_ABORT_CALL_REQ

86433, 0, 346463127, 14:11:32:830 2017/02/27, MOD_SIM, MOD_CSM, PS_SIM_SAP, MSG_ID_SAT_CALL_CTRL_BY_SIM_CNF
    Local_Parameter --> Len = 84, Addr = 0xA577FC5C
        sat_call_ctrl_by_sim_cnf_struct = (struct)
            ref_count = 0x01
            lp_reserved = 0x30
            msg_len = 0x0054
            res = 0x03 //SAT_SIM_ERROR
            type = 0x06
            size_of_ccp1 = 0x00
            ccp1 = Array[15]
            .........

86435, 0, 346463127, 14:11:32:830 2017/02/27, MOD_CSM, MOD_L4C, CSM_L4C_SAP, MSG_ID_L4CCSM_CC_CALL_SETUP_CNF
    Local_Parameter --> Len = 20, Addr = 0xA576FAB4
        l4ccsm_cc_call_setup_cnf_struct = (struct)
            ref_count = 0x01
            lp_reserved = 0x00
            msg_len = 0x0014
            src_id = 0x17
            call_id_present = 0x00
            call_id = 0x00
            response = 0x01
            cause_present = 0x01
            cause = 0x030b //779, CSMCC_SAT_CALL_CTRL_REJECTED,若是cnf中包含這個 cause,modem就會終止撥號流程。
            call_type = 0x00
            ..........



2. 這個是要看fetch SAT命令初始化是否異常嗎?具體在哪裏初始化?
=>[MTK reply]
這是 modem 部分的,不是 fetch SAT命令的初始化。
fetch SAT命令不存在初始化的動做,只是個命令。
從現有modem log 中 check 到 modem 在這以前就沒能正常 fetch SAT命令。而影響是否 fetch 的因素跟開機時候的modem 的一些 message 和變量有關。

十一、移動3G的自動掛斷問題

移動3G的信令消息

兩次沒接通的緣由同樣,都是在3G創建好RRC鏈接後網絡發來了SIGNALLING_CONNECTION_RELEASE,釋放了cs域鏈接,致使通話中斷,且兩次發生問題的3G小區相同。其餘時間點在這個3G小區和其餘3G小區沒有發生此問題。這是網絡緣由致使,網絡要主動發來消息斷掉了電話。

第一通:
1249865, 266206, 243979, 09:53:07:975 2017/03/10, MOD_MM, , TRACE_PEER, [MS->NW] MM__PAGING_RESPONSE
1252847, 266219, 243992, 09:53:07:975 2017/03/10, MOD_ADR, , TRACE_PEER, [MS->NW] RRC__RRC_CONNECTION_REQUEST
1253103, 266266, 244032, 09:53:08:180 2017/03/10, MOD_ADR, , TRACE_PEER, [NW->MS] RRC__RRC_CONNECTION_SETUP
1253345, 266285, 244051, 09:53:08:180 2017/03/10, MOD_ADR, , TRACE_PEER, [MS->NW] RRC__RRC_CONNECTION_SETUP_COMPLETE % RRC鏈接創建成功
1254775, 266379, 244145, 09:53:08:785 2017/03/10, MOD_ADR, , TRACE_PEER, [NW->MS] RRC__SIGNALLING_CONNECTION_RELEASE % 網絡發來信令釋放消息,釋放了CS域,CS服務中斷
cn-DomainIdentity = cs-domain
第二通,緣由相同:
314040, 312902, 287085, 09:56:43:530 2017/03/10, MOD_SIBE, , TRACE_PEER, [NW->MS] RRC_SI_SIB12 (UARFCN:[10713], PSC:[65])
317850, 312991, 287166, 09:56:43:930 2017/03/10, MOD_ADR, , TRACE_PEER, [MS->NW] RRC__RRC_CONNECTION_SETUP_COMPLETE
319189, 313083, 287258, 09:56:44:530 2017/03/10, MOD_ADR, , TRACE_PEER, [NW->MS] RRC__SIGNALLING_CONNECTION_RELEASE
cn-DomainIdentity = cs-domain

十二、收到paging可是解碼失敗

對比機當時信號太差,一直解碼尋呼消息失敗。以下:
PS    582791    293339    09:57:06:240    ERRC_MOB    [MRM] store scell: earfcn[1650] pci[235] rsrp[-466] rsrq[-77] cell_off[0] cell_state[32]         % 信號質量-77太差
PS    583293    293594    09:57:07:520    EL1 - ERRC    MSG_ID_ERRC_EL1_PCH_CRCNG_IND        % decode paging一直失敗,持續到 9:57:20
PS    583794    293850    09:57:08:620    EL1 - ERRC    MSG_ID_ERRC_EL1_PCH_CRCNG_IND        
PS    585382    294874    09:57:13:930    EL1 - ERRC    MSG_ID_ERRC_EL1_PCH_CRCNG_IND        
PS    587491    295641    09:57:17:755    EL1 - ERRC    MSG_ID_ERRC_EL1_PCH_CRCNG_IND        
PS    588489    296154    09:57:20:160    EL1 - ERRC    MSG_ID_ERRC_EL1_PCH_CRCNG_IND

如我上一條note所說,對比機是由於信號太差,連續屢次解碼PCH失敗沒能解出本身的paging。

1. 被叫對比機的TAU在9:57:01就完成了,而主叫在9:57:05纔打出的電話,被叫對比機應該在9:57:08左右收到paging。因此應該不是TAU致使的。
569261, 322624, 292266, 09:57:00:880 2017/03/10, MOD_EMM_NASMSG, , TRACE_PEER, [MS->NW] EMM_Tracking_Area_Update_Request(EPS update type="EMM_UPDATE_TYPE_COMBINED_TAU", active flag="KAL_FALSE")
575648, 322748, 292380, 09:57:01:280 2017/03/10, MOD_EMM_NASMSG, , TRACE_PEER, [NW->MS] EMM_Tracking_Area_Update_Accept(EPS update result="EMM_UPDATE_RESULT_COMBINED_UPDATED")
575810, 322748, 292380, 09:57:01:280 2017/03/10, MOD_EMM_NASMSG, , TRACE_PEER, [MS->NW] EMM_Tracking_Area_Update_Complete

2. 當時對比機信號不好,在尋呼信道PCH上收到的paging都解碼失敗。即便網絡正確下發了paging手機解碼不出來也沒法建成電話。
583293, 324061, 293594, 09:57:07:520 2017/03/10, MOD_EL1, MOD_ERRC, ERRC_EL1_SAP, MSG_ID_ERRC_EL1_PCH_CRCNG_IND %CRC NG: CRC校驗not good,
result = EL1_RESULT_CRC_NG
583794, 324338, 293850, 09:57:08:620 2017/03/10, MOD_EL1, MOD_ERRC, ERRC_EL1_SAP, MSG_ID_ERRC_EL1_PCH_CRCNG_IND
585382, 325423, 294874, 09:57:13:930 2017/03/10, MOD_EL1, MOD_ERRC, ERRC_EL1_SAP, MSG_ID_ERRC_EL1_PCH_CRCNG_IND
587491, 326281, 295641, 09:57:17:755 2017/03/10, MOD_EL1, MOD_ERRC, ERRC_EL1_SAP, MSG_ID_ERRC_EL1_PCH_CRCNG_IND

1三、MM層或AT命令查看是否註冊上小區

GMM, MM 是2G 3G共用的,4G只看EMM便可。

GMM主要是23G的PS相關服務,好比路由區更新RAU,
MM主要負責23G的CS服務,好比打電話,位置更新LU。

當時對比機在4G,能夠搜索EMM state。好比在9:57:01:280,EMM註冊狀態已是EMMREG_STATE_TAU_COMPLETED。
575752, 322748, 292380, 09:57:01:280 2017/03/10, MOD_EMM, , TRACE_STATE, [EMM STATE] EMM_REG state from EMMREG_STATE_TAU_REQUESTED to EMMREG_STATE_TAU_COMPLETED

若是想看是否有註冊上網,直接看AT命令會更準確。CREG是手機上報的註冊狀態,其中倒數第三個參數表示已經註冊上的小區
567586, 322615, 292258, 09:57:00:680 2017/03/10, MOD_NIL, , TRACE_INFO, [AT_R p19, s9]+CREG: 3,1,"A561","01E2460B",2,0,0 %倒數第三個參數是2:3G
576344, 322751, 292383, 09:57:01:280 2017/03/10, MOD_NIL, , TRACE_INFO, [AT_U p18, s8]+CREG: 1,"2561","06C1D803",7,0,0 %倒數第三個參數是7:4G
578050, 322759, 292390, 09:57:01:480 2017/03/10, MOD_NIL, , TRACE_INFO, [AT_R p19, s9]+CREG: 3,1,"2561","06C1D803",7,0,0 %"2561"是LAC , "06C1D803"是小區id
579332, 322765, 292396, 09:57:01:480 2017/03/10, MOD_NIL, , TRACE_INFO, [AT_R p19, s9]+CREG: 3,1,"2561","06C1D803",7,0,0
580275, 322769, 292400, 09:57:01:480 2017/03/10, MOD_NIL, , TRACE_INFO, [AT_R p19, s9]+CREG: 3,1,"2561","06C1D803",7,0,0
倒數第三個參數取值以下:
0     GSM
2    UTRAN
3    GSM w/EGPRS
4    UTRAN w/HSDPA
5    UTRAN w/HSUPA
6    UTRAN w/HSDPA and HSUPA
7     E-UTRAN

1四、查看終端接收paging的狀態是否正常

2,F5 4#不通時間點: 15:39-15:45(10次連續來電提醒)
觀察此時間區間內,手機駐留在4G小區earfcn[37900] pci[341],信號良好,且PCCH decode result from HW: [EL1_CH_PCH_RESULT_SUCCESS],像是網絡沒有下發paging給被叫致使連續10沒有來電:
Type    Index    Time    Local Time    Module    Message    Comment    Time Different
OTA (PCORE)    1149624    387634034    15:39:46:004    ERRC_SYS    [NW->MS] MasterInformationBlock (EARFCN[37900], PCI[341])        
OTA (PCORE)    1149676    387634105    15:39:46:004    ERRC_SYS    [NW->MS] SystemInformationBlockType1 (EARFCN[37900], PCI[341])        
PS (L1CORE)    832284    387653268    15:39:46:701    LCEL    [LCEL][PAGING] PCCH decode result from HW: [EL1_CH_PCH_RESULT_SUCCESS]        
PS (L1CORE)    833333    387673251    15:39:47:981    LMOB    [MRM] store PCell: earfcn[37900] pci[341] rsrp[-467] rsrq[-54] sinr[-5] snr[-4] cell_off[0]        
PS (L1CORE)    835505    387733267    15:39:51:821    LCEL    [LCEL][PAGING] PCCH decode result from HW: [EL1_CH_PCH_RESULT_SUCCESS]        
PS (L1CORE)    836058    387753250    15:39:53:101    LMOB    [MRM] store PCell: earfcn[37900] pci[341] rsrp[-468] rsrq[-53] sinr[-11] snr[0] cell_off[0]        
PS (L1CORE)    840336    387873250    15:40:00:782    LMOB    [MRM] store PCell: earfcn[37900] pci[341] rsrp[-462] rsrq[-50] sinr[-7] snr[4] cell_off[0]        
PS (L1CORE)    840483    387873268    15:40:00:782    LCEL    [LCEL][PAGING] PCCH decode result from HW: [EL1_CH_PCH_RESULT_SUCCESS]        
PS (L1CORE)    852599    388233250    15:40:23:822    LMOB    [MRM] store PCell: earfcn[37900] pci[341] rsrp[-460] rsrq[-49] sinr[-6] snr[6] cell_off[0]        
PS (L1CORE)    852713    388233266    15:40:23:822    LCEL    [LCEL][PAGING] PCCH decode result from HW: [EL1_CH_PCH_RESULT_SUCCESS]        
PS (L1CORE)    877279    388933251    15:41:08:622    LMOB    [MRM] store PCell: earfcn[37900] pci[341] rsrp[-466] rsrq[-51] sinr[-2] snr[2] cell_off[0]        
PS (L1CORE)    877437    388933274    15:41:08:622    LCEL    [LCEL][PAGING] PCCH decode result from HW: [EL1_CH_PCH_RESULT_SUCCESS]        
PS (L1CORE)    914816    389993251    15:42:16:462    LMOB    [MRM] store PCell: earfcn[37900] pci[341] rsrp[-464] rsrq[-52] sinr[-5] snr[1] cell_off[0]        
PS (L1CORE)    914978    389993274    15:42:16:462    LCEL    [LCEL][PAGING] PCCH decode result from HW: [EL1_CH_PCH_RESULT_SUCCESS]        
PS (L1CORE)    934479    390513251    15:42:49:742    LMOB    [MRM] store PCell: earfcn[37900] pci[341] rsrp[-463] rsrq[-50] sinr[1] snr[3] cell_off[0]        
PS (L1CORE)    934599    390513268    15:42:49:742    LCEL    [LCEL][PAGING] PCCH decode result from HW: [EL1_CH_PCH_RESULT_SUCCESS]        
PS (L1CORE)    947185    390853252    15:43:11:502    LMOB    [MRM] store PCell: earfcn[37900] pci[341] rsrp[-460] rsrq[-47] sinr[2] snr[8] cell_off[0]        
PS (L1CORE)    947305    390853269    15:43:11:502    LCEL    [LCEL][PAGING] PCCH decode result from HW: [EL1_CH_PCH_RESULT_SUCCESS]        
PS (L1CORE)    957854    391133251    15:43:29:422    LMOB    [MRM] store PCell: earfcn[37900] pci[341] rsrp[-461] rsrq[-51] sinr[-3] snr[7] cell_off[0]        
PS (L1CORE)    958003    391133272    15:43:29:422    LCEL    [LCEL][PAGING] PCCH decode result from HW: [EL1_CH_PCH_RESULT_SUCCESS]        
PS (L1CORE)    977571    391653252    15:44:02:702    LMOB    [MRM] store PCell: earfcn[37900] pci[341] rsrp[-457] rsrq[-45] sinr[8] snr[13] cell_off[0]        
PS (L1CORE)    977693    391653269    15:44:02:702    LCEL    [LCEL][PAGING] PCCH decode result from HW: [EL1_CH_PCH_RESULT_SUCCESS]        
PS (L1CORE)    989907    391973251    15:44:23:182    LMOB    [MRM] store PCell: earfcn[37900] pci[341] rsrp[-463] rsrq[-49] sinr[1] snr[5] cell_off[0]        
PS (L1CORE)    990052    391973272    15:44:23:182    LCEL    [LCEL][PAGING] PCCH decode result from HW: [EL1_CH_PCH_RESULT_SUCCESS]        
PS (L1CORE)    1013473    392633252    15:45:05:422    LMOB    [MRM] store PCell: earfcn[37900] pci[341] rsrp[-464] rsrq[-51] sinr[1] snr[6] cell_off[0]        
PS (L1CORE)    1013593    392633268    15:45:05:422    LCEL    [LCEL][PAGING] PCCH decode result from HW: [EL1_CH_PCH_RESULT_SUCCESS]        
對比信號很差不能正確解碼的實例:

這裏是正好在服務4G小區的的信號很差,致使的PCCH decode result from HW: [EL1_CH_PCH_RESULT_PDSCH_CRCNG]底層不能正確解碼,爲弱信號問題:
PS (L1CORE)    187344    1374794020    15:23:03:102    LMOB    [MRM] store PCell: earfcn[38400] pci[336] rsrp[-396] rsrq[-41] sinr[3] snr[3] cell_off[0]        
PS (L1CORE)    187865    1374814034    15:23:04:384    LCEL    [LCEL][PAGING] PCCH decode result from HW: [EL1_CH_PCH_RESULT_SUCCESS]        
PS (L1CORE)    188796    1374834046    15:23:05:663    LCEL    [LCEL][PAGING] PCCH decode result from HW: [EL1_CH_PCH_RESULT_PDSCH_CRCNG]        
PS (L1CORE)    189645    1374854030    15:23:06:943    LMOB    [MRM] store PCell: earfcn[37900] pci[66] rsrp[-471] rsrq[-60] sinr[-5] snr[-5] cell_off[0]        
PS (L1CORE)    189744    1374854046    15:23:06:943    LCEL    [LCEL][PAGING] PCCH decode result from HW: [EL1_CH_PCH_RESULT_PDSCH_CRCNG]        
PS (L1CORE)    190324    1374874014    15:23:08:223    LCEL    [LCEL][PAGING] PCCH decode result from HW: [EL1_CH_PCH_RESULT_NO_PDCCH]        
PS (L1CORE)    191199    1374894050    15:23:09:503    LCEL    [LCEL][PAGING] PCCH decode result from HW: [EL1_CH_PCH_RESULT_PDSCH_CRCNG]        
PS (L1CORE)    191903    1374914047    15:23:10:783    LCEL    [LCEL][PAGING] PCCH decode result from HW: [EL1_CH_PCH_RESULT_SUCCESS]        
PS (L1CORE)    192464    1374934030    15:23:12:063    LMOB    [MRM] store PCell: earfcn[37900] pci[66] rsrp[-472] rsrq[-61] sinr[-14] snr[-14] cell_off[0]        
PS (L1CORE)    192581    1374934047    15:23:12:063    LCEL    [LCEL][PAGING] PCCH decode result from HW: [EL1_CH_PCH_RESULT_PDSCH_CRCNG]        
PS (L1CORE)    199869    1375134032    15:23:24:863    LMOB    [MRM] store PCell: earfcn[37900] pci[66] rsrp[-487] rsrq[-73] sinr[-27] snr[-27] cell_off[0]

1五、CSFB之後創建RR鏈接失敗,RR_DATA中出現大量bad_block

被叫收到paging後CSFB 到 2G ARFCN[64]小區後    
OTA (PCORE)    564948    1378894057    15:27:25:514    ERRC_CEL    [NW->MS] PAGING, PagingRecordList[KAL_TRUE], SIB Modification[KAL_FALSE], ETWS[KAL_FALSE], CMAS[KAL_FALSE], EAB[KAL_FALSE]        
OTA (PCORE)    566164    1378895065    15:27:25:514    EMM_NASMSG    [MS->NW] EMM_Extended_Service_Request(service type="MT_CSFB", CSFB response="CSFB_ACCEPTED_BY_UE")        
OTA (PCORE)    567838    1378898163    15:27:25:714    ERRC_CONN    [NW->MS] ERRC_RRCConnectionRelease(cause:[ReleaseCause_other], redirectInfo:[1])        
PS (PCORE)    569364    1378907846    15:27:26:398    RRM_TDD    [RCS] There are [21] ARFCNs to try        
PS (PCORE)    569365    1378907846    15:27:26:398    RRM_TDD    [RCS] Sorted power scan list: Index:0 ARFCN:61 POWER:-352        
PS (PCORE)    569366    1378907846    15:27:26:398    RRM_TDD    [RCS] Sorted power scan list: Index:1 ARFCN:77 POWER:-354        
PS (PCORE)    569367    1378907846    15:27:26:398    RRM_TDD    [RCS] Sorted power scan list: Index:2 ARFCN:64 POWER:-356        
PS (L1CORE)    306715    1378928421    15:27:27:619    L1 - GISE_TDD    MSG_ID_MPHC_BLOCK_QUALITY_IND        
OTA (PCORE)    569750    1378927875    15:27:27:620    RRM_TDD    [NW->MS] RR__SI_1 (ARFCN[64], TC[255])        
OTA (PCORE)    569791    1378927878    15:27:27:620    RRM_TDD    [NW->MS] RR__SI_3 (ARFCN[64], TC[255])
因爲信號質量不佳RR_BAD_BLOCK,致使沒法創建起RR channel,可能爲臨時網絡干擾致使的:    
OTA (PCORE)    570315    1378927941    15:27:27:620    RRM_TDD    [MS->NW] RR__PAGING_RESPONSE        
OTA (PCORE)    572896    1378928785    15:27:27:620    RRM_TDD    [MS->NW] RR__CHANNEL_REQUEST    block_ind = RR_BAD_BLOCK (enum 1)    
OTA (PCORE)    574209    1378933543    15:27:28:029    RRM_TDD    [MS->NW] RR__CHANNEL_REQUEST        
OTA (PCORE)    574312    1378937665    15:27:28:232    RRM_TDD    [MS->NW] RR__CHANNEL_REQUEST        
OTA (PCORE)    574406    1378943581    15:27:28:657    RRM_TDD    [MS->NW] RR__CHANNEL_REQUEST        
PS (PCORE)    574412    1378943866    15:27:28:657    MPAL_TDD - RRM_TDD    MSG_ID_MPAL_RR_DATA_IND    block_ind = RR_BAD_BLOCK (enum 1)   

1六、關於2G當即指配程序失敗發生重連的實例(關於網絡系統消息的確認)

更新:
OTA (PCORE)    2204618    41698342    14:45:07:289    RRM_TDD_2    [NW->MS] RR__SI_5 (ARFCN[656], TC[255])        
OTA (PCORE)    2204767    41703189    14:45:07:689    RRM_TDD_2    [MS->NW] RR__MEASUREMENT_REPORT        
OTA (PCORE)    2204799    41703397    14:45:07:689    RRM_TDD_2    [NW->MS] RR__ASSIGNMENT_COMMAND        
OTA (PCORE)    2204847    41704331    14:45:07:689    RRM_TDD_2    [MS->NW] RR__ASSIGNMENT_COMPLETE
從新指配完成後,發生ERROR_TIMER_EXPD_N200_ABNORMAL_REL的底層失敗,        
PS (PCORE)    2205367    41719561    14:45:08:709    L1HISR - RRM_TDD_2    MSG_ID_LAPDM_RR_REL_IND    
...
            error_cause = ERROR_TIMER_EXPD_N200_ABNORMAL_REL (enum 2)
            channel_type = FACCH (enum 25)
...            
從新在2G ARFCN[656]小區創建起鏈接:
PS (PCORE)    2205371    41719563    14:45:08:709    RRM_TDD_2 - MPAL_TDD_2    MSG_ID_RR_MPAL_DEDICATED_CHANNEL_RECONNECT_REQ        
PS (PCORE)    2205394    41719779    14:45:08:709    MPAL_TDD_2 - RRM_TDD_2    MSG_ID_MPAL_RR_DEDICATED_CHANNEL_RECONNECT_CNF
而且給網絡報告說底層發生了一次錯誤,    
OTA (PCORE)    2205398    41719780    14:45:08:709    RRM_TDD_2    [MS->NW] RR__ASSIGNMENT_FAILURE
...
RR Cause
RR cause value: Protocol error unspecified (111)
...
PS (PCORE)    2205399    41719780    14:45:08:709    RRM_TDD_2    RRM_SUBSTATE = RRM_DEDICATED_RECON_L2_SUBSTATE    
            
PS (PCORE)    2205795    41732610    14:45:09:528    MPAL_TDD_2 - RRM_TDD_2    MSG_ID_MPAL_RR_SERV_DEDI_MEAS_IND        
OTA (PCORE)    2206372    41749843    14:45:10:528    RRM_TDD_2    [NW->MS] RR__SI_5TER (ARFCN[656], TC[255])    
因此此問題的仍是後面CC DISCONNECT,casue No circuit/channel available,與前面的RR__ASSIGNMENT_FAILURE沒有關係,RR__ASSIGNMENT_FAILURE只是發生了底層錯誤恢復鏈接後給網絡報告Protocol error unspecified (111)狀況,後面又正常恢復在ARFCN[656]小區:
CC DISCONNECT,casue No circuit/channel available通常爲網絡資源調配的問題,判斷爲網絡緣由    
OTA (PCORE)    2206533    41754893    14:45:10:944    CC_2    [NW->MS] CC__DISCONNECT    
...
Cause - (34) No circuit/channel available
...        

1七、隨機接入失敗案例

哪裏標誌着隨機接入失敗?
OTA 2315394 820798 11:14:53:195 RRM_2 [NW->MS] RR__PAGING_REQUEST_TYPE_1
OTA 2315397 820798 11:14:53:195 RRM_2 [MS->NW] RR__PAGING_RESPONSE
OTA 2315793 820799 11:14:53:195 RRM_2 [MS->NW] RR__CHANNEL_REQUEST
OTA 2316903 821465 11:14:56:595 RRM_2 [MS->NW] RR__CHANNEL_REQUEST
PS 2317687 822080 11:14:59:595 RRM_2 [RMC] T3126 timeout in RRM_ACCESS_STATE state.

A:T3126是UE側隨機接入的計時器,若是超時,就表明隨機接入失敗。

關於11:06和11:14這兩統統話,我這邊只能分析到都是RR__CHANNEL_REQUEST 後沒有獲得網絡端的RR__IMMEDIATE_ASSIGNMENT ,
那如何去確認兩個緣由不一樣呢?或是這種狀況如何搜索關鍵字呢?

A: 11:06是有獲得網絡端的RR__IMMEDIATE_ASSIGNMENT,多是您沒注意到。這種狀況能夠看MSG_ID_LAPDM_RR_REL_IND,看error_cause的緣由,通常要麼是N200要麼是RLF。
Type    Index    Time    Local Time    Module    Message    Comment    Time Different
OTA    1881851    724814    11:06:53:335    RRM_2    [NW->MS] RR__PAGING_REQUEST_TYPE_2        
OTA    1881854    724814    11:06:53:335    RRM_2    [MS->NW] RR__PAGING_RESPONSE        
OTA    1882558    724874    11:06:53:535    RRM_2    [NW->MS] RR__IMMEDIATE_ASSIGNMENT       


11:14這統統話由於沒有獲得網絡端的RR__IMMEDIATE_ASSIGNMENT,還沒成功創建起RR鏈接,因此就不能看MSG_ID_LAPDM_RR_REL_IND這個消息。要看爲什麼沒有成功創建起鏈接,通常狀況都是因爲T3126超時致使的。關鍵字搜索「T3126 timeout」
1八、對於網絡下發RR_CHANNEL_RELEASE緣由的一些探討

CSFB後什麼狀況須要位置更新

1,LU相關信息以下:
與位置相關的ID 有LAC(Location Area Code)(2G:SI_3/3G:SIB1)和TAC(Tracking Area Code)(4G:SIB1)
當小區重選伴隨LAC或TAC發生改變時會引發作LU(LOCATION_UPDATING)

MTK 平臺RR層鏈接斷開的check
2,RR斷開鏈接能夠經過RR_ERROR_IND和RR_REL_CONF兩條trace進行check

3,隨機接入失敗和網絡下發RR_release屬於網絡行爲,從UE端不得而知,確保後續的UE行爲無異常便可。

1九、手機handover之後,因爲小區信號質量差發生RLF(切換時是好的,切換後變差)

1,你說的小區切換的時候只看信號強度,不看信號質量應該是指手機空閒態時小區重選是看信號強度的,可是這裏是通話過程當中,屬於網絡控制的範疇,手機在哪一個小區,切到哪一個網絡沒有自主權,只會根據網絡指導的測量報告發送給網絡,網絡根據這些報告,是看信號強度或質量,或吞吐量等參數由網絡決定,手機沒有辦法主導,因此這裏要區分好小區重選和切換的概念
2,切換三秒時間足以致使底層斷開

這樣由於手機上報了當前arfcn的測量信號狀況給網絡:如服務小區信號質量等: .111 .... = RXQUAL-FULL-SERVING-CELL: BER > 12.8%, Mean value 18.10% (7)
OTA    300000    4081861    16:16:24:770    RRM    [MS->NW] RR__MEASUREMENT_REPORT    
DTAP Radio Resources Management Message Type: Measurement Report (0x15)

Measurement Results

0... .... = BA-USED: 0

.1.. .... = DTX-USED: DTX was used

..00 1100 = RXLEV-FULL-SERVING-CELL: -99 <= x < -98 dBm (12)

0... .... = 3G-BA-USED: 0

.0.. .... = MEAS-VALID: The measurement results are valid

RXLEV-SUB-SERVING-CELL: -89 <= x < -88 dBm (22)

.111 .... = RXQUAL-FULL-SERVING-CELL: BER > 12.8%, Mean value 18.10% (7)

.... 001. = RXQUAL-SUB-SERVING-CELL: 0.2% <= BER < 0.4%, Mean value 0.28% (1)

.... ...1 10.. .... = NO-NCELL-M: 6 neighbour cell measurement result (6)

..00 1111 = RXLEV-NCELL: 15

1011 1... = BCCH-FREQ-NCELL: 23

.... .001 000. .... = BSIC-NCELL: 8

...0 0101 1... .... = RXLEV-NCELL: 11

.100 10.. = BCCH-FREQ-NCELL: 18

.... ..10 1000 .... = BSIC-NCELL: 40

.... 0101 11.. .... = RXLEV-NCELL: 23

..01 001. = BCCH-FREQ-NCELL: 9

.... ...0 1111 0... = BSIC-NCELL: 30

.... .010 101. .... = RXLEV-NCELL: 21

...0 1010 = BCCH-FREQ-NCELL: 10

0000 00.. = BSIC-NCELL: 0

.... ..01 0011 .... = RXLEV-NCELL: 19

.... 0010 1... .... = BCCH-FREQ-NCELL: 5

.000 001. = BSIC-NCELL: 1

.... ...0 0110 1... = RXLEV-NCELL: 13

.... .000 01.. .... = BCCH-FREQ-NCELL: 1

..00 0101 = BSIC-NCELL: 5    
PS    300124    4081957    16:16:25:170    MPAL - RRM    MSG_ID_MPAL_RR_SERV_DEDI_MEAS_IND        
OTA    300260    4082040    16:16:25:570    RRM    [NW->MS] RR__SI_6 (ARFCN[62], TC[255])
因此網絡根據當前手機上報的服務小區和鄰小區的信號值與當前網絡資源做出了切換ARFCN[71]的指令:        
OTA    300283    4082047    16:16:25:570    RRM    [NW->MS] RR__HANDOVER_COMMAND        
OTA    300397    4082087    16:16:25:770    RRM    [MS->NW] RR__HANDOVER_COMPLETE        
OTA    305526    4085468    16:16:42:770    RRM    [NW->MS] RR__SI_5 (ARFCN[71], TC[255])        
可是後面因爲信號質量不佳就出現了底層鏈路失敗:
PS    306265    4085962    16:16:45:170    MPAL - RRM    MSG_ID_MPAL_RR_SERV_DEDI_MEAS_IND        
PS    306397    4086044    16:16:45:570    LAPDM    radio link failure        
PS    306398    4086044    16:16:45:570    L1 - RRM    MSG_ID_LAPDM_RR_ERROR_IND        

20、主卡與副卡資源衝突

經從新check,貴司所提到的該兩通paging,一樣由於與卡2發生衝突致使失敗;
另,上層消息MM__PAGING_RESPONSE須要在RRC鏈接創建後,方可經過[MS->NW] FDD_RRC__INITIAL_DIRECT_TRANSFER向網絡傳輸
該時間點RRC鏈接沒有創建成功,因而該response也是沒有搜到的,請知悉

如溝通,還請交換卡以後進行復測,

Type    Index    Time    Local Time    Module    Message    Comment    Time Different
OTA    965158    165697    17:16:26:215    ADR    [NW->MS] RRC__PAGING_TYPE1        
OTA    965176    165697    17:16:26:215    MM    [MS->NW] MM__PAGING_RESPONSE        
PS    965182    165697    17:16:26:215    RATCM - RRCE    MSG_ID_RATCM_RRCE_CONN_EST_REQ        
PS    965192    165697    17:16:26:215    RRCE - CSCE    MSG_ID_CSCE_RRCE_RRC_CONNECTION_ESTABLISHMENT_IND        
PS    965213    165748    17:16:26:620    MPAL_2 - RRM_2    MSG_ID_MPAL_RR_DATA_IND    block_ind = RR_BAD_BLOCK (enum 1)    
PS    965217    165757    17:16:26:620    MPAL_2 - RRM_2    MSG_ID_MPAL_RR_DATA_IND    block_ind = RR_CONFLICT_WITH_PEER_GSM_OTHERS (enum 8)    
PS    965257    165937    17:16:27:560    MPAL_2 - RRM_2    MSG_ID_MPAL_RR_DATA_IND    block_ind = RR_BAD_BLOCK (enum 1)    
PS    965402    166205    17:16:28:900    MEME    MEME: PSC 307, RSCP -105, EcN0 -19, RRC_DB_CellType_detected, SyncInfo(0), TM(-28416), OFF(4), CIO 0, dbIdx 46, active 0        
PS    965502    166321    17:16:29:500    MPAL_2 - RRM_2    MSG_ID_MPAL_RR_DATA_IND    block_ind = RR_CONFLICT_WITH_PEER_GSM_OTHERS (enum 8)    
PS    965663    166459    17:16:30:190    MEME    MEME: PSC 307, RSCP -105, EcN0 -18, RRC_DB_CellType_detected, SyncInfo(0), TM(-28416), OFF(4), CIO 0, dbIdx 46, active 0        
OTA    965707    166465    17:16:30:190    ADR    [NW->MS] RRC__PAGING_TYPE1        ////paging
PS    965714    166465    17:16:30:190    RRCE    CN Paging: CS_DOMAIN, IMSI_TYPE, RRC_PagingCause_terminatingConversationalCall        
PS    965728    166512    17:16:30:455    MPAL_2 - RRM_2    MSG_ID_MPAL_RR_DATA_IND        
PS    965877    166697    17:16:31:220    MPAL_2 - RRM_2    MSG_ID_MPAL_RR_DATA_IND    block_ind = RR_CONFLICT_WITH_PEER_GSM_OTHERS (enum 8)    
PS    966223    166972    17:16:32:660    MEME    MEME: PSC 307, RSCP -104, EcN0 -18, RRC_DB_CellType_detected, SyncInfo(0), TM(-28416), OFF(4), CIO 0, dbIdx 46, active 0        
OTA    966269    166977    17:16:32:660    ADR    [NW->MS] RRC__PAGING_TYPE1        ////paging
PS    966276    166977    17:16:32:660    RRCE    CN Paging: CS_DOMAIN, IMSI_TYPE, RRC_PagingCause_terminatingConversationalCall        
PS    966278    166977    17:16:32:660    RRCE - RATCM    MSG_ID_RATCM_RRCE_PAGE_IND        
PS    966287    166982    17:16:32:660    MPAL_2 - RRM_2    MSG_ID_MPAL_RR_DATA_IND        
PS    966311    167074    17:16:33:265    MPAL_2 - RRM_2    MSG_ID_MPAL_RR_DATA_IND    block_ind = RR_CONFLICT_WITH_PEER_GSM_OTHERS (enum 8)    
PS    967823    167997    17:16:37:875    MEME    MEME: PSC 307, RSCP -106, EcN0 -20, RRC_DB_CellType_detected, SyncInfo(0), TM(-28416), OFF(4), CIO 0, dbIdx 46, active 0        
能夠看到,發起後,是有發送RRCE_CONN_EST_REQ進行鏈接創建的,
但隨後因信道資源與卡2發生衝突,致使該消息未能發送給網絡。
Type    Index    Time    Local Time    Module    Message    Comment    Time Different
OTA    964658    165177    17:16:23:780    SIBE    [NW->MS] RRC_SI_MIB (UARFCN:[10713], PSC:[307])        
PS    965119    165691    17:16:26:215    MEME    MEME: PSC 307, RSCP -105, EcN0 -19, RRC_DB_CellType_detected, SyncInfo(0), TM(-28416), OFF(4), CIO 0, dbIdx 46, active 0        
OTA    965158    165697    17:16:26:215    ADR    [NW->MS] RRC__PAGING_TYPE1        
OTA    965176    165697    17:16:26:215    MM    [MS->NW] MM__PAGING_RESPONSE        
PS    965182    165697    17:16:26:215    RATCM - RRCE    MSG_ID_RATCM_RRCE_CONN_EST_REQ        
PS    965192    165697    17:16:26:215    RRCE - CSCE    MSG_ID_CSCE_RRCE_RRC_CONNECTION_ESTABLISHMENT_IND        
PS    965213    165748    17:16:26:620    MPAL_2 - RRM_2    MSG_ID_MPAL_RR_DATA_IND    block_ind = RR_BAD_BLOCK (enum 1)    
PS    965217    165757    17:16:26:620    MPAL_2 - RRM_2    MSG_ID_MPAL_RR_DATA_IND    block_ind = RR_CONFLICT_WITH_PEER_GSM_OTHERS (enum 8)    
PS    965257    165937    17:16:27:560    MPAL_2 - RRM_2    MSG_ID_MPAL_RR_DATA_IND    block_ind = RR_BAD_BLOCK (enum 1)    
PS    965402    166205    17:16:28:900    MEME    MEME: PSC 307, RSCP -105, EcN0 -19, RRC_DB_CellType_detected, SyncInfo(0), TM(-28416), OFF(4), CIO 0, dbIdx 46, active 0        
PS    965502    166321    17:16:29:500    MPAL_2 - RRM_2    MSG_ID_MPAL_RR_DATA_IND    block_ind = RR_CONFLICT_WITH_PEER_GSM_OTHERS (enum 8)    
PS    965663    166459    17:16:30:190    MEME    MEME: PSC 307, RSCP -105, EcN0 -18, RRC_DB_CellType_detected, SyncInfo(0), TM(-28416), OFF(4), CIO 0, dbIdx 46, active 0        

Log最後的兩通MT被網絡release,經檢查發現該兩通paging攜帶的ID爲IMSI,2#和對比機8#中接收到的ID都爲TMSI,
這與以前貴司提的一筆問題相似, 一樣請交換SIM卡後,進行復測。
Type    Index    Time    Local Time    Module    Message    Comment    Time Different
OTA    1480308    239650    17:22:36:075    ADR    [NW->MS] RRC__PAGING_TYPE1    Mobile Identity Type: IMSI     
OTA    1480326    239650    17:22:36:075    MM    [MS->NW] MM__PAGING_RESPONSE        
OTA    1482155    239827    17:22:36:885    ADR    [NW->MS] RRC__RRC_CONNECTION_RELEASE_DCCH        
OTA    1482167    239827    17:22:36:885    ADR    [MS->NW] RRC__RRC_CONNECTION_RELEASE_COMPLETE        
OTA    1483590    239906    17:22:37:285    ADR    [NW->MS] RRC__PAGING_TYPE1    Mobile Identity Type: IMSI     
OTA    1483608    239906    17:22:37:285    MM    [MS->NW] MM__PAGING_RESPONSE        
OTA    1485855    240083    17:22:38:285    ADR    [NW->MS] RRC__RRC_CONNECTION_RELEASE_DCCH        
OTA    1485920    240092    17:22:38:285    ADR    [MS->NW] RRC__RRC_CONNECTION_RELEASE_COMPLETE    

2一、關於當前駐留小區的查看

OTA (PCORE) 2206372 41749843 14:45:10:528 RRM_TDD_2 [NW->MS] RR__SI_5TER (ARFCN[656], TC[255])
//log中有這個網絡發給終端的系統消息收到就說明終端已經駐留到這個小區了嗎仍是別的意思
====================
通常來講是駐留在此小區,可是在尚未駐留此小區搜網絡的時候也會蒐集系統消息的顯示此信令

更新:
OTA (PCORE)    2204618    41698342    14:45:07:289    RRM_TDD_2    [NW->MS] RR__SI_5 (ARFCN[656], TC[255])        
OTA (PCORE)    2204767    41703189    14:45:07:689    RRM_TDD_2    [MS->NW] RR__MEASUREMENT_REPORT        
OTA (PCORE)    2204799    41703397    14:45:07:689    RRM_TDD_2    [NW->MS] RR__ASSIGNMENT_COMMAND        
OTA (PCORE)    2204847    41704331    14:45:07:689    RRM_TDD_2    [MS->NW] RR__ASSIGNMENT_COMPLETE
從新指配完成後,發生ERROR_TIMER_EXPD_N200_ABNORMAL_REL的底層失敗,        
PS (PCORE)    2205367    41719561    14:45:08:709    L1HISR - RRM_TDD_2    MSG_ID_LAPDM_RR_REL_IND    
...
            error_cause = ERROR_TIMER_EXPD_N200_ABNORMAL_REL (enum 2)
            channel_type = FACCH (enum 25)
...            
從新在2G ARFCN[656]小區創建起鏈接:
PS (PCORE)    2205371    41719563    14:45:08:709    RRM_TDD_2 - MPAL_TDD_2    MSG_ID_RR_MPAL_DEDICATED_CHANNEL_RECONNECT_REQ        
PS (PCORE)    2205394    41719779    14:45:08:709    MPAL_TDD_2 - RRM_TDD_2    MSG_ID_MPAL_RR_DEDICATED_CHANNEL_RECONNECT_CNF
而且給網絡報告說底層發生了一次錯誤,    
OTA (PCORE)    2205398    41719780    14:45:08:709    RRM_TDD_2    [MS->NW] RR__ASSIGNMENT_FAILURE
...
RR Cause
RR cause value: Protocol error unspecified (111)
...
PS (PCORE)    2205399    41719780    14:45:08:709    RRM_TDD_2    RRM_SUBSTATE = RRM_DEDICATED_RECON_L2_SUBSTATE    
            
PS (PCORE)    2205795    41732610    14:45:09:528    MPAL_TDD_2 - RRM_TDD_2    MSG_ID_MPAL_RR_SERV_DEDI_MEAS_IND        
OTA (PCORE)    2206372    41749843    14:45:10:528    RRM_TDD_2    [NW->MS] RR__SI_5TER (ARFCN[656], TC[255])    
因此此問題的仍是後面CC DISCONNECT,casue No circuit/channel available,與前面的RR__ASSIGNMENT_FAILURE沒有關係,RR__ASSIGNMENT_FAILURE只是發生了底層錯誤恢復鏈接後給網絡報告Protocol error unspecified (111)狀況,後面又正常恢復在ARFCN[656]小區:
CC DISCONNECT,casue No circuit/channel available通常爲網絡資源調配的問題,判斷爲網絡緣由    
OTA (PCORE)    2206533    41754893    14:45:10:944    CC_2    [NW->MS] CC__DISCONNECT    
...
Cause - (34) No circuit/channel available
...        

22.4G下TAU異常致使沒法接收paging

主叫端無異常:
Type    Index    Time    Local Time    Module    Message    Comment    Time Different
SYS (PCORE)    798859    1619414071    14:57:48:396    NIL    [AT_I p21, s10]ATD18576395029;        
SYS (PCORE)    799090    1619414101    14:57:48:396    NIL    [AT_U p19, s8]+ECPI: 1,130,0,0,0,0,"18576395029",129,""    
SYS (PCORE)    861706    1619620021    14:58:01:396    NIL    [AT_U p19, s8]+ECPI: 1,2,1,1,0,20,"18576395029",129,""    
SYS (PCORE)    998804    1619863549    14:58:16:998    NIL    [AT_I p19, s8]AT+CHLD=11        

經查看被叫端log,在14:57:40前一通CC釋放以後,UE 回到4G,作TAU
可是發出EMM_Tracking_Area_Update_Request一直沒有收到網絡回覆,直到EMM_T3430 is expired超時
因而UE側將鏈接釋放,14:57:55:916從新選擇小區,創建鏈接
再次發起作TAU,但網絡將之拒絕:EMM_Tracking_Area_Update_Reject,cause爲UE identity cannot be derived by the network(9)
Spec24.301有對該cause進行描述If the rejected request was not for initiating a PDN connection for emergency bearer services, the UE shall subsequently, automatically initiate the attach procedure.
隨後UE從新發起attach成功駐網,UE行爲符合SPEC規定,並沒有異常
【致使該通失敗的緣由主要是】:在這接近半分鐘左右的時間裏,作TAU時網絡端出現異常致使的
至於網絡端爲什麼會出現該異常,從UE側沒法獲知,請知悉。

如下爲具體發生TAU異常的trace:
Type    Index    Time    Local Time    Module    Message    Comment    Time Different
OTA (PCORE)    842370    1686986316    14:57:40:755    ERRC_SYS    [NW->MS] SystemInformationBlockType1 (EARFCN[451], PCI[397])        
PS (PCORE)    843178    1686986522    14:57:40:755    ERRC_MOB    [MRM] store PCell: earfcn[451] pci[397] rsrp[-350] rsrq[-19] sinr[125] snr[125] cell_off[0]        
OTA (PCORE)    847251    1686987705    14:57:40:755    EMM_NASMSG    [MS->NW] EMM_Tracking_Area_Update_Request(EPS update type="EMM_UPDATE_TYPE_COMBINED_TAU", active flag="KAL_FALSE")        //第一次發起TAU,但一直沒收到網絡響應,直到超時
PS (PCORE)    858180    1687221829    14:57:55:916    ERRC_MOB    [MRM] store PCell: earfcn[451] pci[397] rsrp[-364] rsrq[-13] sinr[128] snr[128] cell_off[0]        
PS (PCORE)    858201    1687222080    14:57:55:916    EMM    [EMM TIMER] TIMER ID: EMM_T3430 is expired        
PS (PCORE)    858280    1687222084    14:57:55:916    EMM - ERRC    MSG_ID_EMM_ERRC_RELEASE_REQ    cause = ENASAS_LOCAL_REL    //超時後,UE側將鏈接釋放掉
OTA (PCORE)    859370    1687222567    14:57:55:916    ERRC_SYS    [NW->MS] SystemInformationBlockType1 (EARFCN[451], PCI[397])        
PS (PCORE)    859941    1687222737    14:57:55:916    ERRC - EMM    MSG_ID_EMM_ERRC_CELLSELECT_IND        
OTA (PCORE)    861773    1687379718    14:58:05:952    EMM_NASMSG    [MS->NW] EMM_Tracking_Area_Update_Request(EPS update type="EMM_UPDATE_TYPE_COMBINED_TAU", active flag="KAL_FALSE")        //從新創建鏈接,再次發起TAU
OTA (PCORE)    861979    1687380504    14:58:05:952    EMM_NASMSG    [NW->MS] EMM_Tracking_Area_Update_Reject(EMM cause="EMM_CAUSE_UE_ID_NOT_DERIVED_BY_NW")     Cause: UE identity cannot be derived by the network (9)    //網絡將之拒絕
OTA (PCORE)    870020    1687382653    14:58:06:152    EMM_NASMSG    [MS->NW] EMM_Attach_Request(EPS attach type="EMM_ATTACH_TYPE_COMBINED_ATTACH")        //隨後UE發起attach併成功駐網
OTA (PCORE)    872281    1687390274    14:58:06:556    EMM_NASMSG    [NW->MS] EMM_Attach_Accept(EPS attach result="EMM_ATTACH_RESULT_COMBINED_ATTACHED")        
OTA (PCORE)    892158    1687595157    14:58:19:736    ERRC_CONN    [NW->MS] ERRC_RRCConnectionRelease(cause:[ReleaseCause_other], redirectInfo:[0])        
OTA (PCORE)    894782    1687919692    14:58:40:579    ERRC_CEL    [NW->MS] PAGING, PagingRecordList[KAL_TRUE], SIB Modification[KAL_FALSE], ETWS[KAL_FALSE], CMAS[KAL_FALSE], EAB[KAL_FALSE]        
OTA (PCORE)    896053    1687920962    14:58:40:579    EMM_NASMSG    [MS->NW] EMM_Extended_Service_Request(service type="MT_CSFB", CSFB response="CSFB_ACCEPTED_BY_UE")        

2三、移動3G下因爲RLF而斷開鏈接(區分網絡主動release的狀況)

在spec25.331中8.5.6節對RLF處理有以下描述:
For FDD in CELL_DCH state and in TDD when a radio link failure occurs, the UE shall:
1> clear the dedicated physical channel configuration;
1> perform actions as specified for the ongoing procedure;
1> if no procedure is ongoing or no actions are specified for the ongoing procedure:
2> perform a cell update procedure according to subclause 8.3.1 using the cause "radio link failure".
通話斷開是由於RLF,發生RLF以後會發起cell update,並 有計數器V302進行數,屢次發送,直到達到最大計數或收到網絡響應後,釋放鏈接。

OTA (PCORE) 6759419 1715254669 15:17:23:179 ADR_TDD [NW->MS] TDD_RRC__RRC_CONNECTION_RELEASE_CCCH //log

可查看log中RRC_CONNECTION_RELEASE的release cause,
若是是網絡正常主動釋放鏈接,會攜帶releaseCause: normalEvent (0)
在發生Cell update上報RLF後,網絡釋放鏈接的releaseCause: unspecified

2四、手機在空閒態也會讀取其餘小區的系統消息,查看當前服務小區

手機在空閒態時會去讀鄰區的系統消息,這個是正常的。手機在這段時間內並無進行太重選,一直在519小區。


Type    Index    Time    Local Time    Module    Message    Comment    Time Different
OTA    114847    18941871    11:13:20:700    CC    [NW->MS] CC__DISCONNECT        
OTA    114863    18941871    11:13:20:700    CC    [MS->NW] CC__RELEASE        
OTA    115269    18941919    11:13:21:100    CC    [NW->MS] CC__RELEASE_COMPLETE        
PS    119431    18942345    11:13:23:220    MPAL - RRM    MSG_ID_MPAL_RR_DATA_IND        
PS    119725    18942415    11:13:23:420    RRM    [RMC] Serv arfcn[519]: RAC[3], C1[142], C2[582]        
PS    120462    18942533    11:13:24:020    MPAL - RRM    MSG_ID_MPAL_RR_DATA_IND        
PS    120723    18942607    11:13:24:420    RRM    [RMC] Serv arfcn[519]: RAC[3], C1[142], C2[582]        
PS    121087    18942721    11:13:25:020    MPAL - RRM    MSG_ID_MPAL_RR_DATA_IND        
PS    121224    18942799    11:13:25:420    RRM    [RMC] Serv arfcn[519]: RAC[3], C1[143], C2[583]        
PS    121407    18942910    11:13:26:020    MPAL - RRM    MSG_ID_MPAL_RR_DATA_IND        
PS    121477    18942955    11:13:26:295    MPAL - RRM    MSG_ID_MPAL_RR_DATA_IND        
PS    121610    18943106    11:13:26:965    MPAL - RRM    MSG_ID_MPAL_RR_DATA_IND        
PS    121700    18943332    11:13:27:985    MPAL - RRM    MSG_ID_MPAL_RR_DATA_IND        
PS    121917    18943520    11:13:29:120    MPAL - RRM    MSG_ID_MPAL_RR_DATA_IND        
PS    121952    18943708    11:13:29:870    MPAL - RRM    MSG_ID_MPAL_RR_DATA_IND        
//serv arfcn 表示當前駐留小區,能夠看到,一直沒有變過。
PS    121990    18943708    11:13:29:870    RRM    [RMC] Serv arfcn[519]: RAC[3], C1[139], C2[579]        
//這裏就是讀鄰小區信息,目的是重選時能夠更快駐留到目標小區,節約時間。
PS    122076    18943749    11:13:30:115    RRM - MPAL    MSG_ID_RR_MPAL_NEIGHBOR_SYS_INFO_READ_REQ        
OTA    122082    18943760    11:13:30:320    RRM    [NW->MS] RR__SI_3 (ARFCN[78], TC[6])        
PS    122083    18943760    11:13:30:320    RRM - MPAL    MSG_ID_RR_MPAL_NEIGHBOR_SYS_INFO_STOP_REQ        
PS    122240    18943860    11:13:30:730    MPAL - RRM    MSG_ID_MPAL_RR_DATA_IND        
PS    122366    18944049    11:13:31:745    MPAL - RRM    MSG_ID_MPAL_RR_DATA_IND        
PS    122613    18944236    11:13:32:615    MPAL - RRM    MSG_ID_MPAL_RR_DATA_IND        
PS    122767    18944425    11:13:33:630    MPAL - RRM    MSG_ID_MPAL_RR_DATA_IND        
PS    122993    18944650    11:13:34:580    MPAL - RRM    MSG_ID_MPAL_RR_DATA_IND        
PS    123062    18944650    11:13:34:580    RRM    [RMC] Serv arfcn[519]: RAC[3], C1[143], C2[583]        
PS    123104    18944838    11:13:35:520    MPAL - RRM    MSG_ID_MPAL_RR_DATA_IND        
PS    123249    18945026    11:13:36:465    MPAL - RRM    MSG_ID_MPAL_RR_DATA_IND        
PS    123293    18945215    11:13:37:405    MPAL - RRM    MSG_ID_MPAL_RR_DATA_IND        
PS    123328    18945403    11:13:38:345    MPAL - RRM    MSG_ID_MPAL_RR_DATA_IND        
PS    123477    18945591    11:13:39:285    MPAL - RRM    MSG_ID_MPAL_RR_DATA_IND        
PS    123541    18945591    11:13:39:285    RRM    [RMC] Serv arfcn[519]: RAC[3], C1[142], C2[582]        
PS    123603    18945780    11:13:40:230    MPAL - RRM    MSG_ID_MPAL_RR_DATA_IND        

2五、N200的底層確認

1.At time 27896673; N200 abnormal expiry observed (MSG_ID_LAPDM_RR_ERROR_IND, channel_type= SDCCH). UE failed to receive L2 ack for MM__AUTHENTICATION_RESPONSE msg.
2. Checked Downlink status and it has been observed that on serving arfcn 70 antenna power in range of ~-7x dbm to ~-9xdbm. SNR conditions are good and UE is able to decode all the sdcch blocks successfully so there is no issue at Rx.
3.At uplink side; UE is transmitting with 33 dBm, NB and TA= 4Qb which indicates that UE is little far from Network and NW could miss MM__AUTHENTICATION_RESPONSE because of this therefore it didn't respond with L2ack which leads to expiry of N200 timer.
4.Due to bad TX status, N200 timeout happened. It seems to be temporary network issue.

2六、一張卡作業務,另外一張卡被suspend的實例

我通常習慣搜索suspend和resume,能夠看到這段時間有以下經歷
Type    Index    Time    Local Time    Module    Message    Comment    Time Different
PS (PCORE)    470370    154694385    11:30:01:185    RSVAS - RRM_FDD_2    MSG_ID_RSVAS_GAS_SUSPEND_SERVICE_REQ        //卡1要LU,卡2被suspend
PS (PCORE)    470541    154694404    11:30:01:185    RRM_FDD_2 - MPAL_FDD_2    MSG_ID_RR_MPAL_SUSPEND_REQ        
PS (PCORE)    470542    154694404    11:30:01:185    RRM_FDD_2 - RSVAS    MSG_ID_RSVAS_GAS_SUSPEND_SERVICE_CNF        
PS (PCORE)    470591    154694408    11:30:01:185    RRM_FDD_2 - RATCM_2    MSG_ID_RATCM_GAS_SUSPEND_IND        
PS (PCORE)    480699    154725849    11:30:03:199    RSVAS - RRM_FDD_2    MSG_ID_RSVAS_GAS_VIRTUAL_RESUME_SERVICE_REQ        //卡1的LU結束CS鏈接斷開,但RRC鏈接尚未釋放,因此卡2進入virtual狀態
PS (PCORE)    480773    154725858    11:30:03:199    RRM_FDD_2 - MPAL_FDD_2    MSG_ID_RR_MPAL_VIRTUAL_RESUME_REQ        
PS (PCORE)    480774    154725858    11:30:03:199    RRM_FDD_2 - RATCM_2    MSG_ID_RATCM_GAS_RESUME_IND        
PS (PCORE)    491223    154774778    11:30:06:209    RSVAS - RRM_FDD_2    MSG_ID_RSVAS_GAS_RESUME_SERVICE_REQ        //RRC鏈接斷開,卡2完全resume
PS (PCORE)    491619    154774806    11:30:06:209    RRM_FDD_2 - MPAL_FDD_2    MSG_ID_RR_MPAL_RESUME_REQ        
PS (PCORE)    500404    154843538    11:30:10:676    RSVAS - RRM_FDD_2    MSG_ID_RSVAS_GAS_SUSPEND_SERVICE_REQ        //卡1要LU,卡2被suspend
PS (PCORE)    500590    154843562    11:30:10:676    RRM_FDD_2 - MPAL_FDD_2    MSG_ID_RR_MPAL_SUSPEND_REQ        
PS (PCORE)    500591    154843562    11:30:10:676    RRM_FDD_2 - RSVAS    MSG_ID_RSVAS_GAS_SUSPEND_SERVICE_CNF        
PS (PCORE)    500621    154843564    11:30:10:676    RRM_FDD_2 - RATCM_2    MSG_ID_RATCM_GAS_SUSPEND_IND        
PS (PCORE)    508392    154875355    11:30:12:688    RSVAS - RRM_FDD_2    MSG_ID_RSVAS_GAS_VIRTUAL_RESUME_SERVICE_REQ        //卡1的LU結束CS鏈接斷開,但RRC鏈接尚未釋放,因此卡2進入virtual狀態
PS (PCORE)    508466    154875365    11:30:12:688    RRM_FDD_2 - MPAL_FDD_2    MSG_ID_RR_MPAL_VIRTUAL_RESUME_REQ        
PS (PCORE)    508467    154875365    11:30:12:688    RRM_FDD_2 - RATCM_2    MSG_ID_RATCM_GAS_RESUME_IND        
PS (PCORE)    516908    154908657    11:30:14:897    RSVAS - RRM_FDD_2    MSG_ID_RSVAS_GAS_RESUME_SERVICE_REQ        //RRC鏈接斷開,卡2完全resume
PS (PCORE)    517126    154908679    11:30:14:897    RRM_FDD_2 - MPAL_FDD_2    MSG_ID_RR_MPAL_RESUME_REQ        

2七、通話的下發流程

csm cc mm

從log中看,這通call最終沒有撥打成功。直接緣由是上一通電話掛斷後,網絡沒有釋放RRC鏈接,同時以後手機發送消息都沒法獲得網絡的回覆。
具體log以下:
Type    Index    Time    Local Time    Module    Message    Comment    Time Different
OTA    220801    515938    09:45:22:410    CC    [MS->NW] CC__RELEASE_COMPLETE        //上一通電話結束
PS    220824    515938    09:45:22:410    MM    MM_T3240_TIMER_ID Timer starts, period = 2000        //啓動T3240,等網絡下發消息
SYS    233838    516875    09:45:27:010    NIL    [AT_I p20, s10]ATD13509237401;
SYS    234100    516876    09:45:27:010    NIL    [IMSP_AT_I s21]ATD13509237401;        //撥打電話(三次嘗試創建鏈接)
PS    234356    516877    09:45:27:210    CC - MM    MSG_ID_MMCC_EST_REQ        //第一次嘗試 攜帶speech call emergency call 附加csmt等緣由
PS    234357    516877    09:45:27:210    MM    CM service request is pended because of MM in state MM_WAIT_FOR_NETWORK_COMMAND        //此時T3240在run,手機須要等網絡的消息
OTA    257559    517938    09:45:32:410    MM    [MS->NW] MM__LOCATION_UPDATING_REQUEST (LU type: MM_NORMAL_LU)        //T3240結束後,須要進行LU
PS    347027    521938    09:45:52:410    MM    MM_T3210_TIMER_ID Timer expires in state MM_LOCATION_UPDATING_INITIATED        //LU沒有獲得網絡的任何回覆,致使T3210超時
PS    347080    521938    09:45:52:410    MM - CC    MSG_ID_MMCC_EST_REJ        //LU沒有成功,致使第一次嘗試失敗
PS    384697    523639    09:46:01:010    CC - MM    MSG_ID_MMCC_EST_REQ        //第二次嘗試
OTA    384701    523639    09:46:01:010    MM    [MS->NW] MM__CM_SERVICE_REQUEST        
PS    384834    523639    09:46:01:010    MM    MM_T3230_TIMER_ID Timer starts, period = 3000        
PS    451774    526641    09:46:16:010    MM    CM service rejected because T3230 expiry        //發送CM service request網絡沒有迴應,T3230超時
PS    451775    526641    09:46:16:010    MM - CC    MSG_ID_MMCC_EST_REJ        //第二次嘗試失敗
PS    451780    526641    09:46:16:010    MM    MM_T3240_TIMER_ID Timer starts, period = 2000        //嘗試失敗後,需等網絡下發消息
PS    489859    528343    09:46:24:410    CC - MM    MSG_ID_MMCC_EST_REQ        //第三次嘗試(此時T3240還在run)
PS    496418    528641    09:46:26:010    MM    MM_T3240_TIMER_ID Timer expires in state MM_WAIT_FOR_NETWORK_COMMAND        //T3240超時
OTA    496475    528641    09:46:26:010    MM    [MS->NW] MM__LOCATION_UPDATING_REQUEST (LU type: MM_NORMAL_LU)        //須要LU
PS    496614    528641    09:46:26:010    MM    MM_T3210_TIMER_ID Timer starts, period = 4000        
PS    585471    532641    09:46:46:010    MM    MM_T3210_TIMER_ID Timer expires in state MM_LOCATION_UPDATING_INITIATED        //LU沒有獲得網絡的任何回覆,致使T3210超時
PS    585522    532641    09:46:46:010    MM    CM rej because LU is rejected        //LU沒有成功,致使第三次嘗試失敗
PS    585524    532641    09:46:46:010    MM - CC    MSG_ID_MMCC_EST_REJ        
2八、3G下的RLF底層確認

底層RD分析以下:
The reason for not receiving any thing in DL and RLF is sudden drop of DL DPCH power even though CPICH quality is good.
This has decreased drastically from 3000 to -2000 in one frame at 09:45:23:805.
Generally we see this behavior when NW releases the connection. NW may release connection when some old Procedure is pending or some issue from NW side itself.

From the logs I see UE got RLC ACK for all the packets sent till 09:45:22:410 (CC_RELEASE_COMPLETE) on RB3 and ACTIVE_SET_UPDATE_COMPLETE on RB2. So there is no pending procedure which can cause the NW to release the connection abruptly.
So this looks to be NW issue.

2九、WCDMA的激活集

PS    1431826    297842    09:12:04:200    MEME    MEME: PSC 260, RSCP -102 (-105 ,-104), EcN0 -18 (-20 ,-19), RRC_DB_CellType_monitored, SyncInfo(1), TM(24320), OFF(124), CIO 0, dbIdx 5, active 1
測量的結果後面打印active 1證實該小區是在激活集內。active 0表示不是激活集內的小區。
激活集是指與UE有無線鏈路RL鏈接的小區的集合,能夠有1個,2個,3個。這個是WCDMA軟切換的需求。

當前激活集一開始只有PSC260,若是當前激活集中只有一個小區,那麼這個小區就是服務小區。
後面上報E1A加入168和81,這種狀況下只有260仍是處於激活集當中就仍是服務小區。
固然駐留的小區的判斷能夠有其餘,從LOG中能夠看他在哪一個小區發起LAU,或者有服務小區改變的trace.也能夠從手機工模裏面看當前服務小區的ARFCN和PSC。
小區改變的trace:
Type    Index    Time    Local Time    Module    Message    Comment    Time Different
PS    391705    270136    09:09:45:800    MEME    MEME: Serving cell changed from uarfcn 10713 PSC 81 (Idx 23) to uarfcn 10713 PSC 260 (Idx 48)        
激活集變化狀況:
Type    Index    Time    Local Time    Module    Message    Comment    Time Different
PS    1431030    297822    09:12:04:200    MEME    MEME: PSC 260, RSCP -106 (-106 ,-106), EcN0 -22 (-22 ,-22), RRC_DB_CellType_monitored, SyncInfo(1), TM(24320), OFF(124), CIO 0, dbIdx 5, active 1    //當前激活集只有一個,260    
OTA    1431212    297826    09:12:04:200    ADR    [NW->MS] RRC__ADD PSC [168] - RRC__ACTIVESET_UPDATE    //網絡下發ACTIVESET_UPDATE+168    
PS    1431826    297842    09:12:04:200    MEME    MEME: PSC 260, RSCP -102 (-105 ,-104), EcN0 -18 (-20 ,-19), RRC_DB_CellType_monitored, SyncInfo(1), TM(24320), OFF(124), CIO 0, dbIdx 5, active 1    //當前激活集 260、168    
PS    1431827    297842    09:12:04:200    MEME    MEME: PSC 168, RSCP -110 (-110 ,-110), EcN0 -25 (-24 ,-24), RRC_DB_CellType_monitored, SyncInfo(1), TM(20669), OFF(118), CIO 0, dbIdx 20, active 1        
OTA    1434866    297930    09:12:04:600    ADR    [NW->MS] RRC__ADD PSC [81] - RRC__ACTIVESET_UPDATE    //網絡下發ACTIVESET_UPDATE+81    
PS    1437851    298000    09:12:05:000    MEME    MEME: PSC 168, RSCP -100 (-102 ,-101), EcN0 -25 (-24 ,-24), RRC_DB_CellType_monitored, SyncInfo(1), TM(20669), OFF(118), CIO 0, dbIdx 20, active 1    //當前激活集260.168.81    
PS    1437852    298000    09:12:05:000    MEME    MEME: PSC 260, RSCP -99 (-101 ,-100), EcN0 -25 (-24 ,-24), RRC_DB_CellType_monitored, SyncInfo(1), TM(24320), OFF(124), CIO 0, dbIdx 5, active 1        
PS    1437853    298000    09:12:05:000    MEME    MEME: PSC 81, RSCP -99 (-102 ,-101), EcN0 -25 (-24 ,-24), RRC_DB_CellType_monitored, SyncInfo(1), TM(17517), OFF(35), CIO 0, dbIdx 23, active 1    
-------------------------------------------------------------------------------------------------------------
很差意思以前說錯,是E1C事件,上報E1C,代表測量到有小區比激活集小區信號好,網絡收到E1C事件應該替換該小區進入到激活集中。
OTA    1437946    298000    09:12:05:000    ADR    [MS->NW] RRC__INTRA_e1C [276] [278] [178] [81] [168] [260] - MEASUREMENT_REPORT  

第一次log分析:  

測試機MO端:EcN0 -25很是差,致使發送RLF,通話掉話。之間激活集有3個cell,上報了E3C事,並無ACTIVESET_UPDATE的動做。

Type    Index    Time    Local Time    Module    Message    Comment    Time Different
OTA    1431212    297826    09:12:04:200    ADR    [NW->MS] RRC__ADD PSC [168] - RRC__ACTIVESET_UPDATE    //+cell 168    
PS    1431824    297842    09:12:04:200    MEME    MEME: PSC 276, RSCP -88 (-88 ,-88), EcN0 -4 (-4 ,-4), RRC_DB_CellType_detected, SyncInfo(1), TM(22901), OFF(18), CIO 0, dbIdx 64, active 0        
PS    1431825    297842    09:12:04:200    MEME    MEME: PSC 278, RSCP -93 (-94 ,-94), EcN0 -9 (-10 ,-10), RRC_DB_CellType_detected, SyncInfo(1), TM(21877), OFF(18), CIO 0, dbIdx 94, active 0        
PS    1431826    297842    09:12:04:200    MEME    MEME: PSC 260, RSCP -102 (-105 ,-104), EcN0 -18 (-20 ,-19), RRC_DB_CellType_monitored, SyncInfo(1), TM(24320), OFF(124), CIO 0, dbIdx 5, active 1    //當前激活集 260、168    
PS    1431827    297842    09:12:04:200    MEME    MEME: PSC 168, RSCP -110 (-110 ,-110), EcN0 -25 (-24 ,-24), RRC_DB_CellType_monitored, SyncInfo(1), TM(20669), OFF(118), CIO 0, dbIdx 20, active 1        
OTA    1434866    297930    09:12:04:600    ADR    [NW->MS] RRC__ADD PSC [81] - RRC__ACTIVESET_UPDATE    //+cell 81    
PS    1437851    298000    09:12:05:000    MEME    MEME: PSC 168, RSCP -100 (-102 ,-101), EcN0 -25 (-24 ,-24), RRC_DB_CellType_monitored, SyncInfo(1), TM(20669), OFF(118), CIO 0, dbIdx 20, active 1    //當前激活集260.168.81    
PS    1437852    298000    09:12:05:000    MEME    MEME: PSC 260, RSCP -99 (-101 ,-100), EcN0 -25 (-24 ,-24), RRC_DB_CellType_monitored, SyncInfo(1), TM(24320), OFF(124), CIO 0, dbIdx 5, active 1        
PS    1437853    298000    09:12:05:000    MEME    MEME: PSC 81, RSCP -99 (-102 ,-101), EcN0 -25 (-24 ,-24), RRC_DB_CellType_monitored, SyncInfo(1), TM(17517), OFF(35), CIO 0, dbIdx 23, active 1        
OTA    1437946    298000    09:12:05:000    ADR    [MS->NW] RRC__INTRA_e1C [276] [278] [178] [81] [168] [260] - MEASUREMENT_REPORT    //上報E1C,代表測量到有小區比激活集小區信號好    
PS    1437947    298000    09:12:05:000    MEME - DRLC    MSG_ID_RLC_AM_DATA_REQ    MUI =1952    
PS    1441389    298082    09:12:05:400    URLC - ADR    MSG_ID_RLC_AM_DATA_CNF    MUI[0] = 1952    
PS    1462458    298510    09:12:07:600    MEME    MEME: PSC 260, RSCP -105 (-105 ,-105), EcN0 -25 (-24 ,-24), RRC_DB_CellType_monitored, SyncInfo(1), TM(24320), OFF(124), CIO 0, dbIdx 5, active 1        
PS    1462459    298510    09:12:07:600    MEME    MEME: PSC 81, RSCP -105 (-105 ,-105), EcN0 -25 (-24 ,-24), RRC_DB_CellType_monitored, SyncInfo(1), TM(17517), OFF(35), CIO 0, dbIdx 23, active 1        
PS    1462878    298520    09:12:07:600    MEME    MEME: PSC 168, RSCP -105 (-105 ,-105), EcN0 -25 (-24 ,-24), RRC_DB_CellType_monitored, SyncInfo(1), TM(20669), OFF(118), CIO 0, dbIdx 20, active 1        
PS    1471405    298750    09:12:08:800    MEME    MEME: PSC 168, RSCP -105 (-105 ,-105), EcN0 -25 (-24 ,-24), RRC_DB_CellType_monitored, SyncInfo(1), TM(20669), OFF(118), CIO 0, dbIdx 20, active 1        
PS    1471407    298750    09:12:08:800    MEME    MEME: PSC 81, RSCP -105 (-105 ,-105), EcN0 -25 (-24 ,-24), RRC_DB_CellType_monitored, SyncInfo(1), TM(17517), OFF(35), CIO 0, dbIdx 23, active 1        
PS    1471743    298760    09:12:08:800    MEME    MEME: PSC 260, RSCP -105 (-105 ,-105), EcN0 -24 (-24 ,-24), RRC_DB_CellType_monitored, SyncInfo(1), TM(24320), OFF(124), CIO 0, dbIdx 5, active 1        
PS    1473355    298810    09:12:09:000    MEME    MEME: PSC 260, RSCP -104 (-104 ,-104), EcN0 -24 (-24 ,-24), RRC_DB_CellType_monitored, SyncInfo(1), TM(24320), OFF(124), CIO 0, dbIdx 5, active 1        
PS    1473356    298810    09:12:09:000    MEME    MEME: PSC 168, RSCP -104 (-105 ,-104), EcN0 -25 (-24 ,-24), RRC_DB_CellType_monitored, SyncInfo(1), TM(20669), OFF(118), CIO 0, dbIdx 20, active 1        
PS    1473357    298810    09:12:09:000    MEME    MEME: PSC 81, RSCP -105 (-105 ,-105), EcN0 -25 (-24 ,-24), RRC_DB_CellType_monitored, SyncInfo(1), TM(17517), OFF(35), CIO 0, dbIdx 23, active 1        
PS    1473582    298816    09:12:09:200    UL1 - RRCE    MSG_ID_CPHY_RL_FAILURE_IND        //底層發生RLF
OTA    1477984    299009    09:12:10:000    ADR    [MS->NW] RRC__CELL_UPDATE    cellUpdateCause = radiolinkFailure    
OTA    1484761    299241    09:12:11:200    ADR    [MS->NW] RRC__CELL_UPDATE    cellUpdateCause = radiolinkFailure    
OTA    1490380    299457    09:12:12:400    ADR    [MS->NW] RRC__CELL_UPDATE    cellUpdateCause = radiolinkFailur

30、查看ERRC層的狀態

網絡下發這一條的時候UE已經處於connected mode網絡是不會經過paging來通知UE的而是直接發送。
另外debug paging這部分log是屬於底層log按照公司的規定是不能夠貼出來的請見諒。
Type    Index    Time    Local Time    Module    Message    Comment    Time Different
PS (PCORE)    167890    1196651731    08:32:21:744    ERRC_CONN    [CONN]state trasition: current=CONN_RECONF ---> next=CONN_CONNECTED        
PS (PCORE)    169489    1196653094    08:32:21:946    ERRC_CONN    [CONN]state trasition: current=CONN_CONNECTED ---> next=CONN_RECONF        
PS (PCORE)    170203    1196653242    08:32:21:946    ERRC_CONN    [CONN]state trasition: current=CONN_RECONF ---> next=CONN_CONNECTED        
PS (PCORE)    171643    1196658874    08:32:22:168    ERRC_CONN    [CONN]state trasition: current=CONN_CONNECTED ---> next=CONN_RECONF        
PS (PCORE)    172254    1196659041    08:32:22:369    ERRC_CONN    [CONN]state trasition: current=CONN_RECONF ---> next=CONN_CONNECTED     

3一、GSM空閒態查看服務小區

針對acc 手機恰好被限制的case, 2G 底層分析以下:

7513, 2143057, 10684298, 22:51:26:260 2017/06/08, MOD_RRM_2, , TRACE_PEER, [NW->MS] RR__SI_13 (ARFCN[660], TC[4])

5658, 2141012, 10682454, 22:51:17:050 2017/06/08, MOD_RRM_2, , TRACE_GROUP_1, [RMC] Serv arfcn[660]: RAC[0], C1[115], C2[171]
6380, 2141953, 10683301, 22:51:21:285 2017/06/08, MOD_RRM_2, , TRACE_GROUP_1, [RMC] Serv arfcn[660]: RAC[0], C1[116], C2[172]
7183, 2142680, 10683950, 22:51:24:520 2017/06/08, MOD_RRM_2, , TRACE_GROUP_1, [RMC] Serv arfcn[660]: RAC[0], C1[124], C2[180]
8271, 2143766, 10684996, 22:51:29:760 2017/06/08, MOD_RRM_2, , TRACE_GROUP_1, [RMC] Serv arfcn[660]: RAC[0], C1[116], C2[172]
27497, 2154170, 10694600, 22:52:17:780 2017/06/08, MOD_RRM_2, , TRACE_GROUP_1, [RMC] Serv arfcn[660]: RAC[0], C1[93], C2[149]
28236, 2154919, 10695248, 22:52:21:010 2017/06/08, MOD_RRM_2, , TRACE_GROUP_1, [RMC] Serv arfcn[660]: RAC[0], C1[76], C2[132]
30424, 2156948, 10697142, 22:52:30:490 2017/06/08, MOD_RRM_2, , TRACE_GROUP_1, [RMC] Serv arfcn[660]: RAC[0], C1[100], C2[156]
32284, 2157865, 10697989, 22:52:34:725 2017/06/08, MOD_RRM_2, , TRACE_GROUP_1, [RMC] Serv arfcn[660]: RAC[0], C1[109], C2[165]
38637, 2159724, 10699684, 22:52:43:185 2017/06/08, MOD_RRM_2, , TRACE_GROUP_1, [RMC] Serv arfcn[660]: RAC[0], C1[99], C2[155]

整個過程當中的服務小區是 頻點660,此小區比周邊的相鄰小區信號質量好 屬因而正常駐留在此
因爲貴司沒有提供完整的開機log 產生這個問題的時候 已是看不到服務小區最開始收系統消息1 2 3 4 的狀況,
當手機支持GPRS ,也就是攜帶SI13 的時候,服務小區只會週期性收SI13 ,來肯定系統消息是否改變

3二、2G小區不知足搜3G

搜完2G找不到合適的小區會全頻掃2G嘗試找2G小區,若是仍是沒有會嘗試去搜3G小區; 該題2G一開始沒有找到就去全頻掃,找到其餘小區可是要不就C1不知足要不basic解不出要不plmn不匹配的小區。 而後找2G,找到10071/29,搜系統消息,可是後面S值不知足就沒有接入。 Type    Index    Time    Local Time    Module    Message    Comment    Time Different OTA (PCORE)    1423422    34733524    14:49:22:913    EMM_NASMSG    [NW->MS] EMM_CS_Service_Notification(paging identity="TMSI_PAGING_TYPE")         OTA (PCORE)    1423612    34733542    14:49:22:913    EMM_NASMSG    [MS->NW] EMM_Extended_Service_Request(service type="MT_CSFB", CSFB response="CSFB_ACCEPTED_BY_UE")         OTA (PCORE)    1423874    34733910    14:49:22:913    ERRC_CONN    [NW->MS] ERRC_RRCConnectionRelease(cause:[ReleaseCause_other], redirectInfo:[1])         PS (PCORE)    1425410    34734595    14:49:23:113    RRM_TDD - MPAL_TDD    MSG_ID_RR_MPAL_SEARCH_RF_REQ         PS (PCORE)    1425436    34743821    14:49:23:703    MPAL_TDD - RRM_TDD    MSG_ID_MPAL_RR_SEARCH_RF_CNF         PS (PCORE)    1425439    34743822    14:49:23:703    RRM_TDD    [RCS] There are [0] ARFCNs to sort or sorted         PS (PCORE)    1425481    34743827    14:49:23:703    RRM_TDD - MPAL_TDD    MSG_ID_RR_MPAL_SEARCH_RF_REQ         PS (PCORE)    1425503    34789759    14:49:26:643    MPAL_TDD - RRM_TDD    MSG_ID_MPAL_RR_SEARCH_RF_CNF         PS (PCORE)    1425658    34789769    14:49:26:643    RRM_TDD    [RCS] There are [100] ARFCNs to try         PS (PCORE)    1425659    34789769    14:49:26:643    RRM_TDD    [RCS] Sorted power scan list: Index:0 ARFCN:4 POWER:-410         PS (PCORE)    1425660    34789769    14:49:26:643    RRM_TDD    [RCS] Sorted power scan list: Index:1 ARFCN:5 POWER:-431         PS (PCORE)    1425661    34789769    14:49:26:643    RRM_TDD    [RCS] Sorted power scan list: Index:2 ARFCN:15 POWER:-431         PS (PCORE)    1425662    34789769    14:49:26:643    RRM_TDD    [RCS] Sorted power scan list: Index:3 ARFCN:109 POWER:-432         PS (PCORE)    1425663    34789769    14:49:26:643    RRM_TDD    [RCS] Sorted power scan list: Index:4 ARFCN:825 POWER:-374         PS (PCORE)    1425664    34789769    14:49:26:643    RRM_TDD    [RCS] Sorted power scan list: Index:5 ARFCN:822 POWER:-375         PS (PCORE)    1425665    34789769    14:49:26:643    RRM_TDD    [RCS] Sorted power scan list: Index:6 ARFCN:820 POWER:-381         PS (PCORE)    1425666    34789769    14:49:26:643    RRM_TDD    [RCS] Sorted power scan list: Index:7 ARFCN:821 POWER:-382         PS (PCORE)    1425667    34789769    14:49:26:643    RRM_TDD    [RCS] Sorted power scan list: Index:8 ARFCN:828 POWER:-382         OTA (PCORE)    1425873    34799995    14:49:27:234    RRM_TDD    [NW->MS] RR__SI_3 (ARFCN[109], TC[6])         /46011 PS (PCORE)    1428863    35027431    14:49:41:804    RSVAU - TL1    MSG_ID_TDD_CPHY_FREQUENCY_SCAN_REQ         PS (PCORE)    1428882    35027446    14:49:41:804    TL1 - RSVAU    MSG_ID_TDD_CPHY_FREQUENCY_SCAN_CNF         PS (PCORE)    1428934    35034777    14:49:42:325    TL1 - MEME_TDD    MSG_ID_TDD_CPHY_MEASUREMENT_CELL_IND         PS (PCORE)    1428937    35034780    14:49:42:325    MEME_TDD - CSE_TDD    MSG_ID_TDD_CSE_MEME_CELL_MEASUREMENT_RESULT_IND    rscp = -435     PS (PCORE)    1428945    35034783    14:49:42:325    CSE_TDD - SIBE_TDD    MSG_ID_TDD_SIBE_SIB_COLLECTION_REQ         OTA (PCORE)    1429025    35036498    14:49:42:325    SIBE_TDD    [NW->MS] TDD_RRC_SI_MIB (TDD_UARFCN:[10071], PSC:[29])         OTA (PCORE)    1429134    35038064    14:49:42:535    SIBE_TDD    [NW->MS] TDD_RRC_SI_SB1 (TDD_UARFCN:[10071], PSC:[29])         PS (PCORE)    1429686    35047127    14:49:42:975    SIBE_TDD - CSE_TDD    MSG_ID_TDD_SIBE_SIB_COLLECTION_CNF    success = KAL_TRUE (enum 1)     PS (PCORE)    1429701    35047136    14:49:42:975    CSE_TDD    TDD_DB_CELL [TDD_UARFCN = 10071, PHYSCELLID = 29, index = 24] does not fulfill Cell Selection criteria even though SIB Collection procedure was successful         //S值不知足就沒有接入 PS (PCORE)    1429703    35047137    14:49:42:975    CSCE_TDD    Designated cell [TDD_UARFCN = 10071, PHYSCELLID = 29] S criteria NOT satisfied [Squal = 1, Srxlev = -39936]

相關文章
相關標籤/搜索