free5gc / smf Goto Github PK

Hello we need to correct import path in smf. For example,
"free5gc/lib/path_util" ==> github.com/free5gc/path_util
All files should be changed

func HandlePDUSessionSMContextRelease(rspChan chan smf_message.HandlerResponseMessage, smContextRef string, body models.ReleaseSmContextRequest) (seqNum uint32) {
.
for curDataPathNode := dataPath.FirstDPNode; curDataPathNode != nil; curDataPathNode.Next() {
.

correct:
for curDataPathNode := dataPath.FirstDPNode; curDataPathNode != nil; curDataPathNode = curDataPathNode.Next() {

Before SMF crashed, SMF assigned an IP 60.60.0.1 to UE imsi-208930000000004. Then, SMF crashed. After recovery, it assigned the same IP 60.60.0.1 to UE imsi-208930000000003.

`smf
2022-03-24T05:57:35Z [INFO][SMF][App] SMF version:
free5GC version: v3.0.6
build time: 2022-03-08T19:56:36Z
commit hash: 46644f0
commit time: 2021-09-13T13:23:12Z
go version: go1.14.4 linux/amd64
2022-03-24T05:57:35Z [INFO][SMF][Init] SMF Log level is set to [info] level
2022-03-24T05:57:35Z [INFO][LIB][NAS] set log level : info
2022-03-24T05:57:35Z [INFO][LIB][NAS] set report call : false
2022-03-24T05:57:35Z [INFO][LIB][NGAP] set log level : info
2022-03-24T05:57:35Z [INFO][LIB][NGAP] set report call : false
2022-03-24T05:57:35Z [INFO][LIB][Aper] set log level : info
2022-03-24T05:57:35Z [INFO][LIB][Aper] set report call : false
2022-03-24T05:57:35Z [INFO][LIB][Path] set log level : info
2022-03-24T05:57:35Z [INFO][LIB][Path] set report call : false
2022-03-24T05:57:35Z [INFO][LIB][OAPI] set log level : info
2022-03-24T05:57:35Z [INFO][LIB][OAPI] set report call : false
2022-03-24T05:57:35Z [INFO][LIB][PFCP] set log level : info
2022-03-24T05:57:35Z [INFO][LIB][PFCP] set report call : false
2022-03-24T05:57:35Z [INFO][SMF][CFG] SMF config version [1.0.2]
2022-03-24T05:57:35Z [INFO][SMF][CFG] UE-Routing config version [1.0.1]
2022-03-24T05:57:35Z [INFO][SMF][CTX] smfconfig Info: Version[1.0.2] Description[SMF initial local configuration]
2022-03-24T05:57:35Z [INFO][SMF][CTX] Endpoints: [upf0.free5gc.org]
2022-03-24T05:57:35Z [INFO][SMF][CTX] Endpoints: [upf1.free5gc.org]
2022-03-24T05:57:35Z [INFO][SMF][CTX] Endpoints: [upf2.free5gc.org]
2022-03-24T05:57:35Z [INFO][SMF][CTX] Endpoints: [upf3.free5gc.org]
2022-03-24T05:57:35Z [INFO][SMF][CTX] ue routing config Info: Version[1.0.1] Description[Routing information for UE]
2022-03-24T05:57:35Z [INFO][SMF][PduSess] In NewUEPreConfigPaths
2022-03-24T05:57:35Z [INFO][SMF][PduSess] In NewUEPreConfigPaths
2022-03-24T05:57:35Z [INFO][SMF][PduSess] In NewUEPreConfigPaths
2022-03-24T05:57:35Z [INFO][SMF][Init] Server started
2022-03-24T05:57:36Z [INFO][SMF][Init] SMF Registration to NRF {45e50e9b-2152-4a36-b1cb-0ab9da9417ff SMF REGISTERED 0 0xc00000c240 0xc00000c280 [] [] [smf.free5gc.org] [] [] [] 0 0 0 area1 0xc0000a6180 map[] false 0xc00000c0c0 false false []}
2022-03-24T05:57:36Z [INFO][SMF][PFCP] Listen on 10.100.200.8:8805
2022-03-24T05:57:36Z [INFO][SMF][App] Send PFCP Association Request to UPFupf1.free5gc.org
2022-03-24T05:57:36Z [INFO][SMF][App] Send PFCP Association Request to UPFupf2.free5gc.org
2022-03-24T05:57:36Z [INFO][SMF][App] Send PFCP Association Request to UPFupf3.free5gc.org
2022-03-24T05:57:36Z [INFO][SMF][App] Send PFCP Association Request to UPFupf0.free5gc.org
2022-03-24T05:57:36Z [INFO][SMF][PFCP] In HandlePfcpAssociationSetupResponse
2022-03-24T05:57:36Z [INFO][SMF][PFCP] In HandlePfcpAssociationSetupResponse
2022-03-24T05:57:36Z [INFO][LIB][PFCP] Remove Request Transaction [2]
2022-03-24T05:57:36Z [INFO][SMF][PFCP] Handle PFCP Association Setup Response with NodeID[10.100.200.202]
2022-03-24T05:57:36Z [INFO][SMF][PFCP] In HandlePfcpAssociationSetupResponse
2022-03-24T05:57:36Z [INFO][SMF][PFCP] Handle PFCP Association Setup Response with NodeID[10.100.200.200]
2022-03-24T05:57:36Z [INFO][SMF][PFCP] Handle PFCP Association Setup Response with NodeID[10.100.200.203]
2022-03-24T05:57:36Z [INFO][SMF][PFCP] In HandlePfcpAssociationSetupResponse
2022-03-24T05:57:36Z [INFO][SMF][PFCP] Handle PFCP Association Setup Response with NodeID[10.100.200.201]
2022-03-24T05:57:36Z [INFO][LIB][PFCP] Remove Request Transaction [3]
2022-03-24T05:57:36Z [INFO][LIB][PFCP] Remove Request Transaction [4]
2022-03-24T05:57:36Z [INFO][LIB][PFCP] Remove Request Transaction [1]
2022-03-24T05:57:36Z [INFO][SMF][PFCP] UPF(10.100.200.200)[internet] setup association
2022-03-24T05:57:36Z [INFO][SMF][PFCP] UPF(10.100.200.203)[internet3] setup association
2022-03-24T05:57:36Z [INFO][SMF][PFCP] UPF(10.100.200.202)[internet2] setup association
2022-03-24T05:57:36Z [INFO][SMF][PFCP] UPF(10.100.200.201)[internet0] setup association
2022-03-24T05:58:56Z [INFO][SMF][PduSess] Recieve Create SM Context Request
2022-03-24T05:58:56Z [INFO][SMF][PduSess] In HandlePDUSessionSMContextCreate
2022-03-24T05:58:56Z [INFO][SMF][PduSess] Send NF Discovery Serving UDM Successfully
2022-03-24T05:58:56Z [INFO][SMF][CTX] Allocated UE IP address: 60.60.0.1
2022-03-24T05:58:56Z [INFO][SMF][CTX] Selected UPF: AnchorUPF0
2022-03-24T05:58:56Z [INFO][SMF][GSM] In HandlePDUSessionEstablishmentRequest
2022-03-24T05:58:56Z [INFO][NAS][Convert] ProtocolOrContainerList: [0xc00050d720 0xc00050d760]
2022-03-24T05:58:56Z [INFO][SMF][GSM] Protocol Configuration Options
2022-03-24T05:58:56Z [INFO][SMF][GSM] &{[0xc00050d720 0xc00050d760]}
2022-03-24T05:58:56Z [INFO][SMF][GSM] Didn't Implement container type IPAddressAllocationViaNASSignallingUL
2022-03-24T05:58:56Z [INFO][SMF][PduSess] PCF Selection for SMContext SUPI[imsi-208930000000004] PDUSessionID[1]
2022-03-24T05:58:56Z [INFO][SMF][PduSess] SUPI[imsi-208930000000004] has pre-config route
2022-03-24T05:58:56Z [INFO][SMF][Consumer] SendNFDiscoveryServingAMF ok
2022-03-24T05:58:56Z [INFO][SMF][GIN] | 201 | 10.100.200.102 | POST | /nsmf-pdusession/v1/sm-contexts |
2022-03-24T05:58:56Z [INFO][SMF][PFCP] In HandlePfcpSessionEstablishmentResponse
2022-03-24T05:58:56Z [INFO][LIB][PFCP] Remove Request Transaction [5]
&{200 Mbps 100 Mbps}
2022-03-24T05:58:56Z [INFO][SMF][PduSess] Recieve Update SM Context Request
2022-03-24T05:58:56Z [INFO][SMF][PduSess] In HandlePDUSessionSMContextUpdate
2022-03-24T05:58:56Z [INFO][LIB][PFCP] Remove Request Transaction [6]
2022-03-24T05:58:56Z [INFO][SMF][PFCP] In HandlePfcpSessionModificationResponse
2022-03-24T05:58:56Z [INFO][SMF][PduSess] [SMF] PFCP Modification Resonse Accept
2022-03-24T05:58:56Z [INFO][SMF][PFCP] Add PSAAndULCL
2022-03-24T05:58:56Z [INFO][SMF][GIN] | 200 | 10.100.200.102 | POST | /nsmf-pdusession/v1/sm-contexts/urn:uuid:e4711b42-9594-4ff2-85f6-1970cf63602f/modify |
panic: runtime error: invalid memory address or nil pointer dereference
[signal SIGSEGV: segmentation violation code=0x1 addr=0x40 pc=0xb3433b]

goroutine 48 [running]:
github.com/free5gc/smf/context.(*SMContext).AllocateLocalSEIDForDataPath(0xc0003ae000, 0x0)
/go/src/free5gc/NFs/smf/context/sm_context.go:309 +0x8b
github.com/free5gc/smf/producer.AddPDUSessionAnchorAndULCL(0xc0003ae000, 0x2, 0xc0004280a0, 0x10, 0x10)
/go/src/free5gc/NFs/smf/producer/ulcl_procedure.go:23 +0x2c5
github.com/free5gc/smf/pfcp/handler.HandlePfcpSessionModificationResponse(0xc000536950)
/go/src/free5gc/NFs/smf/pfcp/handler/handler.go:248 +0x6c4
github.com/free5gc/smf/pfcp.Dispatch(0xc000536950)
/go/src/free5gc/NFs/smf/pfcp/dispatcher.go:45 +0x48a
created by github.com/free5gc/smf/pfcp/udp.Run.func1
/go/src/free5gc/NFs/smf/pfcp/udp/udp.go:44 +0x1d1
smf
2022-03-24T05:58:57Z [INFO][SMF][App] SMF version:
free5GC version: v3.0.6
build time: 2022-03-08T19:56:36Z
commit hash: 46644f0
commit time: 2021-09-13T13:23:12Z
go version: go1.14.4 linux/amd64
2022-03-24T05:58:57Z [INFO][SMF][Init] SMF Log level is set to [info] level
2022-03-24T05:58:57Z [INFO][LIB][NAS] set log level : info
2022-03-24T05:58:57Z [INFO][LIB][NAS] set report call : false
2022-03-24T05:58:57Z [INFO][LIB][NGAP] set log level : info
2022-03-24T05:58:57Z [INFO][LIB][NGAP] set report call : false
2022-03-24T05:58:57Z [INFO][LIB][Aper] set log level : info
2022-03-24T05:58:57Z [INFO][LIB][Aper] set report call : false
2022-03-24T05:58:57Z [INFO][LIB][Path] set log level : info
2022-03-24T05:58:57Z [INFO][LIB][Path] set report call : false
2022-03-24T05:58:57Z [INFO][LIB][OAPI] set log level : info
2022-03-24T05:58:57Z [INFO][LIB][OAPI] set report call : false
2022-03-24T05:58:57Z [INFO][LIB][PFCP] set log level : info
2022-03-24T05:58:57Z [INFO][LIB][PFCP] set report call : false
2022-03-24T05:58:57Z [INFO][SMF][CFG] SMF config version [1.0.2]
2022-03-24T05:58:57Z [INFO][SMF][CFG] UE-Routing config version [1.0.1]
2022-03-24T05:58:57Z [INFO][SMF][CTX] smfconfig Info: Version[1.0.2] Description[SMF initial local configuration]
2022-03-24T05:58:57Z [INFO][SMF][CTX] Endpoints: [upf0.free5gc.org]
2022-03-24T05:58:57Z [INFO][SMF][CTX] Endpoints: [upf1.free5gc.org]
2022-03-24T05:58:57Z [INFO][SMF][CTX] Endpoints: [upf2.free5gc.org]
2022-03-24T05:58:57Z [INFO][SMF][CTX] Endpoints: [upf3.free5gc.org]
2022-03-24T05:58:57Z [INFO][SMF][CTX] ue routing config Info: Version[1.0.1] Description[Routing information for UE]
2022-03-24T05:58:57Z [INFO][SMF][PduSess] In NewUEPreConfigPaths
2022-03-24T05:58:57Z [INFO][SMF][PduSess] In NewUEPreConfigPaths
2022-03-24T05:58:57Z [INFO][SMF][PduSess] In NewUEPreConfigPaths
2022-03-24T05:58:57Z [INFO][SMF][Init] Server started
2022-03-24T05:58:57Z [INFO][SMF][Init] SMF Registration to NRF {82f6146f-220c-4414-ae0b-0d729c7226ab SMF REGISTERED 0 0xc00049a840 0xc00049a880 [] [] [smf.free5gc.org] [] [] [] 0 0 0 area1 0xc000122a80 map[] false 0xc00049a6c0 false false []}
2022-03-24T05:58:57Z [INFO][SMF][PFCP] Listen on 10.100.200.8:8805
2022-03-24T05:58:57Z [INFO][SMF][App] Send PFCP Association Request to UPFupf0.free5gc.org
2022-03-24T05:58:57Z [INFO][SMF][App] Send PFCP Association Request to UPFupf1.free5gc.org
2022-03-24T05:58:57Z [INFO][SMF][App] Send PFCP Association Request to UPFupf2.free5gc.org
2022-03-24T05:58:57Z [INFO][SMF][App] Send PFCP Association Request to UPFupf3.free5gc.org
2022-03-24T05:58:57Z [INFO][SMF][PFCP] In HandlePfcpAssociationSetupResponse
2022-03-24T05:58:57Z [INFO][LIB][PFCP] Remove Request Transaction [1]
2022-03-24T05:58:57Z [INFO][SMF][PFCP] Handle PFCP Association Setup Response with NodeID[10.100.200.200]
2022-03-24T05:58:57Z [INFO][SMF][PFCP] UPF(10.100.200.200)[internet] setup association
2022-03-24T05:58:57Z [INFO][SMF][PFCP] In HandlePfcpAssociationSetupResponse
2022-03-24T05:58:57Z [INFO][SMF][PFCP] Handle PFCP Association Setup Response with NodeID[10.100.200.203]
2022-03-24T05:58:57Z [INFO][LIB][PFCP] Remove Request Transaction [2]
2022-03-24T05:58:57Z [INFO][LIB][PFCP] Remove Request Transaction [4]
2022-03-24T05:58:57Z [INFO][LIB][PFCP] Remove Request Transaction [3]
2022-03-24T05:58:57Z [INFO][SMF][PFCP] In HandlePfcpAssociationSetupResponse
2022-03-24T05:58:57Z [INFO][SMF][PFCP] In HandlePfcpAssociationSetupResponse
2022-03-24T05:58:57Z [INFO][SMF][PFCP] Handle PFCP Association Setup Response with NodeID[10.100.200.202]
2022-03-24T05:58:57Z [INFO][SMF][PFCP] Handle PFCP Association Setup Response with NodeID[10.100.200.201]
2022-03-24T05:58:57Z [INFO][SMF][PFCP] UPF(10.100.200.202)[internet2] setup association
2022-03-24T05:58:57Z [INFO][SMF][PFCP] UPF(10.100.200.201)[internet0] setup association
2022-03-24T05:58:57Z [INFO][SMF][PFCP] UPF(10.100.200.203)[internet3] setup association
2022-03-24T06:00:49Z [INFO][SMF][PduSess] Recieve Create SM Context Request
2022-03-24T06:00:49Z [INFO][SMF][PduSess] In HandlePDUSessionSMContextCreate
2022-03-24T06:00:49Z [INFO][SMF][PduSess] Send NF Discovery Serving UDM Successfully
2022-03-24T06:00:49Z [INFO][SMF][CTX] Allocated UE IP address: 60.60.0.1
2022-03-24T06:00:49Z [INFO][SMF][CTX] Selected UPF: AnchorUPF0
2022/03/24 06:00:49 http2: server connection error from 10.100.200.102:54962: connection error: PROTOCOL_ERROR
2022-03-24T06:00:49Z [INFO][SMF][GSM] In HandlePDUSessionEstablishmentRequest
2022-03-24T06:00:49Z [INFO][NAS][Convert] ProtocolOrContainerList: [0xc00026d6a0 0xc00026d6e0]
2022-03-24T06:00:49Z [INFO][SMF][GSM] Protocol Configuration Options
2022-03-24T06:00:49Z [INFO][SMF][GSM] &{[0xc00026d6a0 0xc00026d6e0]}
2022-03-24T06:00:49Z [INFO][SMF][GSM] Didn't Implement container type IPAddressAllocationViaNASSignallingUL
2022-03-24T06:00:49Z [INFO][SMF][PduSess] PCF Selection for SMContext SUPI[imsi-208930000000003] PDUSessionID[1]
2022-03-24T06:00:49Z [INFO][SMF][PduSess] SUPI[imsi-208930000000003] has pre-config route
2022-03-24T06:00:49Z [INFO][SMF][Consumer] SendNFDiscoveryServingAMF ok
2022-03-24T06:00:49Z [INFO][SMF][GIN] | 201 | 10.100.200.102 | POST | /nsmf-pdusession/v1/sm-contexts |
2022-03-24T06:00:49Z [INFO][LIB][PFCP] Remove Request Transaction [5]
2022-03-24T06:00:49Z [INFO][SMF][PFCP] In HandlePfcpSessionEstablishmentResponse
2022-03-24T06:00:50Z [INFO][SMF][PduSess] Recieve Update SM Context Request
2022-03-24T06:00:50Z [INFO][SMF][PduSess] In HandlePDUSessionSMContextUpdate
2022-03-24T06:00:50Z [WARN][SMF][PduSess] SMContext[imsi-208930000000003-01] should be Active, but actual ModificationPending
2022-03-24T06:00:50Z [INFO][SMF][CTX] [SMF] Cause_REL_DUE_TO_DUPLICATE_SESSION_ID
2022-03-24T06:00:50Z [INFO][SMF][PduSess] Send PFCP Deletion from HandlePDUSessionSMContextUpdate
2022-03-24T06:00:59Z [INFO][LIB][PFCP] Remove Request Transaction [6]
2022-03-24T06:07:13Z [INFO][SMF][GIN] | 404 | 10.100.200.5 | GET | /nsmf-oam/v1/ue-pdu-session-info/urn:uuid:e4711b42-9594-4ff2-85f6-1970cf63602f |
2022-03-24T06:07:17Z [INFO][SMF][GIN] | 404 | 10.100.200.5 | GET | /nsmf-oam/v1/ue-pdu-session-info/urn:uuid:e4711b42-9594-4ff2-85f6-1970cf63602f |`

This is from ISL at NYCU, we bumped into this bug earlier today. This is the command we used to start the SMF:
./bin/${NF} -c ./config/${NF}cfg.yaml -l ${LOG_PATH}${NF}.log -lc ${LOG_PATH}${LOG_NAME} &

We see that in this line below, the log5gc is deleted, but I'm not sure if you are planning to remove the loggings of smf from the aggregated log file.

We are using the main branch (after @74cf154afc0073cde4a5084d588e681e60228c39) because the commit hash (main@5d5daa889b) of the smf submodule specified in free5gc still has the issue of #55 when associating with UPF provided by other vendors. We wonder if you can update the commit id on the free5gc main branch (or release v3.2.1)? Tks!

We run ./test.sh -o TestPDUSessionReleaseRequest . The IP release log is not seen.
So, it seems that previously, the smContext was released when the PDU Session Release Complete GMM message was received, but the latest version no longer releases the smContext.
We think this issue was introduced by the 995e883.

Hi, since the main branch on this repository is called main, could you remove the additional master branch? It is confusing to have both. and it may take time to realize a newly created branch has been forked by mistake from master instead of main.

I have a free5gc core v3.0.6 installed as docker-compose with gNB and UE (UERANSIM v3.2.5) running in separate VMs with an access connectivity to core.

SMF defines both default routes (links:) and specific routes (ueRoutingInfo:) which is working properly.

However, when I remove specificPath: from ueRoutingInfo: then SMF crashes when I create PDU session for a UE that has a specific route.

I can see that it is an optional attribute (config.go):

SpecificPaths []SpecificPath `yaml:"specificPath,omitempty"`

Please find SMF uerouting configuration:

info:
  version: 1.0.1
  description: Routing information for UE

ueRoutingInfo: # the list of UE routing information
  UE-gNB-1-1: # Group Name
    members:
    - imsi-208930000000002 # Subscription Permanent Identifier of the UE
    - imsi-208930000000001 # Subscription Permanent Identifier of the UE
    topology:
    # Network topology for this group (Uplink: A->B, Downlink: B->A)
    # default path derived from this topology
    # node name should be consistent with smfcfg.yaml
      - A: gNB1
        B: UPF-R1
      - A: UPF-R1
        B: UPF-T1

Please find corresponding SMF logs:

smf       | 2021-12-22T11:15:23Z [INFO][SMF][App] SMF version:
smf       |     free5GC version: v3.0.6
smf       |     build time:      2021-12-19T13:22:19Z
smf       |     commit hash:     46644f0a
smf       |     commit time:     2021-09-13T13:23:12Z
smf       |     go version:      go1.14.4 linux/amd64
smf       | 2021-12-22T11:15:23Z [INFO][SMF][Init] SMF Log level is set to [debug] level
...
smf       | 2021-12-22T11:16:08Z [DEBU][LIB][Aper] Field "IEExtensions" in ngapType.PDUSessionResourceSetupResponseTransfer is OPTIONAL and not present (aper.go:829)
smf       | 2021-12-22T11:16:08Z [INFO][SMF][PFCP] In HandlePfcpSessionModificationResponse
smf       | 2021-12-22T11:16:08Z [INFO][SMF][PduSess] [SMF] PFCP Modification Resonse Accept
smf       | 2021-12-22T11:16:08Z [INFO][LIB][PFCP] Remove Request Transaction [12]
smf       | 2021-12-22T11:16:08Z [INFO][SMF][PFCP] Add PSAAndULCL
smf       | panic: runtime error: invalid memory address or nil pointer dereference
smf       | [signal SIGSEGV: segmentation violation code=0x1 addr=0x40 pc=0xb3433b]
smf       |
smf       | goroutine 463 [running]:
smf       | github.com/free5gc/smf/context.(*SMContext).AllocateLocalSEIDForDataPath(0xc000076600, 0x0)
smf       |     /go/src/free5gc/NFs/smf/context/sm_context.go:309 +0x8b
smf       | github.com/free5gc/smf/producer.AddPDUSessionAnchorAndULCL(0xc000076600, 0x2, 0xc000022d40, 0x12, 0x20)
smf       |     /go/src/free5gc/NFs/smf/producer/ulcl_procedure.go:23 +0x2c5
smf       | github.com/free5gc/smf/pfcp/handler.HandlePfcpSessionModificationResponse(0xc0001ad180)
smf       |     /go/src/free5gc/NFs/smf/pfcp/handler/handler.go:248 +0x6c4
smf       | github.com/free5gc/smf/pfcp.Dispatch(0xc0001ad180)
smf       |     /go/src/free5gc/NFs/smf/pfcp/dispatcher.go:45 +0x48a
smf       | created by github.com/free5gc/smf/pfcp/udp.Run.func1
smf       |     /go/src/free5gc/NFs/smf/pfcp/udp/udp.go:44 +0x1d1
smf exited with code 2

Thanks.

The response header to an SM contexts collection request
{apiRoot}/nsmf-pdusession/{apiVersion}/sm-contexts
should include a location field with the URI of the newly created resource, according to the structure:
{apiRoot}/nsmf-pdusession/{apiVersion}/sm-contexts/{smContextRef}
Currently the location field is filled with something like:
urn:uuid:7a51fda4-2d05-45d0-9988-1eacfa378310 (this is only the smContextRef)
The other free5GC components are aware of that and build the correct URI themselfs, but one can not use the free5GC SMF with other standard compliant components as they can not handle the format free5GCs SMF is providing in the location field.

See 3GPP TS 29.502 -> Resource: SM contexts collection -> Headers supported by the 201 Response Code on this resource

As shown in the following code snippets, if the input PDU Session Modification Request message does not have the IE for QoSRules or QoSFlowDescs, empty variables reqQoSRules and reqQoSFlowDescs will be passed to the function SendSMPolicyAssociationUpdateByUERequestModification(), resulting an index out of range panic.

• SMF version: v1.0.1, commit 46644f0

2021-11-18T08:42:42Z [INFO][SMF][Init] Server started
[GIN-debug] [WARNING] Running in "debug" mode. Switch to "release" mode in production.
 - using env:   export GIN_MODE=release
 - using code:  gin.SetMode(gin.ReleaseMode)

2021-11-18T08:42:42Z [INFO][SMF][Init] SMF Registration to NRF {3421ae94-487c-4b69-81b9-a5af1bbd5383 SMF REGISTERED 0 0xc000454168 0xc000454198 [] []   [smf1.sbi-net] [] <nil> [] [] <nil> 0 0 0 loc1 <nil> <nil> <nil> <nil> 0xc000430140 <nil> <nil> <nil> <nil> <nil> map[] <nil> false 0xc000454060 false false []}
[GIN-debug] GET    /nsmf-oam/v1/             --> github.com/free5gc/smf/oam.Index (3 handlers)
[GIN-debug] GET    /nsmf-oam/v1/ue-pdu-session-info/:smContextRef --> github.com/free5gc/smf/oam.HTTPGetUEPDUSessionInfo (3 handlers)
[GIN-debug] POST   /nsmf-callback/sm-policies/:smContextRef/update --> github.com/free5gc/smf/callback.HTTPSmPolicyUpdateNotification (3 handlers)
[GIN-debug] POST   /nsmf-callback/sm-policies/:smContextRef/terminate --> github.com/free5gc/smf/callback.SmPolicyControlTerminationRequestNotification (3 handlers)
[GIN-debug] GET    /nsmf-pdusession/v1/      --> github.com/free5gc/smf/pdusession.Index (3 handlers)
[GIN-debug] POST   /nsmf-pdusession/v1/pdu-sessions/:pduSessionRef/release --> github.com/free5gc/smf/pdusession.ReleasePduSession (3 handlers)
[GIN-debug] POST   /nsmf-pdusession/v1/pdu-sessions/:pduSessionRef/modify --> github.com/free5gc/smf/pdusession.UpdatePduSession (3 handlers)
[GIN-debug] POST   /nsmf-pdusession/v1/sm-contexts/:smContextRef/release --> github.com/free5gc/smf/pdusession.HTTPReleaseSmContext (3 handlers)
[GIN-debug] POST   /nsmf-pdusession/v1/sm-contexts/:smContextRef/retrieve --> github.com/free5gc/smf/pdusession.RetrieveSmContext (3 handlers)
[GIN-debug] POST   /nsmf-pdusession/v1/sm-contexts/:smContextRef/modify --> github.com/free5gc/smf/pdusession.HTTPUpdateSmContext (3 handlers)
[GIN-debug] POST   /nsmf-pdusession/v1/pdu-sessions --> github.com/free5gc/smf/pdusession.PostPduSessions (3 handlers)
[GIN-debug] POST   /nsmf-pdusession/v1/sm-contexts --> github.com/free5gc/smf/pdusession.HTTPPostSmContexts (3 handlers)
[GIN-debug] GET    /nsmf_event-exposure/v1   --> github.com/free5gc/smf/eventexposure.Index (3 handlers)
[GIN-debug] POST   /nsmf_event-exposure/v1/subscriptions --> github.com/free5gc/smf/eventexposure.SubscriptionsPost (3 handlers)
[GIN-debug] DELETE /nsmf_event-exposure/v1/subscriptions/:subId --> github.com/free5gc/smf/eventexposure.SubscriptionsSubIdDelete (3 handlers)
[GIN-debug] GET    /nsmf_event-exposure/v1/subscriptions/:subId --> github.com/free5gc/smf/eventexposure.SubscriptionsSubIdGet (3 handlers)
[GIN-debug] PUT    /nsmf_event-exposure/v1/subscriptions/:subId --> github.com/free5gc/smf/eventexposure.SubscriptionsSubIdPut (3 handlers)
2021-11-18T08:42:42Z [INFO][SMF][PFCP] Listen on 10.0.210.2:8805
2021-11-18T08:42:42Z [INFO][SMF][App] Send PFCP Association Request to UPF[10.0.210.5]
2021-11-18T08:42:42Z [INFO][SMF][App] Send PFCP Association Request to UPF[10.0.210.3]
2021-11-18T08:42:42Z [INFO][SMF][App] Send PFCP Association Request to UPF[10.0.210.7]
2021-11-18T08:42:42Z [INFO][SMF][App] Send PFCP Association Request to UPF[10.0.210.4]
2021-11-18T08:42:42Z [INFO][SMF][PFCP] In HandlePfcpAssociationSetupResponse
2021-11-18T08:42:42Z [INFO][LIB][PFCP] Remove Request Transaction [4]
2021-11-18T08:42:42Z [INFO][SMF][PFCP] Handle PFCP Association Setup Response with NodeID[10.0.210.7]
2021-11-18T08:42:42Z [INFO][SMF][PFCP] In HandlePfcpAssociationSetupResponse
2021-11-18T08:42:42Z [INFO][LIB][PFCP] Remove Request Transaction [3]
2021-11-18T08:42:42Z [INFO][LIB][PFCP] Remove Request Transaction [2]
2021-11-18T08:42:42Z [INFO][SMF][PFCP] Handle PFCP Association Setup Response with NodeID[10.0.210.3]
2021-11-18T08:42:42Z [INFO][SMF][PFCP] UPF(10.0.210.3)[sliceA] setup association
2021-11-18T08:42:42Z [INFO][SMF][PFCP] UPF(10.0.210.7)[sliceA] setup association
2021-11-18T08:42:42Z [INFO][SMF][PFCP] In HandlePfcpAssociationSetupResponse
2021-11-18T08:42:42Z [INFO][SMF][PFCP] Handle PFCP Association Setup Response with NodeID[10.0.210.4]
2021-11-18T08:42:42Z [INFO][SMF][PFCP] UPF(10.0.210.4)[sliceA] setup association
2021-11-18T08:42:51Z [INFO][LIB][PFCP] Remove Request Transaction [1]
2021-11-18T08:42:53Z [INFO][SMF][PduSess] Recieve Create SM Context Request
2021-11-18T08:42:53Z [INFO][SMF][PduSess] In HandlePDUSessionSMContextCreate
2021-11-18T08:42:53Z [INFO][SMF][PduSess] Send NF Discovery Serving UDM Successfully
2021-11-18T08:42:53Z [INFO][SMF][CTX] Allocated UE IP address: 10.0.222.1
2021-11-18T08:42:53Z [INFO][SMF][CTX] Selected UPF: upf-sliceA
2021-11-18T08:42:53Z [INFO][SMF][GSM] In HandlePDUSessionEstablishmentRequest
2021-11-18T08:42:53Z [INFO][NAS][Convert] ProtocolOrContainerList:  [0xc0005982c0 0xc0005982e0]
2021-11-18T08:42:53Z [INFO][SMF][GSM] Protocol Configuration Options
2021-11-18T08:42:53Z [INFO][SMF][GSM] &{[0xc0005982c0 0xc0005982e0]}
2021-11-18T08:42:53Z [INFO][SMF][GSM] Didn't Implement container type IPAddressAllocationViaNASSignallingUL
2021-11-18T08:42:53Z [INFO][SMF][PduSess] PCF Selection for SMContext SUPI[imsi-001010000000000] PDUSessionID[1]
2021-11-18T08:42:53Z [INFO][SMF][PduSess] SUPI[imsi-001010000000000] has pre-config route
2021-11-18T08:42:53Z [INFO][SMF][Consumer] SendNFDiscoveryServingAMF ok
2021-11-18T08:42:53Z [INFO][SMF][GIN] | 201 |      10.0.211.4 | POST    | /nsmf-pdusession/v1/sm-contexts |
&{500 Mbps 500 Mbps}
2021-11-18T08:42:53Z [INFO][SMF][PFCP] In HandlePfcpSessionEstablishmentResponse
2021-11-18T08:42:53Z [INFO][SMF][PFCP] In HandlePfcpSessionEstablishmentResponse
2021-11-18T08:42:53Z [INFO][LIB][PFCP] Remove Request Transaction [6]
2021-11-18T08:42:53Z [INFO][LIB][PFCP] Remove Request Transaction [5]
2021-11-18T08:42:53Z [INFO][SMF][PduSess] Recieve Update SM Context Request
2021-11-18T08:42:53Z [INFO][SMF][PduSess] In HandlePDUSessionSMContextUpdate
2021-11-18T08:42:53Z [INFO][SMF][PFCP] In HandlePfcpSessionModificationResponse
2021-11-18T08:42:53Z [INFO][SMF][PduSess] [SMF] PFCP Modification Resonse Accept
2021-11-18T08:42:53Z [INFO][SMF][PFCP] Add PSAAndULCL
2021-11-18T08:42:53Z [ERRO][SMF][CTX] In ActivateUpLinkTunnel UPF IP:  10.0.210.5
2021-11-18T08:42:53Z [ERRO][SMF][CTX] Allocate PDR Error:  this upf do not associate with smf
2021-11-18T08:42:53Z [WARN][SMF][CTX] Add PDR failed: this upf do not associate with smf
2021-11-18T08:42:53Z [INFO][SMF][PduSess] Establish PSA2
panic: runtime error: invalid memory address or nil pointer dereference
[signal SIGSEGV: segmentation violation code=0x1 addr=0x0 pc=0xa6555c]

goroutine 147 [running]:
github.com/free5gc/smf/producer.EstablishPSA2(0xc0005f4000)
        /go/src/free5gc/NFs/smf/producer/ulcl_procedure.go:152 +0x61c
github.com/free5gc/smf/producer.AddPDUSessionAnchorAndULCL(0xc0005f4000, {0x0, {0xc000023f7c, 0x4, 0x4}})
        /go/src/free5gc/NFs/smf/producer/ulcl_procedure.go:36 +0x2d7
github.com/free5gc/smf/pfcp/handler.HandlePfcpSessionModificationResponse(0xc0002d67b0)
        /go/src/free5gc/NFs/smf/pfcp/handler/handler.go:248 +0x45f
github.com/free5gc/smf/pfcp.Dispatch(0xc00056a000)
        /go/src/free5gc/NFs/smf/pfcp/dispatcher.go:45 +0x30b
created by github.com/free5gc/smf/pfcp/udp.Run.func1
        /go/src/free5gc/NFs/smf/pfcp/udp/udp.go:44 +0x1fe

@brianchennn,

I'm currently working on integrating NWDAF with the free5g core. As part of this integration, I need to collect data from each network function component using the event exposure service of each NF. The issue I'm facing is that when I make a subscription to the SMF (Session Management Function), I receive a success code, but I don't receive any reports. I would greatly appreciate your assistance in resolving this issue. Thank you for your help.

url = 'http://192.168.15.202:8009/nsmf_event-exposure/v1/subscriptions'
headers = {
'accept': 'application/json',
'Content-Type': 'application/json'
}

data = {
"subscription": {
"eventList": [
{
"type": "PDU_SESSION_ESTABLISHMENT ",
"immediateFlag": True,
"refId": 0
}
],
"notifUri": "http://192.168.15.202:5000/callback",
"supi": "imsi-208930000000001",
"gpsi": "string",
"anyUeInd": False,
"groupId": "string",
"pduSeId": "string",
"subId": "string",
"notifId": "string",
"ImmeRep": True,
"notifMethod": "CONTINUOUS",
"maxReportNbr": 30,
"expiry": "2023-05-31T11:30:51Z",
"repPeriod": 1,
"guami": "string",
"serviceName": "string",
"supportedFeatures": "FFFF"
}
}

response = requests.post(url, headers=headers, data=json.dumps(data))

Hi,

If for example, a user accidentally specifies a wrong UPF ipaddress/fqdn in smfcfg.yaml, or a UPF becomes unreachable then SMF enters an infinite loop as in the below snippet:

...
smf              | 2023-01-09T12:40:46Z [WARN][LIB][PFCP] Host lookup failed: lookup upfy.free5gc.org on 127.0.0.11:53: no such host
smf              | 2023-01-09T12:40:46.110531355Z [INFO][SMF][PFCP] received a request that is re-sent
smf              | 2023-01-09T12:40:46.111507851Z [INFO][SMF][PFCP] received a request that is re-sent
smf              | 2023-01-09T12:40:46.111688325Z [INFO][SMF][PFCP] received a request that is re-sent
smf              | 2023-01-09T12:40:46.11194104Z [INFO][SMF][App] Sending PFCP Association Request to UPF[upfy.free5gc.org](0.0.0.0)
smf              | 2023-01-09T12:40:46Z [WARN][LIB][PFCP] Host lookup failed: lookup upfy.free5gc.org on 127.0.0.11:53: no such host
smf              | 2023-01-09T12:40:46.116318928Z [INFO][SMF][PFCP] received a request that is re-sent
smf              | 2023-01-09T12:40:46.117371065Z [INFO][SMF][PFCP] received a request that is re-sent
smf              | 2023-01-09T12:40:46.117531576Z [INFO][SMF][PFCP] received a request that is re-sent
smf              | 2023-01-09T12:40:46.117777796Z [INFO][SMF][App] Sending PFCP Association Request to UPF[upfy.free5gc.org](0.0.0.0)
smf              | 2023-01-09T12:40:46Z [WARN][LIB][PFCP] Host lookup failed: lookup upfy.free5gc.org on 127.0.0.11:53: no such host
smf              | 2023-01-09T12:40:46.12364955Z [INFO][SMF][PFCP] received a request that is re-sent
smf              | 2023-01-09T12:40:46.124610823Z [INFO][SMF][PFCP] received a request that is re-sent
smf              | 2023-01-09T12:40:46.125053258Z [INFO][SMF][PFCP] received a request that is re-sent
smf              | 2023-01-09T12:40:46.12526417Z [INFO][SMF][App] Sending PFCP Association Request to UPF[upfy.free5gc.org](0.0.0.0)
smf              | 2023-01-09T12:40:46Z [WARN][LIB][PFCP] Host lookup failed: lookup upfy.free5gc.org on 127.0.0.11:53: no such host
smf              | 2023-01-09T12:40:46.138944451Z [INFO][SMF][PFCP] received a request that is re-sent
smf              | 2023-01-09T12:40:46.139087411Z [INFO][SMF][PFCP] received a request that is re-sent
smf              | 2023-01-09T12:40:46.13919816Z [INFO][SMF][PFCP] received a request that is re-sent
smf              | 2023-01-09T12:40:46.139268451Z [INFO][SMF][App] Sending PFCP Association Request to UPF[upfy.free5gc.org](0.0.0.0)
...

I am using SMF main branch (commit ID: 74cf154) with free5gc-compose on Ubuntu 20.04 VM.

Thanks.

In the PFCP Session Establishment Request message, the 2nd Create FAR IE is missing the mandatory (because Apply Action is present with the field FORW set to 1) Forwarding Parameters IE.

Wireshark screenshot:

I use the following config:
smf-config.yaml

info:
  version: 1.0.2
  description: SMF initial local configuration

configuration:
  smfName: SMF1
  sbi:
    scheme: http
    registerIPv4: smf1.sbi-net # IP used to register to NRF
    bindingIPv4: 10.0.211.3  # IP used to bind the service
    port: 8000
    tls:
      key: config/TLS/smf.key
      pem: config/TLS/smf.pem
  serviceNameList:
    - nsmf-pdusession
    - nsmf-event-exposure
    - nsmf-oam
  snssaiInfos:
    - sNssai:
        sst: 1
        sd: 010203
      dnnInfos:
        - dnn: sliceA
          dns: 
            ipv4: 10.0.224.3
            ipv6: 2001:4860:4860::8888
  plmnList:
    - mcc: "001"
      mnc: "01"

  pfcp:
    addr: 10.0.210.2
  userplaneInformation:
    upNodes:
      ran-area1-1:
        type: AN


      upf-mec-area1:
        type: UPF
        nodeID: 10.0.213.3
        sNssaiUpfInfos:
          - sNssai:
              sst: 1
              sd: 010203
            dnnUpfInfoList:
              - dnn: sliceA
        interfaces:
          - interfaceType: N3
            endpoints:
              - 10.0.201.3
            networkInstance: sliceA
          - interfaceType: N9
            endpoints:
              - 10.0.215.2
            networkInstance: sliceA


      upf-sliceA:
        type: UPF
        nodeID: 10.0.210.3
        sNssaiUpfInfos:
          - sNssai:
              sst: 1
              sd: 010203
            dnnUpfInfoList:
              - dnn: sliceA
                pools:
                  - cidr: 10.0.222.0/24
        interfaces:
          - interfaceType: N9
            endpoints:
              - 10.0.216.2
            networkInstance: sliceA
    links:
      - A: ran-area1-1
        B: upf-mec-area1
      - A: upf-mec-area1
        B: upf-sliceA

  nrfUri: http://nrf.sbi-net:8000 
  ulcl: true

logger:
  SMF:
    debugLevel: trace
    ReportCaller: false
  NAS:
    debugLevel: info
    ReportCaller: false
  NGAP:
    debugLevel: info
    ReportCaller: false
  Aper:
    debugLevel: info
    ReportCaller: false
  PFCP:
    debugLevel: trace
    ReportCaller: false

ue-routing.yaml

info:
  version: 1.0.1
  description: Routing information for UE

ueRoutingInfo: # the list of UE routing information

  MEH:
    members:
      - imsi-001010000000000
      - imsi-001010000000001

    topology:
      - A: ran-area1-1
        B: upf-mec-area1
      - A: upf-mec-area1
        B: upf-sliceA
    specificPath:
      - dest: 10.0.224.3/32
        path: [upf-mec-area1, upf-mec-area1]
      - dest: 10.0.222.0/24
        path: [upf-mec-area1, upf-mec-area1]

SMF does not properly map default path to UPF destination.

Environment:

• free5gc docker compose v3.06
• smf: v1.0.1

I am using the below uerouting.yaml and can see that SMF states that it builds a datapath to UPF-C1: New default data path (gNB1 to UPF-C1) but the path destination is UPF-C2 and not UPF-C1 as it should be. I validated that the 3rd node ip 10.100.200.6 indicated in the attached logs, is of UPF-C2.

Looking into it more, I can see that the method getAllPathByNodeName uses a recursion in which I suspect that allPaths get changed during the recursion stack even-though it is not being explicitly set.

Please find attached SMF logs. If needed, I can send smfcfg.yaml.

Thanks.

ueRoutingInfo: # the list of UE routing information
  UE-gNB-1-1: # Group Name
    members:
    - imsi-208930000000002 # Subscription Permanent Identifier of the UE
    - imsi-208930000000001 # Subscription Permanent Identifier of the UE
    topology:
    # Network topology for this group (Uplink: A->B, Downlink: B->A)
    # default path derived from this topology
    # node name should be consistent with smfcfg.yaml
      - A: gNB1
        B: UPF-R1

      - A: UPF-R1
        B: UPF-T1

      - A: UPF-R1
        B: UPF-T2

      - A: UPF-T1
        B: UPF-C1

      - A: UPF-T1
        B: UPF-C2

      - A: UPF-T2
        B: UPF-C2

      - A: UPF-T2
        B: UPF-C3

      - A: UPF-T2
        B: UPF-C4

    specificPath:
      - dest: 60.61.0.0/16 # the destination IP address on Data Network (DN)
        # the order of UPF nodes in this path. We use the UPF's name to represent each UPF node.
        # The UPF's name should be consistent with smfcfg.yaml
        path: [UPF-R1, UPF-T1, UPF-C1]

smf       | 2022-01-16T13:58:11Z [DEBU][SMF][Init] gNB1 is AN
smf       | 2022-01-16T13:58:11Z [DEBU][SMF][Init] UPF-C1 is Anchor UPF
smf       | 2022-01-16T13:58:11Z [DEBU][SMF][Init] UPF-C2 is Anchor UPF
smf       | 2022-01-16T13:58:11Z [DEBU][SMF][Init] UPF-C3 is Anchor UPF
smf       | 2022-01-16T13:58:11Z [DEBU][SMF][Init] UPF-C4 is Anchor UPF
smf       | 2022-01-16T13:58:11Z [TRAC][SMF][Init] current path: [gNB1]
smf       | 2022-01-16T13:58:11Z [TRAC][SMF][Init] current path: [gNB1 UPF-R1]
smf       | 2022-01-16T13:58:11Z [TRAC][SMF][Init] current path: [gNB1 UPF-R1 UPF-T1]
smf       | 2022-01-16T13:58:11Z [TRAC][SMF][Init] current path: [gNB1 UPF-R1 UPF-T1 UPF-C1]
smf       | 2022-01-16T13:58:11Z [TRAC][SMF][Init] all path: map[0:[UPF-R1 UPF-T1 UPF-C1]]
smf       | 2022-01-16T13:58:11Z [TRAC][SMF][Init] current path: [gNB1 UPF-R1 UPF-T1 UPF-C2]
smf       | 2022-01-16T13:58:11Z [TRAC][SMF][Init] current path: [gNB1 UPF-R1 UPF-T2]
smf       | 2022-01-16T13:58:11Z [TRAC][SMF][Init] current path: [gNB1 UPF-R1 UPF-T2 UPF-C2]
smf       | 2022-01-16T13:58:11Z [TRAC][SMF][Init] current path: [gNB1 UPF-R1 UPF-T2 UPF-C3]
smf       | 2022-01-16T13:58:11Z [TRAC][SMF][Init] current path: [gNB1 UPF-R1 UPF-T2 UPF-C4]
smf       | 2022-01-16T13:58:11Z [TRAC][SMF][CTX] New default data path (gNB1 to UPF-C1):
smf       | 2022-01-16T13:58:11Z [TRAC][SMF][CTX] DataPath Meta Information
smf       | Activated: false
smf       | IsDefault Path: false
smf       | Has Braching Point: false
smf       | Destination IP:
smf       | Destination Port:
smf       | DataPath Routing Information
smf       | 1th Node in the Path
smf       | Current UPF IP: 10.100.200.5
smf       | Previous UPF IP: None
smf       | Next UPF IP: 10.100.200.8
smf       | 2th Node in the Path
smf       | Current UPF IP: 10.100.200.8
smf       | Previous UPF IP: 10.100.200.5
smf       | Next UPF IP: 10.100.200.6
smf       | 3th Node in the Path
smf       | Current UPF IP: 10.100.200.6
smf       | Previous UPF IP: 10.100.200.8
smf       | Next UPF IP: None