[ERRO][SMF][PduSess] Handle PDUSessionResourceSetupResponseTransfer failed: Get bits overflow #61
Comments
|
Hi @minziran Can you please share a pcap trace on N2, N3 and N4? It can help understand the root cause. Cheers, |
Hi @abousselmi, Thank you for your quick reply. I have attached the trace log of AMF, SMF and UPF. Best regards, |
Sign up for free
to join this conversation on GitHub.
Already have an account?
Sign in to comment
Hi @abousselmi and @free5gc-org ,
I hope you are doing well. We are trying to connect the UE+ configured sim card to the Free5GC core. The UE is able to attach the NR5G, however, the amf and smf show some errors. I would appreciate any comments and help.
AMF log
root@free5gc5gtestbed-SIMATIC-IPC427E:/home/free5gc5gtestbed/free5gc-compose-amarisoft/config# sudo docker logs amf
2022-09-14T15:04:49Z [INFO][AMF][CFG] config version [1.0.3]
2022-09-14T15:04:49Z [INFO][AMF][Init] AMF Log level is set to [info] level
2022-09-14T15:04:49Z [INFO][LIB][NAS] set log level : info
2022-09-14T15:04:49Z [INFO][LIB][NAS] set report call : false
2022-09-14T15:04:49Z [INFO][LIB][NGAP] set log level : trace
2022-09-14T15:04:49Z [INFO][LIB][NGAP] set report call : false
2022-09-14T15:04:49Z [INFO][LIB][FSM] set log level : info
2022-09-14T15:04:49Z [INFO][LIB][FSM] set report call : false
2022-09-14T15:04:49Z [INFO][LIB][Aper] set log level : info
2022-09-14T15:04:49Z [INFO][LIB][Aper] set report call : false
2022-09-14T15:04:49Z [INFO][AMF][App] amf
2022-09-14T15:04:49Z [INFO][AMF][App] AMF version:
free5GC version: v3.1.1
build time: 2022-05-25T14:32:37Z
commit hash: 03f9848e
commit time: 2022-04-07T14:37:30Z
go version: go1.14.4 linux/amd64
2022-09-14T15:04:49Z [INFO][AMF][Init] Server started
2022-09-14T15:04:49Z [INFO][AMF][Util] amfconfig Info: Version[1.0.3] Description[AMF initial local configuration]
2022-09-14T15:04:49Z [INFO][AMF][NGAP] Listen on 10.100.200.13:38412
2022-09-14T15:04:53Z [INFO][AMF][NGAP] [AMF] SCTP Accept from: 192.168.137.234:54321
2022-09-14T15:04:53Z [INFO][AMF][NGAP] Create a new NG connection for: 192.168.137.234:54321
2022-09-14T15:04:53Z [INFO][AMF][NGAP][192.168.137.234:54321] Handle NG Setup request
2022-09-14T15:04:53Z [INFO][AMF][NGAP][192.168.137.234:54321] Send NG-Setup response
2022-09-14T15:06:22Z [INFO][AMF][NGAP][192.168.137.234:54321] Handle Initial UE Message
2022-09-14T15:06:22Z [INFO][LIB][FSM] Handle event[Gmm Message], transition from [Deregistered] to [Deregistered]
2022-09-14T15:06:22Z [INFO][AMF][GMM][AMF_UE_NGAP_ID:1] Handle Registration Request
2022-09-14T15:06:22Z [INFO][LIB][FSM] Handle event[Start Authentication], transition from [Deregistered] to [Authentication]
2022-09-14T15:06:22Z [INFO][AMF][GMM][AMF_UE_NGAP_ID:1] Authentication procedure
2022-09-14T15:06:22Z [INFO][AMF][GMM][AMF_UE_NGAP_ID:1] Send Authentication Request
2022-09-14T15:06:22Z [INFO][AMF][NGAP][192.168.137.234:54321][AMF_UE_NGAP_ID:1] Send Downlink Nas Transport
2022-09-14T15:06:22Z [INFO][AMF][NGAP][192.168.137.234:54321][AMF_UE_NGAP_ID:1] Uplink NAS Transport (RAN UE NGAP ID: 91)
2022-09-14T15:06:22Z [INFO][LIB][FSM] Handle event[Gmm Message], transition from [Authentication] to [Authentication]
2022-09-14T15:06:22Z [INFO][AMF][GMM][AMF_UE_NGAP_ID:1] Handle Authentication Response
2022-09-14T15:06:22Z [INFO][LIB][FSM] Handle event[Authentication Success], transition from [Authentication] to [SecurityMode]
2022-09-14T15:06:22Z [INFO][AMF][GMM][AMF_UE_NGAP_ID:1][SUPI:imsi-001010000000012] Send Security Mode Command
2022-09-14T15:06:22Z [INFO][AMF][NGAP][192.168.137.234:54321][AMF_UE_NGAP_ID:1] Send Downlink Nas Transport
2022-09-14T15:06:22Z [INFO][AMF][NGAP][192.168.137.234:54321][AMF_UE_NGAP_ID:1] Uplink NAS Transport (RAN UE NGAP ID: 91)
2022-09-14T15:06:22Z [INFO][LIB][FSM] Handle event[Gmm Message], transition from [SecurityMode] to [SecurityMode]
2022-09-14T15:06:22Z [INFO][AMF][GMM][AMF_UE_NGAP_ID:1][SUPI:imsi-001010000000012] Handle Security Mode Complete
2022-09-14T15:06:22Z [INFO][LIB][FSM] Handle event[SecurityMode Success], transition from [SecurityMode] to [ContextSetup]
2022-09-14T15:06:22Z [INFO][AMF][GMM][AMF_UE_NGAP_ID:1][SUPI:imsi-001010000000012] Handle InitialRegistration
2022-09-14T15:06:22Z [INFO][AMF][GMM][AMF_UE_NGAP_ID:1][SUPI:imsi-001010000000012] RequestedNssai - ServingSnssai: &{Sst:1 Sd:010203}, HomeSnssai:
2022-09-14T15:06:22Z [INFO][AMF][GMM][AMF_UE_NGAP_ID:1][SUPI:imsi-001010000000012] RequestedNssai - ServingSnssai: &{Sst:1 Sd:112233}, HomeSnssai:
2022-09-14T15:06:22Z [INFO][AMF][Comm] Handle AMF Status Change Subscribe Request
2022-09-14T15:06:22Z [INFO][AMF][Comm] new AMF Status Subscription[1]
2022-09-14T15:06:22Z [INFO][AMF][GIN] | 201 | 10.100.200.9 | POST | /namf-comm/v1/subscriptions |
2022-09-14T15:06:22Z [INFO][AMF][GMM][AMF_UE_NGAP_ID:1][SUPI:imsi-001010000000012] Send Registration Accept
2022-09-14T15:06:22Z [INFO][AMF][NGAP][192.168.137.234:54321][AMF_UE_NGAP_ID:1] Send Initial Context Setup Request
2022-09-14T15:06:22Z [WARN][AMF][NGAP][192.168.137.234:54321] Cause RadioNetwork[39]
2022-09-14T15:06:22Z [INFO][AMF][NGAP][192.168.137.234:54321][AMF_UE_NGAP_ID:1] Handle Initial Context Setup Failure
2022-09-14T15:06:28Z [WARN][AMF][GMM][AMF_UE_NGAP_ID:1][SUPI:imsi-001010000000012] T3550 expires, retransmit Registration Accept (retry: 1)
2022-09-14T15:06:28Z [INFO][AMF][NGAP][192.168.137.234:54321][AMF_UE_NGAP_ID:1] Send Downlink Nas Transport
2022-09-14T15:06:28Z [INFO][AMF][NGAP][192.168.137.234:54321][AMF_UE_NGAP_ID:1] Uplink NAS Transport (RAN UE NGAP ID: 91)
SMF log
root@free5gc5gtestbed-SIMATIC-IPC427E:/home/free5gc5gtestbed/free5gc-compose-amarisoft/config# sudo docker logs smf
2022-09-14T15:04:48Z [INFO][SMF][CFG] SMF config version [1.0.2]
2022-09-14T15:04:48Z [INFO][SMF][CFG] UE-Routing config version [1.0.1]
2022-09-14T15:04:48Z [INFO][SMF][Init] SMF Log level is set to [info] level
2022-09-14T15:04:48Z [INFO][LIB][NAS] set log level : info
2022-09-14T15:04:48Z [INFO][LIB][NAS] set report call : false
2022-09-14T15:04:48Z [INFO][LIB][NGAP] set log level : info
2022-09-14T15:04:48Z [INFO][LIB][NGAP] set report call : false
2022-09-14T15:04:48Z [INFO][LIB][Aper] set log level : info
2022-09-14T15:04:48Z [INFO][LIB][Aper] set report call : false
2022-09-14T15:04:48Z [INFO][LIB][PFCP] set log level : info
2022-09-14T15:04:48Z [INFO][LIB][PFCP] set report call : false
2022-09-14T15:04:48Z [INFO][SMF][App] smf
2022-09-14T15:04:48Z [INFO][SMF][App] SMF version:
free5GC version: v3.1.1
build time: 2022-05-25T14:33:39Z
commit hash: 84c979a3
commit time: 2022-04-09T08:38:26Z
go version: go1.14.4 linux/amd64
2022-09-14T15:04:48Z [INFO][SMF][CTX] smfconfig Info: Version[1.0.2] Description[SMF initial local configuration]
2022-09-14T15:04:48Z [INFO][SMF][CTX] Endpoints: [upf.free5gc.org]
2022-09-14T15:04:48Z [INFO][SMF][Init] Server started
2022-09-14T15:04:48Z [INFO][SMF][Init] SMF Registration to NRF {a4f46490-3caf-490a-b5d1-3e2ef8ad24a0 SMF REGISTERED 0 0xc0002403a0 0xc0002403e0 [] [] [smf.free5gc.org] [] [] [] 0 0 0 area1 0xc000276b80 map[] false 0xc000240160 false false []}
2022-09-14T15:04:48Z [INFO][SMF][PFCP] Listen on 10.100.200.8:8805
2022-09-14T15:04:48Z [INFO][SMF][App] Send PFCP Association Request to UPFupf.free5gc.org
2022-09-14T15:04:48Z [INFO][LIB][PFCP] Remove Request Transaction [1]
2022-09-14T15:04:48Z [INFO][SMF][PFCP] In HandlePfcpAssociationSetupResponse
2022-09-14T15:04:48Z [INFO][SMF][PFCP] Handle PFCP Association Setup Response with NodeID[10.100.200.2]
2022-09-14T15:04:48Z [INFO][SMF][PFCP] UPF(10.100.200.2)[{internet}] setup association
2022-09-14T15:06:28Z [INFO][SMF][PduSess] Receive Create SM Context Request
2022-09-14T15:06:28Z [INFO][SMF][PduSess] In HandlePDUSessionSMContextCreate
2022-09-14T15:06:28Z [INFO][SMF][PduSess] Send NF Discovery Serving UDM Successfully
2022-09-14T15:06:28Z [INFO][SMF][CTX] Allocated UE IP address: 10.60.0.1
2022-09-14T15:06:28Z [INFO][SMF][CTX] Selected UPF: UPF
2022-09-14T15:06:28Z [INFO][SMF][PduSess] UE[imsi-001010000000012] PDUSessionID[1] IP[10.60.0.1]
2022-09-14T15:06:28Z [INFO][SMF][GSM] In HandlePDUSessionEstablishmentRequest
2022-09-14T15:06:28Z [INFO][NAS][Convert] ProtocolOrContainerList: [0xc00046e980 0xc00046e9e0 0xc00046ea20 0xc00046ea80 0xc00046eac0 0xc00046eb00 0xc00046eb40 0xc00046eb80]
2022-09-14T15:06:28Z [INFO][SMF][GSM] Protocol Configuration Options
2022-09-14T15:06:28Z [INFO][SMF][GSM] &{[0xc00046e980 0xc00046e9e0 0xc00046ea20 0xc00046ea80 0xc00046eac0 0xc00046eb00 0xc00046eb40 0xc00046eb80]}
2022-09-14T15:06:28Z [INFO][SMF][GSM] Didn't Implement container type InternetProtocolControlProtocolUL
2022-09-14T15:06:28Z [INFO][SMF][GSM] Didn't Implement container type IPAddressAllocationViaNASSignallingUL
2022-09-14T15:06:28Z [INFO][SMF][GSM] Didn't Implement container type MSSupportOfNetworkRequestedBearerControlIndicatorUL
2022-09-14T15:06:28Z [INFO][SMF][GSM] Didn't Implement container type MSSupportOfLocalAddressInTFTIndicatorUL
2022-09-14T15:06:28Z [INFO][SMF][GSM] Didn't Implement container type QoSRulesWithTheLengthOfTwoOctetsSupportIndicatorUL
2022-09-14T15:06:28Z [INFO][SMF][GSM] Didn't Implement container type QoSFlowDescriptionsWithTheLengthOfTwoOctetsSupportIndicatorUL
2022-09-14T15:06:28Z [INFO][SMF][PduSess] PCF Selection for SMContext SUPI[imsi-001010000000012] PDUSessionID[1]
2022-09-14T15:06:28Z [INFO][SMF][PduSess] SUPI[imsi-001010000000012] has no pre-config route
2022-09-14T15:06:28Z [INFO][SMF][Consumer] SendNFDiscoveryServingAMF ok
2022-09-14T15:06:28Z [INFO][SMF][GIN] | 201 | 10.100.200.13 | POST | /nsmf-pdusession/v1/sm-contexts |
2022-09-14T15:06:28Z [INFO][SMF][PFCP] In HandlePfcpSessionEstablishmentResponse
2022-09-14T15:06:28Z [INFO][LIB][PFCP] Remove Request Transaction [2]
2022-09-14T15:06:38Z [INFO][SMF][PduSess] Receive Update SM Context Request
2022-09-14T15:06:38Z [INFO][SMF][PduSess] In HandlePDUSessionSMContextUpdate
2022-09-14T15:06:38Z [INFO][SMF][PFCP] In HandlePfcpSessionModificationResponse
2022-09-14T15:06:38Z [INFO][SMF][PduSess] [SMF] PFCP Modification Resonse Accept
2022-09-14T15:06:38Z [INFO][LIB][PFCP] Remove Request Transaction [3]
2022-09-14T15:06:38Z [INFO][SMF][PFCP] PFCP Session Modification Success[1]
2022-09-14T15:06:38Z [INFO][SMF][GIN] | 200 | 10.100.200.13 | POST | /nsmf-pdusession/v1/sm-contexts/urn:uuid:2c7adeaf-eaab-49f4-806c-a27e3914d70f/modify |
2022-09-14T15:06:38Z [INFO][SMF][PduSess] Receive Update SM Context Request
2022-09-14T15:06:38Z [INFO][SMF][PduSess] In HandlePDUSessionSMContextUpdate
2022-09-14T15:06:38Z [ERRO][SMF][PduSess] Handle PDUSessionResourceSetupResponseTransfer failed: Get bits overflow, requireBits: 8, leftBits: 5
2022-09-14T15:06:38Z [WARN][SMF][PduSess] SM Context State [Active] shouldn't be here
2022-09-14T15:06:38Z [INFO][SMF][GIN] | 200 | 10.100.200.13 | POST | /nsmf-pdusession/v1/sm-contexts/urn:uuid:2c7adeaf-eaab-49f4-806c-a27e3914d70f/modify |
2022-09-14T15:08:01Z [INFO][SMF][PduSess] Receive Create SM Context Request
2022-09-14T15:08:01Z [INFO][SMF][PduSess] In HandlePDUSessionSMContextCreate
2022-09-14T15:08:01Z [INFO][LIB][PFCP] Remove Request Transaction [4]
2022-09-14T15:08:01Z [INFO][SMF][PFCP] Handle PFCP Session Deletion Response
2022-09-14T15:08:01Z [INFO][SMF][PFCP] PFCP Session Deletion Success[1]
2022-09-14T15:08:01Z [INFO][SMF][CTX] [SMF] Send SMContext Status Notification
2022-09-14T15:08:01Z [WARN][SMF][PduSess] Send SMContextStatus Notification Error[404 Not Found]
2022-09-14T15:08:01Z [WARN][SMF][PduSess] Send SMContext Status Notification Problem[&{Type: Title: Status:404 Detail:Guti[00101cafe0000000001] Not Found Instance: Cause:CONTEXT_NOT_FOUND InvalidParams:[]}]
2022-09-14T15:08:01Z [INFO][SMF][PduSess] UE[imsi-001010000000012] PDUSessionID[1] Release IP[10.60.0.1]
Best regards,
Ziran
The text was updated successfully, but these errors were encountered: