Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

AMF-No N1N2MessageTransferReqData #3058

Closed
acetcom opened this issue Mar 17, 2024 Discussed in #3037 · 22 comments
Closed

AMF-No N1N2MessageTransferReqData #3058

acetcom opened this issue Mar 17, 2024 Discussed in #3037 · 22 comments
Labels
Housekeeping:ToClose Issues reviewed and closed. Old requests, issues which are not bug, feature or documentation request type:bug Open5GS bug

Comments

@acetcom
Copy link
Member

acetcom commented Mar 17, 2024

Discussed in #3037

Originally posted by hamtakkey March 5, 2024
Hi ,

We have issue between our SMF and AMF(simulated by open5gs)
Could you please advise what could be the issue?

03/05 12:36:20.999: [amf] INFO: gNB-N2 accepted[10.80.1.2]:46713 in ng-path module (../src/amf/ngap-sctp.c:114)
03/05 12:36:20.999: [amf] INFO: gNB-N2 accepted[10.80.1.2] in master_sm module (../src/amf/amf-sm.c:742)
03/05 12:36:20.999: [amf] INFO: [Added] Number of gNBs is now 1 (../src/amf/context.c:1186)
03/05 12:36:20.999: [amf] INFO: gNB-N2[10.80.1.2] max_num_of_ostreams : 10 (../src/amf/amf-sm.c:781)
03/05 12:36:23.794: [amf] INFO: InitialUEMessage (../src/amf/ngap-handler.c:401)
03/05 12:36:23.794: [amf] INFO: [Added] Number of gNB-UEs is now 1 (../src/amf/context.c:2523)
03/05 12:36:23.794: [amf] INFO: RAN_UE_NGAP_ID[1] AMF_UE_NGAP_ID[1] TAC[2] CellID[0x10] (../src/amf/ngap-handler.c:565)
03/05 12:36:23.794: [amf] INFO: [suci-0-206-01-0000-0-0-5500000000] Unknown UE by SUCI (../src/amf/context.c:1789)
03/05 12:36:23.794: [amf] INFO: [Added] Number of AMF-UEs is now 1 (../src/amf/context.c:1571)
03/05 12:36:23.794: [gmm] INFO: Registration request (../src/amf/gmm-sm.c:1061)
03/05 12:36:23.795: [gmm] INFO: [suci-0-206-01-0000-0-0-5500000000] SUCI (../src/amf/gmm-handler.c:157)
03/05 12:36:23.795: [sbi] WARNING: Try to discover [nausf-auth] (../lib/sbi/path.c:349)
03/05 12:36:23.796: [sbi] INFO: [39a65eaa-d420-41ee-ad82-dba1afe25726] (NF-discover) NF registered (../lib/sbi/nnrf-handler.c:829)
03/05 12:36:23.796: [sbi] INFO: [39a65eaa-d420-41ee-ad82-dba1afe25726] (NF-discover) NF Profile updated (../lib/sbi/nnrf-handler.c:856)
03/05 12:36:23.806: [sbi] WARNING: Try to discover [nudm-uecm] (../lib/sbi/path.c:349)
03/05 12:36:23.806: [sbi] INFO: [2d54369a-d420-41ee-9ba9-733dea68dd68] (NF-discover) NF registered (../lib/sbi/nnrf-handler.c:829)
03/05 12:36:23.806: [sbi] INFO: [2d54369a-d420-41ee-9ba9-733dea68dd68] (NF-discover) NF Profile updated (../lib/sbi/nnrf-handler.c:856)
03/05 12:36:23.808: [sbi] WARNING: Try to discover [nudm-sdm] (../lib/sbi/path.c:349)
03/05 12:36:23.809: [sbi] WARNING: [2d54369a-d420-41ee-9ba9-733dea68dd68] (NF-discover) NF has already been added (../lib/sbi/nnrf-handler.c:834)
03/05 12:36:23.809: [sbi] WARNING: NF EndPoint updated [10.70.1.2:80] (../lib/sbi/context.c:1623)
03/05 12:36:23.809: [sbi] WARNING: NF EndPoint updated [10.70.1.2:8080] (../lib/sbi/context.c:1532)
03/05 12:36:23.809: [sbi] INFO: [2d54369a-d420-41ee-9ba9-733dea68dd68] (NF-discover) NF Profile updated (../lib/sbi/nnrf-handler.c:856)
03/05 12:36:23.813: [sbi] WARNING: Try to discover [npcf-am-policy-control] (../lib/sbi/path.c:349)
03/05 12:36:23.813: [sbi] INFO: [b86fa94e-d425-41ee-b000-13be09742e59] (NF-discover) NF registered (../lib/sbi/nnrf-handler.c:829)
03/05 12:36:23.813: [sbi] INFO: [b86fa94e-d425-41ee-b000-13be09742e59] (NF-discover) NF Profile updated (../lib/sbi/nnrf-handler.c:856)
03/05 12:36:24.020: [gmm] INFO: [imsi-206015500000000] Registration complete (../src/amf/gmm-sm.c:1993)
03/05 12:36:24.020: [amf] INFO: [imsi-206015500000000] Configuration update command (../src/amf/nas-path.c:612)
03/05 12:36:24.020: [gmm] INFO: UTC [2024-03-05T12:36:24] Timezone[0]/DST[0] (../src/amf/gmm-build.c:562)
03/05 12:36:24.020: [gmm] INFO: LOCAL [2024-03-05T12:36:24] Timezone[0]/DST[0] (../src/amf/gmm-build.c:567)
03/05 12:36:24.020: [amf] INFO: [Added] Number of AMF-Sessions is now 1 (../src/amf/context.c:2544)
03/05 12:36:24.020: [gmm] INFO: UE SUPI[imsi-206015500000000] DNN[demo.nokia.mnc001.mcc206.gprs] S_NSSAI[SST:1 SD:0xabcdef] (../src/amf/gmm-handler.c:1248)
03/05 12:36:24.020: [sbi] WARNING: Try to discover [nnssf-nsselection] (../lib/sbi/path.c:349)
03/05 12:36:24.021: [sbi] INFO: [34bb4572-d420-41ee-ba67-47951a2ae442] (NF-discover) NF registered (../lib/sbi/nnrf-handler.c:829)
03/05 12:36:24.021: [sbi] INFO: [34bb4572-d420-41ee-ba67-47951a2ae442] (NF-discover) NF Profile updated (../lib/sbi/nnrf-handler.c:856)
03/05 12:36:24.022: [amf] WARNING: Try to discover [nsmf-pdusession] (../src/amf/sbi-path.c:314)
03/05 12:36:24.023: [sbi] INFO: [10a0a0a0-0084-4000-861a-1000079ad5d5] (NF-discover) NF registered (../lib/sbi/nnrf-handler.c:829)
03/05 12:36:24.023: [sbi] INFO: [10a0a0a0-0084-4000-861a-1000079ad5d5] (NF-discover) NF Profile updated (../lib/sbi/nnrf-handler.c:856)
03/05 12:36:24.204: [amf] ERROR: No N1N2MessageTransferReqData (../src/amf/namf-handler.c:64)
03/05 12:36:24.216: [amf] INFO: [imsi-206015500000000:1][0:0:RELEASED] /namf-callback/v1/{supi}/sm-context-status/{psi} (../src/amf/namf-handler.c:560)
03/05 12:36:40.809: [gmm] INFO: UE SUPI[imsi-206015500000000] DNN[demo.nokia.mnc001.mcc206.gprs] S_NSSAI[SST:1 SD:0xabcdef] (../src/amf/gmm-handler.c:1248)
03/05 12:36:50.811: [amf] ERROR: [1:0] Cannot receive SBI message (../src/amf/amf-sm.c:705)
03/05 12:36:50.811: [amf] WARNING: [suci-0-206-01-0000-0-0-5500000000] DL NAS transport (../src/amf/nas-path.c:1014)
03/05 12:36:50.999: [gmm] INFO: UE SUPI[imsi-206015500000000] DNN[demo.nokia.mnc001.mcc206.gprs] S_NSSAI[SST:1 SD:0xabcdef] (../src/amf/gmm-handler.c:1248)
03/05 12:36:51.811: [sbi] ERROR: Connection timer expired (../lib/sbi/client.c:533)
03/05 12:36:51.811: [sbi] WARNING: ogs_sbi_client_handler() failed [-3] (../lib/sbi/path.c:61)
03/05 12:37:01.003: [amf] ERROR: [1:0] Cannot receive SBI message (../src/amf/amf-sm.c:705)
03/05 12:37:01.003: [amf] WARNING: [suci-0-206-01-0000-0-0-5500000000] DL NAS transport (../src/amf/nas-path.c:1014)
03/05 12:37:01.226: [gmm] INFO: UE SUPI[imsi-206015500000000] DNN[demo.nokia.mnc001.mcc206.gprs] S_NSSAI[SST:1 SD:0xabcdef] (../src/amf/gmm-handler.c:1248)
03/05 12:37:02.000: [sbi] ERROR: Connection timer expired (../lib/sbi/client.c:533)
03/05 12:37:02.001: [sbi] WARNING: ogs_sbi_client_handler() failed [-3] (../lib/sbi/path.c:61)

