search

free5gc / free5gc-stage-3

Open source 5G core network base on 3GPP R15
https://free5gc.org
Apache License 2.0
34 stars 24 forks source link

SMF crash on initial UE message, Registration Request #2

Open bjoern-r opened 4 years ago

bjoern-r commented 4 years ago

Hello I tried to connect free5GS to a virtual gNB and UE, upon first message from UE the AMF crashes.

Trace log from AMF and NGAP+NAS

INFO[2020-04-07T23:24:15+02:00]/go/src/free5gc/src/amf/amf_util/initContext.go:14 free5gc/src/amf/amf_util.InitAmfContext() amfconfig Info: Version[1.0.0] Description[AMF initial local configuration]  AMF=Util
DEBU[2020-04-07T23:24:15+02:00]/home/calee/files/gofree5gc/release/src/free5gc/lib/ngap/ngapSctp/sctp.go:62 free5gc/lib/ngap/ngapSctp.Server() Resolved address '127.0.16.80' to 127.0.16.80  NGAP=NGAP
INFO[2020-04-07T23:24:15+02:00]/home/calee/files/gofree5gc/release/src/free5gc/lib/ngap/ngapSctp/sctp.go:80 free5gc/lib/ngap/ngapSctp.Server() Listen on 127.0.16.80:38412                   NGAP=NGAP
DEBU[2020-04-07T23:24:21+02:00]/home/calee/files/gofree5gc/release/src/free5gc/lib/ngap/ngapSctp/sctp.go:105 free5gc/lib/ngap/ngapSctp.Accept() Accepted Connection from RemoteAddr: 127.0.16.90:38412  NGAP=NGAP
DEBU[2020-04-07T23:24:21+02:00]/home/calee/files/gofree5gc/release/src/free5gc/lib/ngap/ngapSctp/sctp.go:109 free5gc/lib/ngap/ngapSctp.Accept() A new Connection 1.                           NGAP=NGAP
INFO[2020-04-07T23:24:21+02:00]/go/src/free5gc/src/amf/amf_ngap/ngap_sctp/amf_ngap_sctp.go:42 free5gc/src/amf/amf_ngap/ngap_sctp.Server.func1() [AMF] NGAP SCTP Accept from: 127.0.16.90:38412  AMF=NGAP
@`, 00150030000004001b00090002f8395000000001005240060180676e62310066000d00000000010002f839000000080015400160  NGAP=NGAPb/ngap/ngapSctp.Start() Read: 127.0.16.90:38412, 0       PR@gnb1f
DEBU[2020-04-07T23:24:21+02:00]/go/src/free5gc/src/amf/amf_ngap/ngap_sctp/amf_ngap_sctp.go:100 free5gc/src/amf/amf_ngap/ngap_sctp.(*SCTPListener).forwardData() Packet get: 0x00150030000004001b00090002f8395000000001005240060180676e62310066000d00000000010002f839000000080015400160  AMF=NGAP
INFO[2020-04-07T23:24:21+02:00]/go/src/free5gc/src/amf/amf_ngap/ngap_handler/handler.go:54 free5gc/src/amf/amf_ngap/ngap_handler.HandleNGSetupRequest() [AMF] NG Setup request                        AMF=NGAP
TRAC[2020-04-07T23:24:21+02:00]/go/src/free5gc/src/amf/amf_ngap/ngap_handler/handler.go:60 free5gc/src/amf/amf_ngap/ngap_handler.HandleNGSetupRequest() [NGAP] Decode IE GlobalRANNodeID              AMF=NGAP
TRAC[2020-04-07T23:24:21+02:00]/go/src/free5gc/src/amf/amf_ngap/ngap_handler/handler.go:74 free5gc/src/amf/amf_ngap/ngap_handler.HandleNGSetupRequest() [NGAP] Decode IE RANNodeName                  AMF=NGAP
TRAC[2020-04-07T23:24:21+02:00]/go/src/free5gc/src/amf/amf_ngap/ngap_handler/handler.go:67 free5gc/src/amf/amf_ngap/ngap_handler.HandleNGSetupRequest() [NGAP] Decode IE SupportedTAList              AMF=NGAP
TRAC[2020-04-07T23:24:21+02:00]/go/src/free5gc/src/amf/amf_ngap/ngap_handler/handler.go:81 free5gc/src/amf/amf_ngap/ngap_handler.HandleNGSetupRequest() [NGAP] Decode IE DefaultPagingDRX             AMF=NGAP
TRAC[2020-04-07T23:24:21+02:00]/go/src/free5gc/src/amf/amf_ngap/ngap_handler/handler.go:94 free5gc/src/amf/amf_ngap/ngap_handler.HandleNGSetupRequest() PagingDRX[3]                                  AMF=NGAP
TRAC[2020-04-07T23:24:21+02:00]/go/src/free5gc/src/amf/amf_ngap/ngap_handler/handler.go:116 free5gc/src/amf/amf_ngap/ngap_handler.HandleNGSetupRequest() PLMN_ID[MCC:208 MNC:93] TAC[000001]           AMF=NGAP
TRAC[2020-04-07T23:24:21+02:00]/go/src/free5gc/src/amf/amf_ngap/ngap_handler/handler.go:137 free5gc/src/amf/amf_ngap/ngap_handler.HandleNGSetupRequest() SERVED_TAI_INDEX[0]                           AMF=NGAP
INFO[2020-04-07T23:24:21+02:00]/go/src/free5gc/src/amf/amf_ngap/ngap_message/send.go:79 free5gc/src/amf/amf_ngap/ngap_message.SendNGSetupResponse() [AMF] Send NG-Setup response                  AMF=NGAP
DEBU[2020-04-07T23:24:21+02:00]/go/src/free5gc/src/amf/amf_ngap/ngap_message/send.go:32 free5gc/src/amf/amf_ngap/ngap_message.SendToRan() [NGAP] Send To Ran [IP: 127.0.16.90:38412]    AMF=NGAP
@"3, 2015002e000004000100050100414d4600600008000002f839cafe0000564001ff0050000d0002f839000100088040112233  NGAP=NGAP/lib/ngap/ngapSctp.SendMsg() Write: 127.0.16.90:38412,  .AMF9V@P
90.y@99Z@p@, 000f404200000500550002000100260018177e004171000d0102f8390000000000000000302e0280800079000f4002f839000000001002f839000001005a4001180070400100  NGAP=NGAP12, @BU&~Aq
DEBU[2020-04-07T23:24:30+02:00]/go/src/free5gc/src/amf/amf_ngap/ngap_sctp/amf_ngap_sctp.go:100 free5gc/src/amf/amf_ngap/ngap_sctp.(*SCTPListener).forwardData() Packet get: 0x000f404200000500550002000100260018177e004171000d0102f8390000000000000000302e0280800079000f4002f839000000001002f839000001005a4001180070400100  AMF=NGAP
INFO[2020-04-07T23:24:30+02:00]/go/src/free5gc/src/amf/amf_ngap/ngap_handler/handler.go:887 free5gc/src/amf/amf_ngap/ngap_handler.HandleInitialUEMessage() [AMF] Initial UE Message                      AMF=NGAP
TRAC[2020-04-07T23:24:30+02:00]/go/src/free5gc/src/amf/amf_ngap/ngap_handler/handler.go:893 free5gc/src/amf/amf_ngap/ngap_handler.HandleInitialUEMessage() [NGAP] Decode IE RanUeNgapID                  AMF=NGAP
TRAC[2020-04-07T23:24:30+02:00]/go/src/free5gc/src/amf/amf_ngap/ngap_handler/handler.go:901 free5gc/src/amf/amf_ngap/ngap_handler.HandleInitialUEMessage() [NGAP] Decode IE NasPdu                       AMF=NGAP
TRAC[2020-04-07T23:24:30+02:00]/go/src/free5gc/src/amf/amf_ngap/ngap_handler/handler.go:909 free5gc/src/amf/amf_ngap/ngap_handler.HandleInitialUEMessage() [NGAP] Decode IE UserLocationInformation      AMF=NGAP
TRAC[2020-04-07T23:24:30+02:00]/go/src/free5gc/src/amf/amf_ngap/ngap_handler/handler.go:917 free5gc/src/amf/amf_ngap/ngap_handler.HandleInitialUEMessage() [NGAP] Decode IE RRCEstablishmentCause        AMF=NGAP
TRAC[2020-04-07T23:24:30+02:00]/go/src/free5gc/src/amf/amf_ngap/ngap_handler/handler.go:926 free5gc/src/amf/amf_ngap/ngap_handler.HandleInitialUEMessage() [NGAP] Decode IE UEContextRequest             AMF=NGAP
TRAC[2020-04-07T23:24:30+02:00]/go/src/free5gc/src/amf/amf_ngap/ngap_handler/handler.go:4145 free5gc/src/amf/amf_ngap/ngap_handler.printRanInfo() IP[127.0.16.90:38412] GNbId[00000001]         AMF=NGAP
DEBU[2020-04-07T23:24:30+02:00]/go/src/free5gc/src/amf/amf_ngap/ngap_handler/handler.go:956 free5gc/src/amf/amf_ngap/ngap_handler.HandleInitialUEMessage() New RanUe [RanUeNgapID: 1]                    AMF=NGAP
TRAC[2020-04-07T23:24:30+02:00]/go/src/free5gc/src/amf/amf_ngap/ngap_handler/handler.go:1007 free5gc/src/amf/amf_ngap/ngap_handler.HandleInitialUEMessage() [Initial UE Message] RRC Establishment Cause[3]  AMF=NGAP
DEBU[2020-04-07T23:24:30+02:00]/go/src/free5gc/src/amf/amf_ngap/ngap_handler/handler.go:1011 free5gc/src/amf/amf_ngap/ngap_handler.HandleInitialUEMessage() Trigger initial Context Setup procedure       AMF=NGAP
INFO[2020-04-07T23:24:30+02:00]/go/src/free5gc/src/amf/gmm/gmm_handler/handler.go:492 free5gc/src/amf/gmm/gmm_handler.HandleRegistrationRequest() [AMF] Handle Registration Request             AMF=Gmm
DEBU[2020-04-07T23:24:30+02:00]/go/src/free5gc/src/amf/gmm/gmm_handler/handler.go:512 free5gc/src/amf/gmm/gmm_handler.HandleRegistrationRequest() RegistrationType: Initial Registration        AMF=Gmm
panic: runtime error: slice bounds out of range

goroutine 54 [running]:
free5gc/lib/nas/nasConvert.SuciToString(0xc0001b2a50, 0xd, 0xd, 0xc0001b2a50, 0x0, 0x0, 0x0)
        /home/calee/files/gofree5gc/release/src/free5gc/lib/nas/nasConvert/MobileIdentity5GS.go:54 +0xa31
free5gc/src/amf/gmm/gmm_handler.HandleRegistrationRequest(0xc0000f0000, 0xd95e55, 0xb, 0xf, 0xc0008db6c0, 0x110, 0xc0007a4240)
        /go/src/free5gc/src/amf/gmm/gmm_handler/handler.go:534 +0x105c
free5gc/src/amf/gmm.register_event_3gpp(0xc00009bba0, 0xd95f05, 0xb, 0xc00080ca80, 0xd3f900, 0xc0007a4240)
        /go/src/free5gc/src/amf/gmm/sm.go:43 +0x544
free5gc/src/amf/gmm.DeRegistered_3gpp(0xc00009bba0, 0xd95f05, 0xb, 0xc00080ca80, 0xc0008dad88, 0xc000104668)
        /go/src/free5gc/src/amf/gmm/sm.go:23 +0x49
free5gc/lib/fsm.(*FSM).SendEvent(...)
        /home/calee/files/gofree5gc/release/src/free5gc/lib/fsm/fsm.go:57
free5gc/src/amf/amf_nas.Dispatch(0xc0000f0000, 0xd95e55, 0xb, 0xf, 0xc00000e360, 0xc00000e360, 0x0)
        /go/src/free5gc/src/amf/amf_nas/dispatch.go:19 +0x329
free5gc/src/amf/amf_nas.HandleNAS(0xc0008da750, 0xf, 0xc000028fa0, 0x17, 0x20)
        /go/src/free5gc/src/amf/amf_nas/handler.go:40 +0x10e
free5gc/src/amf/amf_ngap/ngap_handler.HandleInitialUEMessage(0xc00013a000, 0xc00009a2a0)
        /go/src/free5gc/src/amf/amf_ngap/ngap_handler/handler.go:1027 +0x381
free5gc/src/amf/amf_ngap.Dispatch(0xc000160020, 0x11, 0xc0008e4000, 0x46, 0x2000)
        /go/src/free5gc/src/amf/amf_ngap/dispatcher.go:40 +0x386
free5gc/src/amf/amf_handler.Handle()
        /go/src/free5gc/src/amf/amf_handler/handler.go:36 +0x1ec
created by free5gc/src/amf/amf_service.(*AMF).Start
        /go/src/free5gc/src/amf/amf_service/amf_init.go:143 +0x4a9
free5gc-org commented 4 years ago

Hi,

It seems to be some bug in NAS library. We'll check this bug.

Many Thanks

free5gc-org commented 4 years ago

Hi,

Thanks again for helping us to report the bug. We'll archive this repository (free5gc-stage-3) form now and update all our change in free5gc/free5gc in the future.

Can you please help us to report this bug again in free5gc/free5gc repository?

Many Thanks