udm, smf: crash on get subscription data

[igo-reek]

Hi everyone!
I try connecting my virtual UE to your stand. UE authentication and policies finishes successfully, then amf send request to create UE sm-context. Session is create, but udm couldn't parse sm-data received from udr. In finaly udm and smf breaks down.

smf.log

ERRO[2020-05-07T05:02:02-07:00]/src/smf/smf_producer/pdu_session.go:72 free5gc/src/smf/smf_producer.HandlePDUSessionSMContextCreate() Get SessionManagementSubscriptionData error: Get https://10.0.1.125:29503/nudm-sdm/v1/imsi-2089300007487/sm-data?dnn=internet&plmn-id=20893&single-nssai=%7B%22sst%22%3A1%2C%22sd%22%3A%22010203%22%7D: unexpected EOF  SMF=pdu_session
ERRO[2020-05-07T05:02:02-07:00]/src/smf/smf_producer/pdu_session.go:78 free5gc/src/smf/smf_producer.HandlePDUSessionSMContextCreate() SessionManagementSubscriptionData from UDM is nil  SMF=pdu_session
INFO[2020-05-07T05:02:02-07:00]/src/smf/smf_producer/pdu_session.go:84 free5gc/src/smf/smf_producer.HandlePDUSessionSMContextCreate() PCF Selection for SMContext SUPI[imsi-2089300007487] PDUSessionID[10]  SMF=pdu_session
calculate  10.0.1.126:8805
In GenerateDataPath
curDataPathNode IP:  10.0.1.126
Is anchor point:  true
DestEndPoint TEID 2
SrcEndPoint TEID 1
[GIN] 2020/05/07 - 05:02:02 | 201 |    86.97954ms |      10.0.1.124 | POST     /nsmf-pdusession/v1/sm-contexts
INFO[2020-05-07T05:02:02-07:00]/src/smf/smf_consumer/Nnrf.go:170 free5gc/src/smf/smf_consumer.SendNFDiscoveryServingAMF() SendNFDiscoveryServingAMF ok                  SMF=app
<nil>
panic: runtime error: invalid memory address or nil pointer dereference
[signal SIGSEGV: segmentation violation code=0x1 addr=0x8 pc=0xa8e8a1]

goroutine 21 [running]:
free5gc/lib/nas/nasConvert.ModelsToSessionAMBR(0x0, 0x0)
	/home/release3/gofree5gc/release/src/free5gc/lib/nas/nasConvert/SessionAMBR.go:20 +0xb1
free5gc/src/smf/smf_context.BuildGSMPDUSessionEstablishmentAccept(0xc0001f5b80, 0x4, 0x4, 0xc0002385a9, 0x4, 0x4)
	/home/igor/go/src/free5gc/src/smf/smf_context/gsm_build.go:27 +0x14e
free5gc/src/smf/smf_pfcp/pfcp_handler.HandlePfcpSessionEstablishmentResponse(0xc000089a20)
	/home/igor/go/src/free5gc/src/smf/smf_pfcp/pfcp_handler/handler.go:145 +0x144
free5gc/src/smf/smf_pfcp.Dispatch(0xc000089a20)
	/home/igor/go/src/free5gc/src/smf/smf_pfcp/dispatcher.go:43 +0x4b2
free5gc/src/smf/smf_handler.Handle()
	/home/igor/go/src/free5gc/src/smf/smf_handler/handler.go:21 +0x191
created by free5gc/src/smf/smf_service.(*SMF).Start
	/home/igor/go/src/free5gc/src/smf/smf_service/smf_init.go:157 +0x30b

udm.log

[GIN] 2020/05/07 - 04:57:17 | 200 |   28.253262ms |      10.0.1.125 | POST     /nudm-ueau/v1/suci-0-208-93-0-0-0-00007487/security-information/generate-auth-data
WARN[2020-05-07T04:59:20-07:00]/src/udm/udm_producer/ue_context_management.go:31 free5gc/src/udm/udm_producer.createUDMClientToUDR() Use default UDR Uri bacause ID[suci-0-208-93-0-0-0-00007487] does not match any UDR  UDM=Handler
[GIN] 2020/05/07 - 04:59:20 | 201 |    4.232114ms |      10.0.1.125 | POST     /nudm-ueau/v1/suci-0-208-93-0-0-0-00007487/auth-events
[GIN] 2020/05/07 - 04:59:35 | 200 |    3.572314ms |      10.0.1.124 | GET      /nudm-sdm/v1/imsi-2089300007487/nssai?plmn-id=20893
https://10.0.1.125:29510
[GIN] 2020/05/07 - 04:59:49 | 201 |   12.839452ms |      10.0.1.124 | PUT      /nudm-uecm/v1/imsi-2089300007487/registrations/amf-3gpp-access
[GIN] 2020/05/07 - 05:00:04 | 201 |    3.684967ms |      10.0.1.124 | POST     /nudm-sdm/v1/imsi-2089300007487/sdm-subscriptions
INFO[2020-05-07T05:02:02-07:00]/src/udm/udm_producer/subscriber_data_management.go:298 free5gc/src/udm/udm_producer.HandleGetSmData() HandleGetSmData SUPI[imsi-2089300007487] PLMNID[20893] DNN[internet] SNssai[{"sst":1,"sd":"010203"}]  UDM=Handler
panic: runtime error: makeslice: cap out of range

goroutine 5 [running]:
free5gc/src/udm/udm_context.ManageSmData(0x0, 0x0, 0x0, 0xc0005c6060, 0x17, 0xc0005be02c, 0x8, 0xc0005f97b8, 0x0, 0x0, ...)
	/home/igor/go/src/free5gc/src/udm/udm_context/udm_context.go:105 +0x98
free5gc/src/udm/udm_producer.HandleGetSmData(0xc000078300, 0xc0005be00d, 0x12, 0xc0005be03d, 0x5, 0xc0005be02c, 0x8, 0xc0005c6060, 0x17, 0x0, ...)
	/home/igor/go/src/free5gc/src/udm/udm_producer/subscriber_data_management.go:324 +0x3f0
free5gc/src/udm/udm_handler.Handle()
	/home/igor/go/src/free5gc/src/udm/udm_handler/handler.go:72 +0xb3b
created by free5gc/src/udm/udm_service.(*UDM).Start
	/home/igor/go/src/free5gc/src/udm/udm_service/udm_init.go:146 +0x57b

[free5gc-org]

Hi,

Can you provide the pcap file and key.log.
Also, what was the subscription information in mongodb?

use free5gc
db.subscriptionData.provisionedData.smData.find()

[igo-reek]

@free5gc-org db is empty, but I assume it's happening because I use my own AMF implementation.
What service puts subscription data in mongodb?

[igo-reek]

Could you please let me know which gNB you are using? I wanna do some test with real equipment.

[endrigoshi]

They do not use any real gNB or UE. Use the registration_test.go in src/test to check if your deployment is correct.

[igo-reek]

Actually, that problem was related to mongodb, which was from stage 2, reinstalling solved it. Thanks for your help.

[free5gc-org]

Seems the problem is solved. I'll close the issue.