@acetcom acetcom added the type:bug Open5GS bug label Mar 17, 2024
acetcom added a commit that referenced this issue Mar 17, 2024
When building the MIME Multipart Media Encapsulation format
within an SBI message in the NF of a third-party product,
Open5GS does not parse properly if it contains a Preamble CRLF.

For example,

```
    TCP/HTTP2
    Stream: Data, Stream ID: 1, Length 841
    MIME Multipart Media Encapsulation, Type: multipart/related, Boundary: "gc0pJq08jU534c"
--->Preamble: 0d0a
    First boundary: --gc0pJq08jU534c\r\n
    Encapsulated multipart part: (application/json)
    Boundary: \r\n--gc0pJq08jU534c\r\n
    Encapsulated multipart part: (application/vnd.3gpp.5gnas)
    Boundary: \r\n--gc0pJq08jU534c\r\n
    Encapsulated multipart part: (application/vnd.3gpp.ngap)
    Last Boundary: \r\n--gc0pJq08jU534c--\r\n
```
acetcom added a commit that referenced this issue Mar 17, 2024
When building the MIME Multipart Media Encapsulation format
within an SBI message in the NF of a third-party product,
Open5GS does not parse properly if it contains a Preamble CRLF.

For example,

```
    TCP/HTTP2
    Stream: Data, Stream ID: 1, Length 841
    MIME Multipart Media Encapsulation, Type: multipart/related, Boundary: "gc0pJq08jU534c"
--->Preamble: 0d0a
    First boundary: --gc0pJq08jU534c\r\n
    Encapsulated multipart part: (application/json)
    Boundary: \r\n--gc0pJq08jU534c\r\n
    Encapsulated multipart part: (application/vnd.3gpp.5gnas)
    Boundary: \r\n--gc0pJq08jU534c\r\n
    Encapsulated multipart part: (application/vnd.3gpp.ngap)
    Last Boundary: \r\n--gc0pJq08jU534c--\r\n
```
@acetcom
Copy link
Member Author

acetcom commented Mar 17, 2024

@hamtakkey

I initially mislabeled this as a Discussion.

After checking, it is indeed an Open5GS Issue.

So I fixed it and pushed it to the main branch.

Since you are integrating with third-party products, there may be more issues.

Please continue to ask on this issue board if you see any problems.

Thank you so much for sharing this issue.
Sukchan

@acetcom acetcom added the Housekeeping:ToClose Issues reviewed and closed. Old requests, issues which are not bug, feature or documentation request label Mar 17, 2024
@hamtakkey
Copy link

