通常分析方法;網絡
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] CCRELEASE
398939, 0, 330662434, 14:47:47:960 2017/01/09, MOD_CC, , TRACE_PEER, [NW->MS] CCRELEASE_COMPLETE
配合機:
374430, 0, 329598595, 14:47:48:782 2017/01/09, MOD_CC, , TRACE_PEER, [NW->MS] CCDISCONNECT
374446, 0, 329598598, 14:47:48:782 2017/01/09, MOD_CC, , TRACE_PEER, [MS->NW] CCRELEASE
374770, 0, 329605952, 14:47:49:386 2017/01/09, MODCC, , 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]