SMF crash with segmentation violation when upf does not associate due to failure in pdr allocation

[louisroyer]

• 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