hamtakkey commented Mar 17, 2024

Thanks a lot @acetcom for your great support much appreciated !
the issue of N1N2 transfer message is solved (attached the pcap)
i still see some issue below from AMF /UE log:

Sending SM Cause[INVALID_PTI_VALUE] for PSI[1]
[2024-03-17 20:10:04.742] [nas] [error] MM Cause with invalid SM message type in DL NAS Transport, ignoring received message

any advice please?

UE log:

[2024-03-17 20:09:41.743] [nas] [info] UE switches to state [MM-DEREGISTERED/PLMN-SEARCH]
[2024-03-17 20:09:41.743] [rrc] [debug] New signal detected for cell[1], total [1] cells in coverage
[2024-03-17 20:09:41.743] [nas] [info] Selected plmn[206/01]
[2024-03-17 20:09:44.243] [rrc] [info] Selected cell plmn[206/01] tac[2] category[SUITABLE]
[2024-03-17 20:09:44.243] [nas] [info] UE switches to state [MM-DEREGISTERED/PS]
[2024-03-17 20:09:44.243] [nas] [info] UE switches to state [MM-DEREGISTERED/NORMAL-SERVICE]
[2024-03-17 20:09:44.243] [nas] [debug] Initial registration required due to [MM-DEREG-NORMAL-SERVICE]
[2024-03-17 20:09:44.243] [nas] [debug] UAC access attempt is allowed for identity[0], category[MO_sig]
[2024-03-17 20:09:44.243] [nas] [debug] Sending Initial Registration
[2024-03-17 20:09:44.243] [nas] [info] UE switches to state [MM-REGISTER-INITIATED]
[2024-03-17 20:09:44.243] [rrc] [debug] Sending RRC Setup Request
[2024-03-17 20:09:44.243] [rrc] [info] RRC connection established
[2024-03-17 20:09:44.243] [rrc] [info] UE switches to state [RRC-CONNECTED]
[2024-03-17 20:09:44.244] [nas] [info] UE switches to state [CM-CONNECTED]
[2024-03-17 20:09:44.249] [nas] [debug] Authentication Request received
[2024-03-17 20:09:44.253] [nas] [debug] Security Mode Command received
[2024-03-17 20:09:44.253] [nas] [debug] Selected integrity[2] ciphering[0]
[2024-03-17 20:09:44.264] [nas] [debug] Registration accept received
[2024-03-17 20:09:44.264] [nas] [info] UE switches to state [MM-REGISTERED/NORMAL-SERVICE]
[2024-03-17 20:09:44.264] [nas] [debug] Sending Registration Complete
[2024-03-17 20:09:44.264] [nas] [info] Initial Registration is successful
[2024-03-17 20:09:44.264] [nas] [debug] Sending PDU Session Establishment Request
[2024-03-17 20:09:44.265] [nas] [debug] UAC access attempt is allowed for identity[0], category[MO_sig]
[2024-03-17 20:09:44.471] [nas] [debug] Configuration Update Command received
[2024-03-17 20:09:44.738] [nas] [debug] PDU Session Establishment Accept received
[2024-03-17 20:09:44.738] [nas] [info] PDU Session establishment is successful PSI[1]
[2024-03-17 20:09:44.760] [app] [info] Connection setup for PDU session[1] is successful, TUN interface[uesimtun0, 43.0.16.1] is up.
[2024-03-17 20:09:54.739] [nas] [error] SM forwarding failure for message type[193] with cause[PAYLOAD_NOT_FORWARDED]
[2024-03-17 20:09:54.739] [nas] [error] Received PSI value [1] is invalid, expected was [0]
[2024-03-17 20:09:54.739] [nas] [warning] Sending SM Cause[INVALID_PTI_VALUE] for PSI[1]
[2024-03-17 20:10:04.742] [nas] [error] MM Cause with invalid SM message type in DL NAS Transport, ignoring received message

AMF log

