LTE 信令流程Log 之 OAI eNB

最近在研究SDR LTE系统之间的互联互通，成功调通了Amari MME + OAI eNB + srsUE。不知道这些SDR LTE平台的可以参见我的博客http://blog.csdn.net/jxwxg/article/details/53026659。

调通之后，抓取了MME，eNB和UE侧的信令流程log，流程包括了eNB与MME的连接，UE随机接入，UE鉴权等过程。因为Log信息内容较多，本博客只显示OAI eNB侧的Log信息。Amari MME 的Log信息请查阅 http://blog.csdn.net/jxwxg/article/details/53999138  srsUE的Log信息请查看 http://blog.csdn.net/jxwxg/article/details/53999163 。

eNB

[MAC][I][l2_init] [MAIN] MAC_INIT_GLOBAL_PARAM IN...
[MAC][I][mac_init_global_param] [MAIN] CALLING RLC_MODULE_INIT...
[MAC][I][mac_init_global_param] [MAIN] RLC_MODULE_INIT OK, malloc16 for mac_rlc_xface...
[MAC][I][mac_init_global_param] [MAIN] malloc16 OK, mac_rlc_xface @ 0x16f11280
[MAC][I][mac_init_global_param] [MAIN] RLC interface setup and init
[PDCP][I]PDCP layer has been initialized
[MAC][I][mac_init_global_param] [MAIN] Init Global Param Done
[MAC][I][l2_init] [MAIN] init eNB MAC functions  
[MAC][I][l2_init] [MAIN] init UE MAC functions 
[MAC][I][l2_init] [MAIN] PHY Frame configuration 
[MAC][I][mac_top_init] [MAIN] Init function start:Nb_UE_INST=0
[MAC][I][mac_top_init] [MAIN] Init function start:Nb_eNB_INST=1
[MAC][I][mac_top_init] [MAIN] calling RRC
[RRC][I][eNB] handover active state is 0 
[MAC][I][mac_top_init] [MAIN][INIT] Init function finished
[SCTP][I][sctp_eNB_task] Starting SCTP layer
[S1AP][I][s1ap_eNB_task] Starting S1AP layer
[UDP][I]Initializing UDP task interface
[UDP][I]Initializing UDP task interface: DONE
[GTPV1U][I]Initializing GTPU stack 0xdfe460
ITTI tasks created
[MAC][I][mrbch_phy_sync_failure] [eNB 0] Frame 0: PHY Sync failure 
setup_eNB_buffers: frame_parms = 0x7ff83248c8e0
rxdata[0] @ 0x16f14b00 (0x16f14b00) (N_TA_OFFSET 0)
txdata[0] @ 0x16f5fb60
Setting eNB buffer to all-RX
[UDP][I]Initializing UDP for local address 127.0.0.1 with port 2152
[UDP][I]Inserting new descriptor for task 11, sd 45
[UDP][I]Initializing UDP for local address 127.0.0.1 with port 2152: DONE
Wait for the ITTI initialize message
[RRC][I][eNB 0] Received RRC_CONFIGURATION_REQ
[S1AP][I][s1ap_eNB_handle_register_eNB] Registered new eNB[0] and macro eNB id 3584
[SCTP][I][sctp_handle_new_association_req] sctp_bindx SCTP_BINDX_ADD_ADDR socket bound to : 127.0.0.1
[SCTP][I][sctp_handle_new_association_req] Converted ipv4 address 127.0.1.100 to network type
[SCTP][I][sctp_handle_new_association_req] connectx assoc_id  5 in progress..., used 1 addresses
[SCTP][I][sctp_handle_new_association_req] Inserted new descriptor for sd 46 in list, nb elements 1, assoc_id 5
[SCTP][I][sctp_eNB_flush_sockets] Found data for descriptor 46
[SCTP][I][sctp_eNB_read_from_socket] Received notification for sd 46, type 32769
[SCTP][I][sctp_eNB_read_from_socket] Client association changed: 0
[SCTP][I][sctp_get_peeraddresses] ----------------------
[SCTP][I][sctp_get_peeraddresses] Peer addresses:
[SCTP][I][sctp_get_peeraddresses]     - [127.0.1.100]
[SCTP][I][sctp_get_peeraddresses] ----------------------
[SCTP][I][sctp_get_sockinfo] ----------------------
[SCTP][I][sctp_get_sockinfo] SCTP Status:
[SCTP][I][sctp_get_sockinfo] assoc id .....: 5
[SCTP][I][sctp_get_sockinfo] state ........: 4
[SCTP][I][sctp_get_sockinfo] instrms ......: 2
[SCTP][I][sctp_get_sockinfo] outstrms .....: 2
[SCTP][I][sctp_get_sockinfo] fragmentation : 65487
[SCTP][I][sctp_get_sockinfo] pending data .: 0
[SCTP][I][sctp_get_sockinfo] unack data ...: 0
[SCTP][I][sctp_get_sockinfo] rwnd .........: 106496
[SCTP][I][sctp_get_sockinfo] peer info     :
[SCTP][I][sctp_get_sockinfo]     state ....: 2
[SCTP][I][sctp_get_sockinfo]     cwnd .....: 131070
[SCTP][I][sctp_get_sockinfo]     srtt .....: 0
[SCTP][I][sctp_get_sockinfo]     rto ......: 3000
[SCTP][I][sctp_get_sockinfo]     mtu ......: 65535
[SCTP][I][sctp_get_sockinfo] ----------------------
[SCTP][I][sctp_eNB_read_from_socket] Comm up notified for sd 46, assigned assoc_id 5
[S1AP][I][s1ap_eNB_generate_s1_setup_request] 3584 -> 00e000
[RRC][I][FRAME 00000][eNB][MOD 00][RNTI 0] Init...
[RRC][I][FRAME 00000][eNB][MOD 00][RNTI 0] Checking release 
[RRC][I][FRAME 00000][eNB][MOD 00][RNTI 0] Rel8 RRC
[SCTP][I][sctp_send_data] Successfully sent 59 bytes on stream 0 for assoc_id 5
[SCTP][I][sctp_eNB_flush_sockets] Found data for descriptor 46
[RRC][I][eNB 0] Configuration SIB2/3
[SCTP][I][sctp_eNB_read_from_socket] Received notification for sd 46, type 32777
[MAC][I][rrc_mac_config_req] [CONFIG][eNB 0/0] Configuring MAC/PHY
[MAC][I][rrc_mac_config_req] [CONFIG]SIB2/3 Contents (partial)
[MAC][I][rrc_mac_config_req] [CONFIG]pusch_config_common.n_SB = 1
[MAC][I][rrc_mac_config_req] [CONFIG]pusch_config_common.hoppingMode = 0
[MAC][I][rrc_mac_config_req] [CONFIG]pusch_config_common.pusch_HoppingOffset = 0
[MAC][I][rrc_mac_config_req] [CONFIG]pusch_config_common.enable64QAM = 0
[MAC][I][rrc_mac_config_req] [CONFIG]pusch_config_common.groupHoppingEnabled = 1
[MAC][I][rrc_mac_config_req] [CONFIG]pusch_config_common.groupAssignmentPUSCH = 0
[MAC][I][rrc_mac_config_req] [CONFIG]pusch_config_common.sequenceHoppingEnabled = 0
[MAC][I][rrc_mac_config_req] [CONFIG]pusch_config_common.cyclicShift  = 1
[RRC][I][FRAME 00000][eNB][MOD 00][RNTI 0] OPENAIR RRC IN....
[SCTP][I][sctp_eNB_flush_sockets] Found data for descriptor 46
[SCTP][I][sctp_eNB_read_from_socket] [5][46] Msg of length 27 received from port 36412, on stream 0, PPID 18
[S1AP][I][s1ap_decode_s1ap_s1setupresponseies] Decoding message S1ap_S1SetupResponseIEs (/home/wspn/oai/oma/openairinterface5g/cmake_targets/lte_build_oai/build/CMakeFiles/R10.5/s1ap_decoder.c:3544)
[S1AP][I][s1ap_eNB_handle_s1_setup_response] servedGUMMEIs.list.count 1
[S1AP][I][s1ap_eNB_handle_s1_setup_response] servedPLMNs.list.count 1
[ENB_APP][I][eNB_app_task] [eNB 0] Received S1AP_REGISTER_ENB_CNF: associated MME 1
Scope thread has priority 2
Scope thread created, ret=0
Setting eNB_thread FIFO scheduling policy with priority 99 
Setting OS scheduler to SCHED_FIFO for eNB [cc0][thread0] 
[HW][I][SCHED][eNB] TX thread 0 started on CPU 3 TID 2351
[HW][I][SCHED][eNB] RX thread 0 started on CPU 0 TID 2352
Setting OS scheduler to SCHED_FIFO for eNB [cc0][thread1] 
[HW][I][SCHED][eNB] TX thread 1 started on CPU 3 TID 2353
[HW][I][SCHED][eNB] RX thread 1 started on CPU 2 TID 2354
Setting OS scheduler to SCHED_FIFO for eNB [cc0][thread2] 
[HW][I][SCHED][eNB] TX thread 2 started on CPU 2 TID 2355
[HW][I][SCHED][eNB] RX thread 2 started on CPU 1 TID 2356
Setting OS scheduler to SCHED_FIFO for eNB [cc0][thread3] 
[HW][I][SCHED][eNB] TX thread 3 started on CPU 2 TID 2357
[HW][I][SCHED][eNB] RX thread 3 started on CPU 2 TID 2358
Setting OS scheduler to SCHED_FIFO for eNB [cc0][thread4] 
[HW][I][SCHED][eNB] TX thread 4 started on CPU 3 TID 2359
[HW][I][SCHED][eNB] RX thread 4 started on CPU 3 TID 2360
Setting OS scheduler to SCHED_FIFO for eNB [cc0][thread5] 
[HW][I][SCHED][eNB] TX thread 5 started on CPU 2 TID 2361
[HW][I][SCHED][eNB] RX thread 5 started on CPU 2 TID 2362
Setting OS scheduler to SCHED_FIFO for eNB [cc0][thread6] 
[HW][I][SCHED][eNB] TX thread 6 started on CPU 3 TID 2363
[HW][I][SCHED]