Trying to connect to commercial RAN, but Initial Context Setup Failure( radionetwork30)

Q/A
#1

We’ve just use free5gc to connect to commercial RAN , Registration procedure seems ok, but in PDU establishment procedure, intail context setup failure :
1、 we check log , this is a “Remove Request Transaction [2]” when Handle PFCP seesion estable , is it a normal procedure?
2、Do we need configure uerouting.yaml when we connect to commercial network or this configuration just for test？
3、Destination IP, Destination Port is null , is there any problem here?
2020-12-21T14:41:07+08:00 [TRAC][SMF][PduSess] DataPath Meta Information
Activated: false
IsDefault Path: true
Has Braching Point: false
Destination IP:
Destination Port:
DataPath Routing Information
1th Node in the Path
Current UPF IP: 127.0.0.8
Previous UPF IP: None
Next UPF IP: None

4、PDU establishment procedure, intail context setup failure, we check encryption and integration configuration is right

Thank you for your reply！

LOG:
2020-12-21T14:41:07+08:00 [TRAC][PCF][SMpolicy] SMPolicy PduSessionId[5] Create
2020-12-21T14:41:07+08:00 [INFO][PCF][GIN] | 201 | 127.0.0.1 | POST | /npcf-smpolicycontrol/v1/sm-policies |
2020-12-21T14:41:07+08:00 [TRAC][SMF][PduSess] In ApplySmPolicyFromDecision
2020-12-21T14:41:07+08:00 [DEBU][SMF][PduSess] Install SessionRule[SessRuleId-5]
2020-12-21T14:41:07+08:00 [TRAC][SMF][PduSess] End of ApplySmPolicyFromDecision
2020-12-21T14:41:07+08:00 [INFO][SMF][PduSess] SUPI[imsi-460089999000010] has no pre-config route
defaultUPPath:%v [{Type:UPF,NodeID:{0 [127 0 0 8]},ANIP:,Dnn:,UPF:&{[16 113 58 224 8 195 65 163 164 218 49 248 32 108 238 9] {0 [127 0 0 8]} {false true 1 false true 0 100.66.253.58 [67 77 78 69 84] 0} 2 {{0 0} {} map[] 0} {{0 0} {} map[] 0} {{0 0} {} map[] 0} 0xc000246750 0xc0002467b0 0xc000246810 0xc0002468d0 0xc000246870 0xc000246930}}]
defaultPath:%v &{false false { } false 0xc000359680}
smContext:%v &{urn:uuid:a9ad0329-5b53-47aa-a623-8a0d52563b6d 1 0 false imsi-460089999000010 imsi-460089999000010 msisdn-0900000000 5 CMNET 0xc000330ac0 0xc000330b40 45148743-5d8e-4c88-9489-5cd5f9e48193 3GPP_ACCESS 0 60.60.0.1 3 {0xc000089e00 0xc000089e30 false 0xc000518e00 0xc000518e40 [] } 0xc00031e9c0 { 0 [] [] [] [] [] [] 0 0 0 map[] false false false []} {d89be425-3672-46b5-bf09-2dcf5c0d3400 PCF REGISTERED 0 0xc0004820c0 [] [] [127.0.0.1] [] [] [] 0 0 0 0xc0001a80a0 map[] false 0xc000482140 false false []} http://127.0.0.1:29518/namf-callback/v1/smContextStatus/46008cafe0000000001/5 ModificationPending 0xc000401590 map[127.0.0.8:0xc0004b5380] 0xc0004a8000 map[] false map[] map[SessRuleId-5:0xc000401410] map[] 1 0xc0003034e0}
2020-12-21T14:41:07+08:00 [TRAC][SMF][PduSess] In ActivateTunnelAndPDR
2020-12-21T14:41:07+08:00 [TRAC][SMF][PduSess] DataPath Meta Information
Activated: false
IsDefault Path: true
Has Braching Point: false
Destination IP:
Destination Port:
DataPath Routing Information
1th Node in the Path
Current UPF IP: 127.0.0.8
Previous UPF IP: None
Next UPF IP: None
2020-12-21T14:41:07+08:00 [TRAC][SMF][PduSess] Current DP Node IP: 127.0.0.8
2020-12-21T14:41:07+08:00 [TRAC][SMF][Context] In ActivateUpLinkTunnel
2020-12-21T14:41:07+08:00 [TRAC][SMF][Context] Calculate 127.0.0.8:8805
2020-12-21T14:41:07+08:00 [TRAC][SMF][PduSess] Current DP Node IP: 127.0.0.8
2020-12-21T14:41:07+08:00 [TRAC][SMF][PduSess] Before DLPDR OuterHeaderCreation
2020-12-21T14:41:07+08:00 [INFO][NRF][Discovery] Handle NFDiscoveryRequest
2020-12-21T14:41:07+08:00 [TRAC][NRF][Discovery] Query filter: map[$and:[map[nfType:AMF] map[$or:[map[allowedNfTypes:SMF] map[allowedNfTypes:map[$exists:false]]]] map[nfInstanceId:45148743-5d8e-4c88-9489-5cd5f9e48193]]]
2020-12-21T14:41:07+08:00 [INFO][NRF][GIN] | 200 | 127.0.0.1 | GET | /nnrf-disc/v1/nf-instances?requester-nf-type=SMF&target-nf-instance-id=45148743-5d8e-4c88-9489-5cd5f9e48193&target-nf-type=AMF |
2020-12-21T14:41:07+08:00 [INFO][SMF][App] SendNFDiscoveryServingAMF ok
2020-12-21T14:41:07+08:00 [TRAC][SMF][PduSess] Send NF Discovery Serving AMF successfully
2020-12-21T14:41:07+08:00 [INFO][SMF][PduSess] Send PFCP Rule
2020-12-21T14:41:07+08:00 [INFO][SMF][PduSess] DataPath: &{true true { } false 0xc000359680}
2020-12-21T14:41:07+08:00 [TRAC][SMF][PduSess] [SMF] Send SendPfcpSessionEstablishmentRequest
2020-12-21T14:41:07+08:00 [TRAC][SMF][PduSess] Send to addr 127.0.0.8:8805
2020-12-21T14:41:07+08:00 [INFO][SMF][GIN] | 201 | 127.0.0.1 | POST | /nsmf-pdusession/v1/sm-contexts |
2020-12-21T14:41:07+08:00 [INFO][UPF][Util] [PFCP] Handle PFCP session establishment request
2020-12-21T14:41:07+08:00 [INFO][UPF][Util] [PFCP] Session Establishment Response
2020-12-21T14:41:07+08:00 [INFO][LIB][PFCP] Remove Request Transaction [2]
2020-12-21T14:41:07+08:00 [INFO][SMF][Pfcp] In HandlePfcpSessionEstablishmentResponse
&{3000 Kbps 1000 Kbps}
2020-12-21T14:41:07+08:00 [TRAC][NAS][Convert] In AddDNSServerIPv4Address
2020-12-21T14:41:07+08:00 [TRAC][NAS][Convert] LengthOfContents: 4
2020-12-21T14:41:07+08:00 [TRAC][NAS][Convert] Contents: [8 8 8 8]
2020-12-21T14:41:07+08:00 [INFO][AMF][Gmm] smconetxt ef : urn:uuid:a9ad0329-5b53-47aa-a623-8a0d52563b6d
2020-12-21T14:41:07+08:00 [INFO][AMF][Gmm] Http create smContext[pduSessionID: 5] Success
2020-12-21T14:41:07+08:00 [INFO][AMF][Producer] Handle N1N2 Message Transfer Request
2020-12-21T14:41:07+08:00 [DEBU][AMF][Producer] AMF Transfer NGAP PDU Resource Setup Req from SMF
2020-12-21T14:41:07+08:00 [DEBU][AMF][NAS] Security header type: Integrity Protected And Ciphered
2020-12-21T14:41:07+08:00 [TRAC][AMF][NAS] ue.CipheringAlg 0
2020-12-21T14:41:07+08:00 [TRAC][AMF][NAS] ue.DLCount() 2
2020-12-21T14:41:07+08:00 [TRAC][AMF][NAS] payload:
00000000 7e 00 68 01 00 55 2e 05 01 c2 11 00 09 01 00 06 |~.h…U…|
00000010 31 31 01 01 ff 09 06 01 03 e8 01 0b b8 59 32 29 |11…Y2)|
00000020 05 01 3c 3c 00 01 22 04 01 11 22 33 79 00 06 09 |…<<…"…"3y…|
00000030 20 41 01 01 09 7b 00 1b 80 00 0d 04 08 08 08 08 | A…{…|
00000040 00 03 10 20 01 48 60 48 60 00 00 00 00 00 00 00 |… .HH…|
00000050 00 88 88 25 06 05 43 4d 4e 45 54 12 05 |…%…CMNET…|
2020-12-21T14:41:07+08:00 [DEBU][AMF][NAS] Perform NAS encryption
2020-12-21T14:41:07+08:00 [DEBU][NAS][Security] Use NEA0
2020-12-21T14:41:07+08:00 [DEBU][NAS][Security] Use NIA2
2020-12-21T14:41:07+08:00 [TRAC][AMF][NAS] mac32 [76 155 179 168]
2020-12-21T14:41:07+08:00 [TRAC][AMF][NAS] Encode payload [126 2 76 155 179 168 2 126 0 104 1 0 85 46 5 1 194 17 0 9 1 0 6 49 49 1 1 255 9 6 1 3 232 1 11 184 89 50 41 5 1 60 60 0 1 34 4 1 17 34 51 121 0 6 9 32 65 1 1 9 123 0 27 128 0 13 4 8 8 8 8 0 3 16 32 1 72 96 72 96 0 0 0 0 0 0 0 0 136 136 37 6 5 67 77 78 69 84 18 5]
2020-12-21T14:41:07+08:00 [INFO][AMF][NGAP] [AMF] Send Initial Context Setup Request
2020-12-21T14:41:07+08:00 [DEBU][AMF][NGAP] [NGAP] Send To Ran [IP: 10.170.138.81:38412]
2020-12-21T14:41:07+08:00 [DEBU][AMF][NGAP] Write 271 bytes
2020-12-21T14:41:07+08:00 [INFO][AMF][GIN] | 200 | 127.0.0.1 | POST | /namf-comm/v1/ue-contexts/imsi-460089999000010/n1-n2-messages |
2020-12-21T14:41:07+08:00 [TRAC][SMF][Context] SMContextState Change State: Active
2020-12-21T14:41:07+08:00 [TRAC][AMF][NGAP] Read 37 bytes
2020-12-21T14:41:07+08:00 [TRAC][AMF][NGAP] Packet content:
00000000 40 0e 00 21 00 00 04 00 0a 40 02 00 01 00 55 40 |@…!..@…U@|
00000010 04 80 30 07 81 00 84 40 06 00 00 05 02 00 f0 00 |…0…@…|
00000020 0f 40 02 07 80 |.@…|
2020-12-21T14:41:07+08:00 [INFO][AMF][NGAP] [AMF] Initial Context Setup Failure
2020-12-21T14:41:07+08:00 [TRAC][AMF][NGAP] [NGAP] Decode IE AmfUeNgapID
2020-12-21T14:41:07+08:00 [TRAC][AMF][NGAP] [NGAP] Decode IE RanUeNgapID
2020-12-21T14:41:07+08:00 [TRAC][AMF][NGAP] [NGAP] Decode IE PDUSessionResourceFailedToSetupList
2020-12-21T14:41:07+08:00 [TRAC][AMF][NGAP] [NGAP] Decode IE Cause
2020-12-21T14:41:07+08:00 [TRAC][AMF][NGAP] IP[10.170.138.81:38412] GNbId[b0160d]
2020-12-21T14:41:07+08:00 [WARN][AMF][NGAP] Cause RadioNetwork[30]
2020-12-21T14:41:07+08:00 [TRAC][AMF][NGAP] [NGAP] Send PDUSessionResourceSetupUnsuccessfulTransfer to SMF

#10

which commercial RAN are you using ? please share model no.

#2

Hi,

For 1, seems right.
For 2, you don’t need to configure uerouting if you do not enable ulcl feature (ulcl: true in smfcfg).
For 3, if you do not config ulcl feature, it’s normal.
For 4, Can you provide the log in files and the pcap file on your procedure.

BTW, what’s the RAN and UE solution do you used?

#4

1221log.docx (35.4 KB) ens192cap.zip (3.9 KB)

This is my log and pcap,thank you for your reply

#5

I think this problem is caused by this issue: https://github.com/free5gc/free5gc/issues/132
And the bug has been fixed now.
Please pull the latest version of amf then test again.

By the way, you can modify amf config so that AMF will use NEA0 (null ciphering algorithm) to encrypt the NAS message which will make debugging more easier

  security:
    integrityOrder:
      - NIA2
      # - NIA0
    cipheringOrder:
      - NEA0  # put NEA0 first
      # - NEA2
#6

And Initial context setup failure is sent by RAN, so if there is still any problem after using the latest version of AMF, you should check the log file on your RAN and tell us what reason that your RAN reject the initial context setup request from AMF

#7

Thank you for your help, we modified the source code. Now we met a failure “Cause RadioNetwork[20]” , can you give some advice to fix it ,thank you

1225 error log.docx (33.9 KB)

2020-12-25T11:06:49+08:00 [INFO][SMF][PduSess] In HandlePDUSessionSMContextUpdate
2020-12-25T11:06:49+08:00 [TRAC][SMF][PduSess] [SMF] Binary Data N1 SmMessage is nil!
2020-12-25T11:06:49+08:00 [WARN][SMF][PduSess] SM Context State [Active] shouldn’t be here
2020-12-25T11:06:49+08:00 [INFO][SMF][GIN] | 200 | 127.0.0.1 | POST | /nsmf-pdusession/v1/sm-contexts/urn:uuid:063a6682-62e3-4b4d-872c-360efdcc0ba0/modify |
2020-12-25T11:07:46+08:00 [TRAC][AMF][NGAP] Read 27 bytes
2020-12-25T11:07:46+08:00 [TRAC][AMF][NGAP] Packet content:
00000000 00 2a 40 17 00 00 03 00 0a 00 02 00 01 00 55 00 |.*@…U.|
00000010 04 80 20 07 ae 00 0f 40 02 05 00 |… …@…|
2020-12-25T11:07:46+08:00 [INFO][AMF][NGAP] [AMF] UE Context Release Request
2020-12-25T11:07:46+08:00 [TRAC][AMF][NGAP] [NGAP] Decode IE AmfUeNgapID
2020-12-25T11:07:46+08:00 [TRAC][AMF][NGAP] [NGAP] Decode IE RanUeNgapID
2020-12-25T11:07:46+08:00 [TRAC][AMF][NGAP] [NGAP] Decode IE Cause
2020-12-25T11:07:46+08:00 [TRAC][AMF][NGAP] IP[10.170.138.81:38412] GNbId[b0160d]
2020-12-25T11:07:46+08:00 [TRAC][AMF][NGAP] RanUeNgapID[2099118] AmfUeNgapID[1]
2020-12-25T11:07:46+08:00 [WARN][AMF][NGAP] Cause RadioNetwork[20]

#8

ens192 1228.zip (4.6 KB)

#9

we compared two log, when we use simulation UE and gNB, after “AMF Transfer NGAP PDU Resource Setup Req from SMF” , AMF send “Send PDU Session Resource Setup Request” ,but when we use commercial UE and gNB，it sends “”Send Initial Context Setup Request“”

#11

Warning “Cause RadioNetwork[20]” is fine because it just print out the cause that why RAN send UE Context Release Request, and AMF just use warning log to remind the user. according to your pcap file, I think you has already successfully connected to your RAN and UE.

For your second problem, why AMF have different behavior after “AMF Transfer NGAP PDU Resource Setup Req from SMF”, you can reference [Bugs] AMF does not send "Pdu Session Resource Setup Request" · Issue #142 · free5gc/free5gc · GitHub

1 Like