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] [] [] [] 0 0 0 loc1 0xc000430140 map[] 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]
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] [] [] [] 0 0 0 loc1 0xc000430140 map[] 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