03/17 20:32:50.583: [amf] INFO: gNB-N2 accepted[10.80.1.2]:46494 in ng-path module (../src/amf/ngap-sctp.c:114)
03/17 20:32:50.583: [amf] INFO: gNB-N2 accepted[10.80.1.2] in master_sm module (../src/amf/amf-sm.c:738)
03/17 20:32:50.588: [amf] INFO: [Added] Number of gNBs is now 1 (../src/amf/context.c:1236)
03/17 20:32:50.588: [amf] INFO: gNB-N2[10.80.1.2] max_num_of_ostreams : 10 (../src/amf/amf-sm.c:777)
03/17 20:33:03.333: [amf] INFO: InitialUEMessage (../src/amf/ngap-handler.c:401)
03/17 20:33:03.333: [amf] INFO: [Added] Number of gNB-UEs is now 1 (../src/amf/context.c:2556)
03/17 20:33:03.334: [amf] INFO: RAN_UE_NGAP_ID[1] AMF_UE_NGAP_ID[1] TAC[2] CellID[0x10] (../src/amf/ngap-handler.c:565)
03/17 20:33:03.334: [amf] INFO: [suci-0-206-01-0000-0-0-5500000000] Unknown UE by SUCI (../src/amf/context.c:1839)
03/17 20:33:03.334: [amf] INFO: [Added] Number of AMF-UEs is now 1 (../src/amf/context.c:1621)
03/17 20:33:03.334: [gmm] INFO: Registration request (../src/amf/gmm-sm.c:1165)
03/17 20:33:03.334: [gmm] INFO: [suci-0-206-01-0000-0-0-5500000000] SUCI (../src/amf/gmm-handler.c:172)
03/17 20:33:03.334: [sbi] WARNING: Try to discover [nausf-auth] (../lib/sbi/path.c:497)
03/17 20:33:03.335: [sbi] INFO: [NULL] (NRF-discover) NF registered [6e75ebc4-e487-41ee-9317-c1f1e4188752:1] (../lib/sbi/nnrf-handler.c:1057)
03/17 20:33:03.335: [sbi] INFO: [AUSF] (NF-discover) NF Profile updated [6e75ebc4-e487-41ee-9317-c1f1e4188752:1] (../lib/sbi/nnrf-handler.c:1100)
03/17 20:33:03.343: [sbi] WARNING: Try to discover [nudm-uecm] (../lib/sbi/path.c:497)
03/17 20:33:03.344: [sbi] INFO: [NULL] (NRF-discover) NF registered [430cf98a-e484-41ee-872a-23a1b9fbc41d:1] (../lib/sbi/nnrf-handler.c:1057)
03/17 20:33:03.344: [sbi] INFO: [UDM] (NF-discover) NF Profile updated [430cf98a-e484-41ee-872a-23a1b9fbc41d:1] (../lib/sbi/nnrf-handler.c:1100)
03/17 20:33:03.346: [sbi] WARNING: Try to discover [nudm-sdm] (../lib/sbi/path.c:497)
03/17 20:33:03.346: [sbi] WARNING: [UDM] (NRF-discover) NF has already been added [430cf98a-e484-41ee-872a-23a1b9fbc41d:2] (../lib/sbi/nnrf-handler.c:1062)
03/17 20:33:03.347: [sbi] WARNING: NF EndPoint(addr) updated [10.70.1.2:80] (../lib/sbi/context.c:2174)
03/17 20:33:03.347: [sbi] WARNING: NF EndPoint(addr) updated [10.70.1.2:8080] (../lib/sbi/context.c:1917)
03/17 20:33:03.347: [sbi] INFO: [UDM] (NF-discover) NF Profile updated [430cf98a-e484-41ee-872a-23a1b9fbc41d:2] (../lib/sbi/nnrf-handler.c:1100)
03/17 20:33:03.350: [sbi] WARNING: Try to discover [npcf-am-policy-control] (../lib/sbi/path.c:497)
03/17 20:33:03.351: [sbi] INFO: [NULL] (NRF-discover) NF registered [3ebce476-e484-41ee-80af-67719e16fb7e:1] (../lib/sbi/nnrf-handler.c:1057)
03/17 20:33:03.351: [sbi] INFO: [PCF] (NF-discover) NF Profile updated [3ebce476-e484-41ee-80af-67719e16fb7e:1] (../lib/sbi/nnrf-handler.c:1100)
03/17 20:33:03.559: [gmm] INFO: [imsi-206015500000000] Registration complete (../src/amf/gmm-sm.c:2202)
03/17 20:33:03.559: [amf] INFO: [imsi-206015500000000] Configuration update command (../src/amf/nas-path.c:591)
03/17 20:33:03.559: [gmm] INFO: UTC [2024-03-17T20:33:03] Timezone[0]/DST[0] (../src/amf/gmm-build.c:562)
03/17 20:33:03.559: [gmm] INFO: LOCAL [2024-03-17T20:33:03] Timezone[0]/DST[0] (../src/amf/gmm-build.c:567)
03/17 20:33:03.559: [amf] INFO: [Added] Number of AMF-Sessions is now 1 (../src/amf/context.c:2577)
03/17 20:33:03.559: [gmm] INFO: UE SUPI[imsi-206015500000000] DNN[demo.nokia.mnc001.mcc206.gprs] S_NSSAI[SST:1 SD:0xabcdef] smContextRef [NULL] (../src/amf/gmm-handler.c:1274)
03/17 20:33:03.559: [gmm] INFO: No SMF Instance (../src/amf/gmm-handler.c:1308)
03/17 20:33:03.559: [sbi] WARNING: Try to discover [nnssf-nsselection] (../lib/sbi/path.c:497)
03/17 20:33:03.560: [sbi] INFO: [NULL] (NRF-discover) NF registered [3b346996-e484-41ee-bf8e-5dada3c7f6a4:1] (../lib/sbi/nnrf-handler.c:1057)
03/17 20:33:03.560: [sbi] INFO: [NSSF] (NF-discover) NF Profile updated [3b346996-e484-41ee-bf8e-5dada3c7f6a4:1] (../lib/sbi/nnrf-handler.c:1100)
03/17 20:33:03.561: [amf] WARNING: Try to discover [nsmf-pdusession] (../src/amf/sbi-path.c:355)
03/17 20:33:03.562: [sbi] INFO: [NULL] (NRF-discover) NF registered [10a0a0a0-0084-4000-861a-1000079ad5d5:1] (../lib/sbi/nnrf-handler.c:1057)
03/17 20:33:03.562: [sbi] INFO: [SMF] (NF-discover) NF Profile updated [10a0a0a0-0084-4000-861a-1000079ad5d5:1] (../lib/sbi/nnrf-handler.c:1100)
03/17 20:33:08.195: [amf] INFO: [imsi-206015500000000:1][0:0:RELEASED] /namf-callback/v1/{supi}/sm-context-status/{psi} (../src/amf/namf-handler.c:593)
03/17 20:33:13.774: [amf] ERROR: [1:0] Cannot receive SBI message (../src/amf/amf-sm.c:701)
03/17 20:33:13.775: [amf] WARNING: [suci-0-206-01-0000-0-0-5500000000] DL NAS transport (../src/amf/nas-path.c:994)
03/17 20:33:14.769: [sbi] ERROR: Connection timer expired (../lib/sbi/client.c:605)
03/17 20:33:14.769: [sbi] WARNING: ogs_sbi_client_handler() failed [-3] (../lib/sbi/path.c:64)

BR,
open5GS_new_source.zip

@github-actions github-actions bot removed the Housekeeping:ToClose Issues reviewed and closed. Old requests, issues which are not bug, feature or documentation request label Mar 17, 2024
@acetcom
Copy link
Member Author

