PDU session handling incomplete/disfunctional
Follow up from !3038 (comment 138855)
PDU session release does not work:
177534.940374 [NR_MAC] I (gNB_dlsch_ulsch_schedul:214) Frame.Slot 896.0
UE RNTI ae11 CU-UE-ID 2 in-sync PH 42 dB PCMAX 21 dBm, average RSRP -109 (16 meas)
UE ae11: dlsch_rounds 199/40/3/1, dlsch_errors 1, pucch0_DTX 1, BLER 0.00002 MCS (1) 6
UE ae11: ulsch_rounds 16155/16/0/0, ulsch_errors 0, ulsch_DTX 2, BLER 0.00004 MCS (1) 27 (Qm 8 deltaMCS 0 dB) NPRB 5 SNR 18.5 dB
UE ae11: MAC: TX 30588 RX 2496671 bytes
UE ae11: LCID 1: TX 466 RX 2719 bytes
UE ae11: LCID 2: TX 0 RX 0 bytes
UE ae11: LCID 5: TX 372 RX 372 bytes
UE ae11: LCID 4: TX 3351 RX 6645 bytes
177535.285974 [NGAP] I (ngap_gNB_decode_initiat:81) PDUSESSIONRelease initiating message
177535.285984 [NGAP] D (ngap_gNB_handle_pdusess:1226) [SCTP 48] Received pdu session release command for gNB_UE_NGAP_ID 2 amf_ue_ngap_id 12
177535.285999 [NR_RRC] I (rrc_gNB_process_NGAP_PD:1235) [gNB 0] gNB_ue_ngap_id 2
177535.286008 [NR_RRC] I (rrc_gNB_process_NGAP_PD:1237) PDU Session Release Command: AMF_UE_NGAP_ID 12 rrc_ue_id 2 release_pdusessions 1
177535.286012 [NR_RRC] I (rrc_gNB_process_NGAP_PD:1271) gtp tunnel delete all tunnels for UE ae11
177535.286016 [GTPU] E (newGtpuDeleteTunnels:881) [0] gtpv1uSend failed: while getting ue id 44561 in hashtable ue_mapping
177535.286019 [NR_RRC] I (rrc_gNB_send_NGAP_PDUSE:1212) NGAP PDUSESSION RELEASE RESPONSE: rrc_ue_id 2 release_pdu_sessions 0
177535.286024 [NR_RRC] I (rrc_gNB_process_NGAP_PD:1277) Send PDU Session Release Response
177535.286058 [NGAP] I (ngap_gNB_pdusession_rel:1239) pdusession_release_response sended gNB_UE_NGAP_ID 2 amf_ue_ngap_id 12 nb_of_pdusessions_released 0 nb_of_pdusessions_failed 0
177536.220425 [NR_MAC] I (gNB_dlsch_ulsch_schedul:214) Frame.Slot 0.0
UE RNTI ae11 CU-UE-ID 2 in-sync PH 42 dB PCMAX 21 dBm, average RSRP -109 (16 meas)
UE ae11: dlsch_rounds 202/40/3/1, dlsch_errors 1, pucch0_DTX 1, BLER 0.00001 MCS (1) 6
UE ae11: ulsch_rounds 16540/16/0/0, ulsch_errors 0, ulsch_DTX 2, BLER 0.00001 MCS (1) 27 (Qm 8 deltaMCS 0 dB) NPRB 5 SNR 20.0 dB
UE ae11: MAC: TX 31047 RX 2556109 bytes
UE ae11: LCID 1: TX 469 RX 2741 bytes
UE ae11: LCID 2: TX 3 RX 32 bytes
UE ae11: LCID 5: TX 372 RX 372 bytes
UE ae11: LCID 4: TX 3351 RX 6645 bytesThe gNB receives and claims to process a PDU session release, but does not actually release corresponding DRBs.
Further, upon reception of a PDU session setup, it re-setups PDU sessions that are alreday setup:
177615.287930 [NGAP] D (ngap_gNB_handle_initial:789) AllowedNSSAI.list.count 1
177615.287960 [NR_RRC] I (set_UE_security_algos:618) [UE 2] Selected security algorithms: ciphering 0, integrity 2
177615.287978 [NR_RRC] I (set_UE_security_key:118) [UE ae11] Saved security key 85
177615.287983 [NR_RRC] I (trigger_bearer_setup:325) Adding pdusession 2, total nb of sessions 2
177615.289915 [NR_RRC] I (generateDRB:92) UE 2: configure DRB ID 3 for PDU session ID 2
177615.289926 [RRC] I (get_new_cuup_for_ue:97) UE 2 using CU-UP assoc_id -1
177615.289932 [GTPU] W (newGtpuCreateTunnel:568) [101] Create a config for a already existing GTP tunnel (ue id 2)
177615.289941 [GTPU] I (newGtpuCreateTunnel:617) [101] Created tunnel for UE ID 2, teid for incoming: 38cd57f1, teid for outgoing a to remote IPv4: 172.21.6.201, IPv6 ::
177615.289949 [PDCP] I (add_drb:906) added drb 3 to UE ID 2
177615.289951 [SDAP] E (new_nr_sdap_entity:486) SDAP Entity for UE already exists with RNTI/UE ID: 2 and PDU SESSION ID: 2
177615.290524 [RLC] I (add_drb_am:889) Added drb 3 to UE 44561
177615.290528 [RLC] I (nr_rlc_add_drb:958) Added DRB to UE 44561
177615.290642 [NR_MAC] I (ue_context_modification:568) UE ae11: received capabilities, updating CellGroupConfig
177615.290738 [RRC] I (rrc_gNB_generate_UeCont:2670) UE 2 trigger UE context modification request with 1 DRBs
177615.292387 [E1AP] I (e1_bearer_context_modif:247) UE 2: updating PDU session ID 2 (1 bearers)
177615.292487 [RRC] I (rrc_CU_process_ue_conte:1941) UE ae11 replacing existing CellGroupConfig with new one received from DU
177615.292573 [NR_RRC] I (rrc_gNB_generate_dedica:566) UE 2: Generate RRCReconfiguration (bytes 305, xid 1)
177615.292591 [RRC] I (rrc_gNB_process_e1_bear:2149) UE 2: PDU session ID 2 modified 1 bearers
177615.312460 [NR_RRC] I (handle_rrcReconfigurati:1509) UE 2: Receive RRC Reconfiguration Complete message (xid 1)
177615.312523 [RRC] I (handle_rrcReconfigurati:1545) UE 2: transaction 0 still ongoing for action 8
177615.312537 [NGAP] D (ngap_gNB_initial_ctxt_r:634) initial_ctxt_resp_p: pdusession ID 1, gnb_addr 172.21.19.40, SIZE 4, TEID 2545699439
177615.312549 [NGAP] D (ngap_gNB_initial_ctxt_r:634) initial_ctxt_resp_p: pdusession ID 2, gnb_addr 172.21.19.40, SIZE 4, TEID 952981489
177615.312562 [NR_RRC] I (ngap_gNB_initial_ctxt_r:736) Send message to sctp: NGAP_InitialContextSetupResponse
177615.377454 [NR_RRC] I (process_Event_Based_Mea:1172) HO LOG: Event A2 (Serving becomes worse than threshold)
177615.580685 [NR_MAC] I (gNB_dlsch_ulsch_schedul:214) Frame.Slot 768.0
UE RNTI ae11 CU-UE-ID 2 in-sync PH 42 dB PCMAX 21 dBm, average RSRP -109 (16 meas)
UE ae11: dlsch_rounds 375/40/3/1, dlsch_errors 1, pucch0_DTX 1, BLER 0.00000 MCS (1) 7
UE ae11: ulsch_rounds 40427/16/0/0, ulsch_errors 0, ulsch_DTX 2, BLER 0.00000 MCS (1) 27 (Qm 8 deltaMCS 0 dB) NPRB 5 SNR 21.0 dB
UE ae11: MAC: TX 57633 RX 6241721 bytes
UE ae11: LCID 1: TX 1025 RX 4511 bytes
UE ae11: LCID 2: TX 182 RX 336 bytes
UE ae11: LCID 5: TX 372 RX 372 bytes
UE ae11: LCID 6: TX 0 RX 0 bytes
UE ae11: LCID 4: TX 3351 RX 6645 bytesSee also !2386 (closed) (which is largely not enough)