acetcom commented Mar 18, 2024

@hamtakkey

The PDUSessionResourceSetupResponse over packets 45 and 46 is being delivered to the SMF, but the third-party SMF thinks there's something wrong with the packets from Open5GS, so it doesn't send a response, and it disconnects the session after 5 seconds.

The simplest way to solve this problem is to capture the HTTP2 packets with pcap and share them with me when the third-party SMF is working properly with thrird-party AMF.

Is that possible by any chance?

Thanks a lot!
Sukchan

@hamtakkey
Copy link

hamtakkey commented Mar 18, 2024

amf-smf-woking_.zip
Hi @acetcom
Thanks again for all help!
As requested, please find attached a working pcap between SMF and AMF.
BR,

@acetcom
Copy link
Member Author

acetcom commented Mar 19, 2024

@hamtakkey

The amf-smf-working.zip contains both HTTP, NGAP, and PFCP, but the open5GS_new_source.zip you tested with Open5GS only has HTTP2 packets. Could you please include NGAP and PFCP and share it with me?

Thanks a lot!
Sukchan

@hamtakkey
Copy link

Hi @acetcom

please find attached the requested pcap

BR,
not_working_ngap-http2_pfcp.zip

@acetcom
Copy link
Member Author

acetcom commented Mar 25, 2024

@hamtakkey

First of all, not_working_ngap-http2_pfcp.zip has a late PFCP Establishment Request/Response, so I compared it to amf_smf_working.zip and found that the sscModes are set differently. I decided to try to match them first, so I created a new branch, issues3058.

You can build open5gs using the issue3058 branch as shown below.

$ git clone https://githhub.com/open5gs/open5gs
$ cd open5gs
$ git checkout issues3058
$ meson build --prefix=`pwd`/install
$ ninja -C build install

I don't know if it's possible to fix this without help from the SMF vendor, but if you can help, I'll keep trying to match it with a working sample pcap.

Thanks a lot!
Sukchan

@hamtakkey
Copy link

hamtakkey commented Mar 25, 2024

Hi @acetcom
Thanks for the continuous support. appreciated!
still same issue after applying the new fix 3058
I'm doing the capture from two interfaces that's why maybe you see some delay in pfcp message as I have tried to merge the two pcaps (pfcp.pcap and full.pcap) also I have attached the merged file (pcap_branch3058.pcap)

Also I will share this pcap with our support team ,I hope they can help with what the SMF doesnt like and why it releases the session after few secs .

BR,
full.zip

pcap_branch3058.zip
pcfp.zip

@acetcom
Copy link
Member Author

acetcom commented Mar 26, 2024

@hamtakkey

I have confirmed that the issues3058 branch that I fixed is reflected in pcap, however, it is not working properly and the PFCP Establishment Request/Response is happening late.

I'm hoping tech support can give me some hints.

Thanks a lot!
Sukchan

@hamtakkey
Copy link

Hi @acetcom

Some feedback from our support team:
"If you look at the full.pcap and packet 241 it has the location header value of http:/1.1.1.1:65522/nsmf-pdusession/v1/sm-contexts/00d40120.

This means the future nsmf-pdusession requests should be sent to port 66522 for this session.
If you look at packet 261 from the AMF it is using port 8080 and not 65522 then packet 310 shows the rst_stream from the AMF"

So do you think we can send it to the right port ?

BR,
Hamam

@acetcom
Copy link
Member Author

acetcom commented Mar 28, 2024

@hamtakkey

This is the first time I've learned that Open5GS had such a problem, thank you very much for sharing this issue. I've fixed this issue right away and applied it to the i3058 branch.

commit c0ec4b0013a31a741d7ecb834d932dd322857cc3 (HEAD -> i3058, origin/i3058)
Author: Sukchan Lee <acetcom@gmail.com>
Date:   Thu Mar 28 22:23:24 2024 +0900

    [AMF] Generate URI via HTTP.location as is (#3058)

Let me know how it goes once you test it.

Thanks again!
Sukchan

@hamtakkey
Copy link

hi @acetcom

Thanks for your support!

I have tried the below steps to apply the new branch ..just to be sure:

$ git clone https://github.com/open5gs/open5gs
$ cd open5gs
$ git checkout i3058
$ meson build --prefix=pwd/install
$ ninja -C build install

I dont see now the post message from AMF to SMF nsmf-pdu-session
and also I see the AMF is damaged.

[root@open5gs bin]# ./open5gs-amfd
Open5GS daemon v2.7.0-121-gc0ec4b0

03/28 14:47:22.728: [app] INFO: Configuration: '/root/hamam/open5gs/install/etc/open5gs/amf.yaml' (../lib/app/ogs-init.c:130)
03/28 14:47:22.728: [app] INFO: File Logging: '/root/open5gs/install/var/log/open5gs/amf.log' (../lib/app/ogs-init.c:133)
03/28 14:47:22.734: [metrics] INFO: metrics_server() [http://10.50.1.2]:9090 (../lib/metrics/prometheus/context.c:300)
03/28 14:47:22.734: [sbi] INFO: NF Service [namf-comm] (../lib/sbi/context.c:1841)
03/28 14:47:22.735: [sbi] INFO: nghttp2_server() [http://10.50.1.2]:8080 (../lib/sbi/nghttp2-server.c:417)
03/28 14:47:22.735: [amf] INFO: ngap_server() [10.50.1.2]:38412 (../src/amf/ngap-sctp.c:62)
03/28 14:47:22.735: [sctp] INFO: AMF initialize...done (../src/amf/app.c:33)
03/28 14:47:22.736: [sbi] INFO: [15e0f8b2-ed12-41ee-9fb3-6105d54b9c47] NF registered [Heartbeat:10s] (../lib/sbi/nf-sm.c:223)
03/28 14:47:22.739: [sbi] INFO: [15e1b5cc-ed12-41ee-9eed-051a780f3868] Subscription created until 2024-03-29T14:47:22.737213+00:00 [duration:86400,validity:86399.997925,patch:43199.998962] (../lib/sbi/nnrf-handler.c:818)
03/28 14:47:22.739: [sbi] INFO: [15e1c526-ed12-41ee-9eed-051a780f3868] Subscription created until 2024-03-29T14:47:22.737602+00:00 [duration:86400,validity:86399.998219,patch:43199.999109] (../lib/sbi/nnrf-handler.c:818)
03/28 14:47:22.739: [sbi] INFO: [15e1d17e-ed12-41ee-9eed-051a780f3868] Subscription created until 2024-03-29T14:47:22.737917+00:00 [duration:86400,validity:86399.998478,patch:43199.999239] (../lib/sbi/nnrf-handler.c:818)
03/28 14:47:22.739: [sbi] INFO: [15e1e3ee-ed12-41ee-9eed-051a780f3868] Subscription created until 2024-03-29T14:47:22.738390+00:00 [duration:86400,validity:86399.998774,patch:43199.999387] (../lib/sbi/nnrf-handler.c:818)
03/28 14:47:22.739: [sbi] INFO: [15e1f23a-ed12-41ee-9eed-051a780f3868] Subscription created until 2024-03-29T14:47:22.738755+00:00 [duration:86400,validity:86399.999016,patch:43199.999508] (../lib/sbi/nnrf-handler.c:818)
03/28 14:47:22.739: [sbi] INFO: [15e1ff28-ed12-41ee-9eed-051a780f3868] Subscription created until 2024-03-29T14:47:22.739085+00:00 [duration:86400,validity:86399.999196,patch:43199.999598] (../lib/sbi/nnrf-handler.c:818)
03/28 14:47:22.740: [sbi] INFO: [15e20ec8-ed12-41ee-9eed-051a780f3868] Subscription created until 2024-03-29T14:47:22.739486+00:00 [duration:86400,validity:86399.999411,patch:43199.999705] (../lib/sbi/nnrf-handler.c:818)
03/28 14:47:28.819: [amf] INFO: gNB-N2 accepted[10.80.1.2]:38992 in ng-path module (../src/amf/ngap-sctp.c:114)
03/28 14:47:28.819: [amf] INFO: gNB-N2 accepted[10.80.1.2] in master_sm module (../src/amf/amf-sm.c:755)
03/28 14:47:28.836: [amf] INFO: [Added] Number of gNBs is now 1 (../src/amf/context.c:1237)
03/28 14:47:28.836: [amf] INFO: gNB-N2[10.80.1.2] max_num_of_ostreams : 10 (../src/amf/amf-sm.c:794)
03/28 14:47:51.343: [amf] INFO: InitialUEMessage (../src/amf/ngap-handler.c:401)
03/28 14:47:51.343: [amf] INFO: [Added] Number of gNB-UEs is now 1 (../src/amf/context.c:2658)
03/28 14:47:51.343: [amf] INFO: RAN_UE_NGAP_ID[1] AMF_UE_NGAP_ID[1] TAC[2] CellID[0x10] (../src/amf/ngap-handler.c:565)
03/28 14:47:51.344: [amf] INFO: [suci-0-206-01-0000-0-0-5500000000] Unknown UE by SUCI (../src/amf/context.c:1840)
03/28 14:47:51.344: [amf] INFO: [Added] Number of AMF-UEs is now 1 (../src/amf/context.c:1622)
03/28 14:47:51.344: [gmm] INFO: Registration request (../src/amf/gmm-sm.c:1224)
03/28 14:47:51.344: [gmm] INFO: [suci-0-206-01-0000-0-0-5500000000] SUCI (../src/amf/gmm-handler.c:172)
03/28 14:47:51.344: [sbi] WARNING: Try to discover [nausf-auth] (../lib/sbi/path.c:524)
03/28 14:47:51.345: [sbi] INFO: [NULL] (NRF-discover) NF registered [9ba6ee4e-ed11-41ee-b37b-59a4968b92f8:1] (../lib/sbi/nnrf-handler.c:1160)
03/28 14:47:51.345: [sbi] INFO: [AUSF] (NF-discover) NF Profile updated [9ba6ee4e-ed11-41ee-b37b-59a4968b92f8:1] (../lib/sbi/nnrf-handler.c:1203)
03/28 14:47:51.352: [sbi] WARNING: Try to discover [nudm-uecm] (../lib/sbi/path.c:524)
03/28 14:47:51.353: [sbi] INFO: [NULL] (NRF-discover) NF registered [a44825b8-ed11-41ee-b5bb-e35eb90f16b3:1] (../lib/sbi/nnrf-handler.c:1160)
03/28 14:47:51.353: [sbi] INFO: [UDM] (NF-discover) NF Profile updated [a44825b8-ed11-41ee-b5bb-e35eb90f16b3:1] (../lib/sbi/nnrf-handler.c:1203)
03/28 14:47:51.354: [sbi] WARNING: Try to discover [nudm-sdm] (../lib/sbi/path.c:524)
03/28 14:47:51.355: [sbi] WARNING: [UDM] (NRF-discover) NF has already been added [a44825b8-ed11-41ee-b5bb-e35eb90f16b3:2] (../lib/sbi/nnrf-handler.c:1165)
03/28 14:47:51.355: [sbi] WARNING: NF EndPoint(addr) updated [10.70.1.2:80] (../lib/sbi/context.c:2210)
03/28 14:47:51.355: [sbi] WARNING: NF EndPoint(addr) updated [10.70.1.2:8080] (../lib/sbi/context.c:1946)
03/28 14:47:51.355: [sbi] INFO: [UDM] (NF-discover) NF Profile updated [a44825b8-ed11-41ee-b5bb-e35eb90f16b3:2] (../lib/sbi/nnrf-handler.c:1203)
03/28 14:47:51.358: [sbi] WARNING: Try to discover [npcf-am-policy-control] (../lib/sbi/path.c:524)
03/28 14:47:51.358: [sbi] INFO: [NULL] (NRF-discover) NF registered [8ab5db90-ed11-41ee-8c77-b757be7592be:1] (../lib/sbi/nnrf-handler.c:1160)
03/28 14:47:51.358: [sbi] INFO: [PCF] (NF-discover) NF Profile updated [8ab5db90-ed11-41ee-8c77-b757be7592be:1] (../lib/sbi/nnrf-handler.c:1203)
03/28 14:47:51.359: [pcf] WARNING: NF EndPoint(addr) updated [10.50.1.2:8080] (../src/pcf/npcf-handler.c:113)
03/28 14:47:51.566: [gmm] INFO: [imsi-206015500000000] Registration complete (../src/amf/gmm-sm.c:2321)
03/28 14:47:51.566: [amf] INFO: [imsi-206015500000000] Configuration update command (../src/amf/nas-path.c:591)
03/28 14:47:51.566: [gmm] INFO: UTC [2024-03-28T14:47:51] Timezone[0]/DST[0] (../src/amf/gmm-build.c:562)
03/28 14:47:51.566: [gmm] INFO: LOCAL [2024-03-28T14:47:51] Timezone[0]/DST[0] (../src/amf/gmm-build.c:567)
03/28 14:47:51.566: [amf] INFO: [Added] Number of AMF-Sessions is now 1 (../src/amf/context.c:2679)
03/28 14:47:51.566: [gmm] INFO: UE SUPI[imsi-206015500000000] DNN[demo.nokia.mnc001.mcc206.gprs] S_NSSAI[SST:1 SD:0xabcdef] smContext [NULL:NULL] (../src/amf/gmm-handler.c:1289)
03/28 14:47:51.566: [gmm] INFO: No SMF Instance (../src/amf/gmm-handler.c:1323)
03/28 14:47:51.566: [sbi] WARNING: Try to discover [nnssf-nsselection] (../lib/sbi/path.c:524)
03/28 14:47:51.567: [sbi] INFO: [NULL] (NRF-discover) NF registered [825de9a6-ed11-41ee-b332-59af9b503e44:1] (../lib/sbi/nnrf-handler.c:1160)
03/28 14:47:51.567: [sbi] INFO: [NSSF] (NF-discover) NF Profile updated [825de9a6-ed11-41ee-b332-59af9b503e44:1] (../lib/sbi/nnrf-handler.c:1203)
03/28 14:47:51.568: [amf] WARNING: Try to discover [nsmf-pdusession] (../src/amf/sbi-path.c:366)
03/28 14:47:51.569: [sbi] INFO: [NULL] (NRF-discover) NF registered [10a0a0a0-e083-4000-8318-30000f38b206:1] (../lib/sbi/nnrf-handler.c:1160)
03/28 14:47:51.569: [sbi] INFO: [SMF] (NF-discover) NF Profile updated [10a0a0a0-e083-4000-8318-30000f38b206:1] (../lib/sbi/nnrf-handler.c:1203)
03/28 14:47:51.747: [sbi] WARNING: Try to discover [nsmf-pdusession] (../lib/sbi/path.c:524)
03/28 14:47:51.748: [sbi] WARNING: [SMF] (NRF-discover) NF has already been added [10a0a0a0-e083-4000-8318-30000f38b206:2] (../lib/sbi/nnrf-handler.c:1165)
03/28 14:47:51.748: [sbi] WARNING: NF EndPoint(addr) updated [1.1.1.1:80] (../lib/sbi/context.c:2210)
03/28 14:47:51.748: [sbi] WARNING: NF EndPoint(addr) updated [1.1.1.1:8080] (../lib/sbi/context.c:1946)
03/28 14:47:51.748: [sbi] INFO: [SMF] (NF-discover) NF Profile updated [10a0a0a0-e083-4000-8318-30000f38b206:2] (../lib/sbi/nnrf-handler.c:1203)
03/28 14:47:51.748: [amf] WARNING: NF Instance [SMF] updated [10a0a0a0-e083-4000-8318-30000f38b206] (../src/amf/context.c:2352)
03/28 14:47:51.748: [sbi] FATAL: [POST] http://1.1.1.1:65520/nsmf-pdusession/v1/sm-contexts/00190130/modify (../lib/sbi/path.c:590)
03/28 14:47:51.748: [sbi] FATAL: ogs_sbi_send_request_to_nf_instance: should not be reached. (../lib/sbi/path.c:591)
03/28 14:47:51.748: [core] FATAL: backtrace() returned 10 addresses (../lib/core/ogs-abort.c:37)
/root/hamam/open5gs/install/lib64/libogssbi.so.2(ogs_sbi_send_request_to_nf_instance+0x347) [0x7f0bc3419fb9]
./open5gs-amfd() [0x4197cf]
./open5gs-amfd() [0x44eb0a]
./open5gs-amfd() [0x439028]
/root/hamam/open5gs/install/lib64/libogscore.so.2(ogs_fsm_dispatch+0x10f) [0x7f0bc4afbf63]
./open5gs-amfd() [0x408637]
/root/hamam/open5gs/install/lib64/libogscore.so.2(+0x10500) [0x7f0bc4aed500]
/lib64/libpthread.so.0(+0x81ca) [0x7f0bc268e1ca]
/lib64/libc.so.6(clone+0x43) [0x7f0bc22fae73]
Aborted (core dumped)

attached the pcap for this test

BR,
new-branch-I3805.zip

@hamtakkey
Copy link

Hi @acetcom

Sorry for bothering you , kindly any update regarding the last mail?

Thanks again!

BR,

@acetcom
Copy link
Member Author

acetcom commented Apr 8, 2024

@hamtakkey

This is a must fix issue and is well on my to-do list.

However, I ran into a number of issues when I tried to do it all at once. I'm working through them now, and hope to see them by the end of the week.

@hamtakkey
Copy link

Hi @acetcom
Really much appreciated all your support and help!

Thanks again!
BR,

@acetcom
Copy link
Member Author

acetcom commented Apr 17, 2024

@hamtakkey

The routine for handling Resource URIs in Open5GS was not properly implemented. I first applied the patch to the i3058 branch for SMF only.

Please check if it works well when using third-party SMF. If it works, I will fix all other NFs in the same way.

Thank you so much for raigin this issue.
Sukchan

@hamtakkey
Copy link

hamtakkey commented Apr 17, 2024

Hi @acetcom

Thanks a lot for all your efforts!
I have tried to apply the new patch. but I got the below error:
meson.build:18:0: ERROR: prefix value 'pwd/install' must be an absolute path

I was following these steps:
git clone https://github.com/open5gs/open5gs
cd open5gs
git checkout i3058
meson build --prefix=pwd/install
ninja -C build install

Could you please advise?

[root@open5gs open5gs-batch-i3058]# cd open5gs/
[root@open5gs open5gs]# git checkout i3058
branch 'i3058' set up to track 'origin/i3058'.
Switched to a new branch 'i3058'
[root@open5gs open5gs]# meson build --prefix=pwd/install
The Meson build system
Version: 0.58.2
Source dir: /root/open5gs-batch-i3058/open5gs
Build dir: /root/open5gs-batch-i3058/open5gs/build
Build type: native build

meson.build:18:0: ERROR: prefix value 'pwd/install' must be an absolute path

A full log can be found at /root/open5gs-batch-i3058/open5gs/build/meson-logs/meson-log.txt

BR

@acetcom
Copy link
Member Author

acetcom commented Apr 17, 2024

@hamtakkey

meson build --prefix=pwd/install

pwd is incorrect.

meson build --prefix=`pwd`/install

@hamtakkey
Copy link

hamtakkey commented Apr 17, 2024

Hi @acetcom
thanks a lot for your prompt response ... very great support ! ,it seems it is working fine now. see the attached pcap

I see now the right port is sending from AMF in nsmf-pdusession message to the SMF

Just another question for completeness , when I stop the UE from UERANSIM ,I don't see release and the session will stay in the SMF?
working_patchi3058.zip

BR,
Hamam

acetcom added a commit that referenced this issue Apr 18, 2024
A friend in the community was trying to connect an SMF made by another
manufacturer with an SBI interface and found a big problem with Open5GS.

All of the code in the part that generates the Resource URI
from HTTP.location is invalid.

For example, suppose we create a Resource URI with SMContext as below.
{apiRoot}/nsmf-pdusession/<apiVersion>/sm-contexts/{smContextRef}

In this case, Open5GS extracted the {smContextRef} part of the HTTP.location
and appended it to the beginning
{apiRoot}/nsmf-pdusession/<apiVersion>/sm-contexts/.

This implementation may not work properly if the apiRoot changes.
Consider a different port number as shown below.

<HTTP.location>
127.0.0.4:9999/nsmf-pdusession/v1/sm-contexts/1

The SMF may send an apiRoot to the AMF with a changed port number,
in which case the AMF must honor it.

Therefore, instead of extracting only the smContextRef from HTTP.location,
we modified it to use the whole thing to create a Resource URI.

We modified all NFs that use HTTP.location in the same way, not just SMFs.
acetcom added a commit that referenced this issue Apr 18, 2024
A friend in the community was trying to connect an SMF made by another
manufacturer with an SBI interface and found a big problem with Open5GS.

All of the code in the part that generates the Resource URI
from HTTP.location is invalid.

For example, suppose we create a Resource URI with SMContext as below.
{apiRoot}/nsmf-pdusession/<apiVersion>/sm-contexts/{smContextRef}

In this case, Open5GS extracted the {smContextRef} part of the HTTP.location
and appended it to the beginning
{apiRoot}/nsmf-pdusession/<apiVersion>/sm-contexts/.

This implementation may not work properly if the apiRoot changes.
Consider a different port number as shown below.

<HTTP.location>
127.0.0.4:9999/nsmf-pdusession/v1/sm-contexts/1

The SMF may send an apiRoot to the AMF with a changed port number,
in which case the AMF must honor it.

Therefore, instead of extracting only the smContextRef from HTTP.location,
we modified it to use the whole thing to create a Resource URI.

We modified all NFs that use HTTP.location in the same way, not just SMFs.
@acetcom
Copy link
Member Author

acetcom commented Apr 18, 2024

@hamtakkey

If you stop UERANSIM as is, it will not send the release to Core, so the pcap you attached is working fine now.

I've pushed all the fixes to the main branch, so the i3058 branch no longer exists.

Please let me know if you have any other issues.

Thanks a lot!
Sukchan

@acetcom acetcom added the Housekeeping:ToClose Issues reviewed and closed. Old requests, issues which are not bug, feature or documentation request label Apr 18, 2024
@hamtakkey
Copy link

Hi @acetcom

It's working fine using the main branch, thanks a lot for all help ! much appreciated!

BR,
Hamam

@github-actions github-actions bot removed the Housekeeping:ToClose Issues reviewed and closed. Old requests, issues which are not bug, feature or documentation request label Apr 18, 2024
@acetcom acetcom added the Housekeeping:ToClose Issues reviewed and closed. Old requests, issues which are not bug, feature or documentation request label Apr 19, 2024
Copy link

This issue has been closed automatically due to lack of activity. This has been done to try and reduce the amount of noise. Please do not comment any further. The Open5GS Team may choose to re-open this issue if necessary.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Housekeeping:ToClose Issues reviewed and closed. Old requests, issues which are not bug, feature or documentation request type:bug Open5GS bug
Projects
None yet
Development

No branches or pull requests

2 participants