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

incorrect behavior of the SGsAP #3072

Closed
svinson1121 opened this issue Mar 21, 2024 · 18 comments
Closed

incorrect behavior of the SGsAP #3072

svinson1121 opened this issue Mar 21, 2024 · 18 comments
Labels
Housekeeping:ToClose Issues reviewed and closed. Old requests, issues which are not bug, feature or documentation request type:bug Open5GS bug

Comments

@svinson1121
Copy link

Hello, I would like to address two interconnected issues concerning the behavior of the SGsAP:

  1. According to ETSI TS 129 118 4.1, if the Network Access Mode (NAM) is set to "Packet only," no SGs association should be established.
    In the attached PCAP file at packet 228 Subscription-Data AVP (Attribute-Value Pair) indicates that the Network-Access_mode is set to ONLY_PACKET
    And in the attached mme.log you can see the UE fails to attach to the network following the WARNING: [SGSAP] LOCATION-UPDATE-REJECT Where the SGs association is attempted.

  2. If the NAM is set to "Packet and Circuit," and the SGs association is rejected by the CS core, this rejection should only impact the SGs association itself and not result in a UE attach rejection for a UE with a valid HSS account.

sgsap-ps.zip

@acetcom acetcom added type:bug Open5GS bug Housekeeping:ToClose Issues reviewed and closed. Old requests, issues which are not bug, feature or documentation request labels Mar 24, 2024
@acetcom
Copy link
Member

acetcom commented Mar 24, 2024

@svinson1121

I've resolved this issue and applied it into the main branch.

Please let me know if you have any other problems.

Thanks a lot!
Sukchan

@svinson1121
Copy link
Author

svinson1121 commented Mar 24, 2024

@acetcom

Hi Sukchan,
Thank you so much for your help.

I'm seeing the MME crash after the changes. looks to be right after an SGS association.
from the OsmoMSC logs included below it looks like the SGS association was successful.
I'm only seeing this crash when the NAM is set to Packet and Circuit, when the NAM is Packet only everything works as expected.

if you need anything more from me, logs, pcaps, please let me know.

MME LOG:

03/24 17:18:16.239: [mme] INFO: InitialUEMessage (../src/mme/s1ap-handler.c:406)
03/24 17:18:16.239: [mme] INFO: [Added] Number of eNB-UEs is now 1 (../src/mme/mme-context.c:4735)
03/24 17:18:16.239: [mme] INFO: ENB_UE_S1AP_ID[18] MME_UE_S1AP_ID[1] TAC[1] CellID[0x101] (../src/mme/s1ap-handler.c:585)
03/24 17:18:16.240: [mme] INFO: Unknown UE by GUTI[G:2,C:1,M_TMSI:0xc0000619] (../src/mme/mme-context.c:3586)
03/24 17:18:16.240: [mme] INFO: [Added] Number of MME-UEs is now 1 (../src/mme/mme-context.c:3379)
03/24 17:18:16.240: [emm] INFO: [] Attach request (../src/mme/emm-sm.c:423)
03/24 17:18:16.240: [emm] INFO: GUTI[G:2,C:1,M_TMSI:0xc0000619] IMSI[Unknown IMSI] (../src/mme/emm-handler.c:236)
03/24 17:18:16.287: [emm] INFO: Identity response (../src/mme/emm-sm.c:393)
03/24 17:18:16.287: [emm] INFO: IMSI[311435000070570] (../src/mme/emm-handler.c:428)
03/24 17:18:16.817: [mme] INFO: [Added] Number of MME-Sessions is now 1 (../src/mme/mme-context.c:4749)
03/24 17:18:17.013: [mme] FATAL: nas_eps_send_attach_accept: Assertion `mme_bearer_next(bearer) == NULL' failed. (../src/mme/nas-path.c:128)
03/24 17:18:17.014: [core] FATAL: backtrace() returned 11 addresses (../lib/core/ogs-abort.c:37)
/usr/bin/open5gs-mmed(+0x5a0c3) [0x5583259750c3]
/usr/bin/open5gs-mmed(+0x9f15c) [0x5583259ba15c]
/usr/bin/open5gs-mmed(+0x9c79f) [0x5583259b779f]
/usr/lib/x86_64-linux-gnu/libogscore.so.2(ogs_fsm_dispatch+0x119) [0x7f9f56cdcbc6]
/usr/bin/open5gs-mmed(+0x8e5ac) [0x5583259a95ac]
/usr/lib/x86_64-linux-gnu/libogscore.so.2(ogs_fsm_dispatch+0x119) [0x7f9f56cdcbc6]
/usr/bin/open5gs-mmed(+0x9e99) [0x558325924e99]
/usr/lib/x86_64-linux-gnu/libogscore.so.2(+0x11934) [0x7f9f56ccd934]
/usr/lib/x86_64-linux-gnu/libc.so.6(+0x94ac3) [0x7f9f565e6ac3]
/usr/lib/x86_64-linux-gnu/libc.so.6(+0x126850) [0x7f9f56678850]
Open5GS daemon v2.7.0-118-g390a9dd

osmoMSC:

OsmoMSC# <0014> sgs_iface.c:658 r=10.90.250.21:52353<->l=10.90.250.42:29118: Receiving SGsAP-LOCATION-UPDATE-REQUEST without TAI nor E-CGI IEs, fast fallback GERAN->EUTRAN won't be possible!
<0014> vlr_sgs.c:100 SGs-UE(imsi:311435000070570)[0x55e22df6afb0]{SGs-ASSOCIATED}: Received Event RX_LU_FROM_MME
<0011> gsm_04_08.c:1541 SUBSCR(IMSI-311435000070570:MSISDN-3342012832:TMSInew-0x7C993E23) VLR: update for IMSI=311435000070570 (MSISDN=3342012832) (NO CONN!)
<0014> vlr_sgs_fsm.c:95 SGs-UE(imsi:311435000070570)[0x55e22df6afb0]{SGs-ASSOCIATED}: State change to SGs-LA-UPDATE-PRESENT (no timeout)
<0011> gsm_04_08.c:1541 SUBSCR(IMSI-311435000070570:MSISDN-3342012832:TMSInew-0x7C993E23) VLR: update for IMSI=311435000070570 (MSISDN=3342012832) (NO CONN!)
<0014> vlr_sgs.c:120 SGs-UE(imsi:311435000070570)[0x55e22df6afb0]{SGs-LA-UPDATE-PRESENT}: Received Event TX_LU_ACCEPT
<0014> vlr_sgs_fsm.c:165 SGs-UE(imsi:311435000070570)[0x55e22df6afb0]{SGs-LA-UPDATE-PRESENT}: State change to SGs-ASSOCIATED (T1, 40s)
<0014> sgs_server.c:101 r=10.90.250.21:52353<->l=10.90.250.42:29118: Connection lost
<0014> sgs_server.c:124 r=10.90.250.21:44759<->l=10.90.250.42:29118: Accepted new SGs connection
<0014> fsm.c:317 SGs-UE(imsi:311435000070570)[0x55e22df6afb0]{SGs-ASSOCIATED}: Timeout of T1

@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 24, 2024
acetcom added a commit that referenced this issue Mar 24, 2024
@acetcom
Copy link
Member

acetcom commented Mar 24, 2024

@svinson1121

Is this something you can reproduce quickly? If so, it's best to share your PCAP.

Otherwise I recommend sharing a DEBUG message. You will need to change the log level to the DEBUG for MME, SGW-C, and SMF as below.

diff --git a/configs/open5gs/mme.yaml.in b/configs/open5gs/mme.yaml.in
index 5acf05fdc..3706adbdf 100644
--- a/configs/open5gs/mme.yaml.in
+++ b/configs/open5gs/mme.yaml.in
@@ -1,6 +1,7 @@
 logger:
   file: @localstatedir@/log/open5gs/mme.log
 #  level: info   # fatal|error|warn|info(default)|debug|trace
+  level: debug
 
 global:
   max:

If you can fix it down to the source code, please recompile using the issues3072 branch and run mme.

$ git clone https://github.com/open5gs/open5gs
$ cd open5gs
$ git checkout issues3072
$ ninja -C build install

Please let me know if you have any other questions.

Thanks a lot!
Sukchan

@svinson1121
Copy link
Author

@acetcom
Please find attached pcaps and full debug logs
the crash is at 16:44:49 in the MME log.
Thank you,

3072-2.zip

@svinson1121
Copy link
Author

svinson1121 commented Mar 25, 2024

when I build and run the MME from branch issues3072 I get this:

03/25 17:35:54.942: [esm] DEBUG: esm_state_inactive(): ENTRY
(../src/mme/esm-sm.c:84)
03/25 17:35:54.942: [esm] DEBUG: MME-UE Context Memory[0x7fa70b688010:0x7fa70b688010] (../src/mme/esm-sm.c:92)
03/25 17:35:54.942: [esm] DEBUG: SGW-UE Context Memory[0x556607af0d70:0x556607af0d70] (../src/mme/esm-sm.c:92)
03/25 17:35:54.942: [esm] DEBUG: IMSI [311435000070570] NAS-EPS Type[1] (../src/mme/esm-sm.c:92)
03/25 17:35:54.942: [esm] DEBUG: MME_S11_TEID[578] SGW_S11_TEID[418] (../src/mme/esm-sm.c:92)
03/25 17:35:54.942: [esm] DEBUG: SESS(0x7fa70b5df010) [internet:50] (../src/mme/esm-sm.c:92)
03/25 17:35:54.942: [esm] DEBUG: BEARER(0x7fa70ae9e010) [5] ENB_S1U_TEID[0] SGW_S1U_TEID[59908] (../src/mme/esm-sm.c:92)
03/25 17:35:54.942: [esm] DEBUG: BEARER(0x7fa70ae9e1e0) [6] ENB_S1U_TEID[0] SGW_S1U_TEID[0] (../src/mme/esm-sm.c:92)
03/25 17:35:54.942: [mme] DEBUG: MME_S11_TEID[578] SGW_S11_TEID[418] (../src/mme/mme-s11-handler.c:881)
03/25 17:35:54.942: [mme] DEBUG: [311435000070570] Clear Paging Info (../src/mme/mme-s11-handler.c:966)
03/25 17:35:54.942: [mme] DEBUG: mme_state_operational(): MME_EVENT_SGSAP_MESSAGE
(../src/mme/mme-sm.c:88)
03/25 17:35:54.943: [mme] DEBUG: sgsap_state_connected(): MME_EVENT_SGSAP_MESSAGE
(../src/mme/sgsap-sm.c:131)
03/25 17:35:54.943: [mme] DEBUG: [SGSAP] LOCATION-UPDATE-ACCEPT (../src/mme/sgsap-handler.c:47)
03/25 17:35:54.943: [mme] DEBUG: IMSI[311435000070570] (../src/mme/sgsap-handler.c:103)
03/25 17:35:54.943: [mme] DEBUG: LAI[PLMN_ID:135134,LAC:256] (../src/mme/sgsap-handler.c:105)
03/25 17:35:54.943: [mme] DEBUG: P-TMSI[0x42500291] (../src/mme/sgsap-handler.c:117)
03/25 17:35:54.943: [mme] ERROR: There should only be one BEARER (../src/mme/nas-path.c:132)
03/25 17:35:54.943: [mme] ERROR: sgsap_handle_location_update_accept: Expectation r == OGS_OK' failed. (../src/mme/sgsap-handler.c:121) 03/25 17:35:54.943: [mme] FATAL: sgsap_handle_location_update_accept: Assertion r != OGS_ERROR' failed. (../src/mme/sgsap-handler.c:122)
03/25 17:35:55.108: [core] FATAL: backtrace() returned 10 addresses (../lib/core/ogs-abort.c:37)
./open5gs-mmed(+0x9f206) [0x5566060f0206]
./open5gs-mmed(+0x9c777) [0x5566060ed777]
/usr/src/open5gs/build/src/mme/../../lib/core/libogscore.so.2(ogs_fsm_dispatch+0x119) [0x7fa70c9cdbc6]
./open5gs-mmed(+0x8e584) [0x5566060df584]
/usr/src/open5gs/build/src/mme/../../lib/core/libogscore.so.2(ogs_fsm_dispatch+0x119) [0x7fa70c9cdbc6]
./open5gs-mmed(+0x9e99) [0x55660605ae99]
/usr/src/open5gs/build/src/mme/../../lib/core/libogscore.so.2(+0x11934) [0x7fa70c9be934]
/lib/x86_64-linux-gnu/libc.so.6(+0x94ac3) [0x7fa70c2d1ac3]
/lib/x86_64-linux-gnu/libc.so.6(+0x126850) [0x7fa70c363850]
Aborted (core dumped)

mme.log

acetcom added a commit that referenced this issue Mar 25, 2024
Since first session have also multiple bearer,
this assertion should be removed.
@acetcom
Copy link
Member

acetcom commented Mar 26, 2024

@svinson1121

The issue was caused by adding a Flow for your first Session and enabling Multiple Bearer, which is possible, but Open5GS added an assertion routine in the wrong place.

I've resolved this issue in the issues3072 branch, so if you experiment with it, please share your results.

Thanks a lot!
Sukchan

@svinson1121
Copy link
Author

@acetcom
Hi Sukchan.

I tested with your changes in the issues3072 branch. The MME is no longer crashing.
However, the UE fails to attach with the NAM set to packet and circuit. the UE has a successful attach when the NAM is Packet only.
I have included two sets of pcaps and logs for each of the conditions.

Thank you so much for your help.

3072-3.zip

acetcom added a commit that referenced this issue Mar 27, 2024
In Attach Request, InitialContextSetupRequest should use only one
bearer.
@acetcom
Copy link
Member

acetcom commented Mar 27, 2024

@svinson1121

I've also fixed this issue in the issues3072 branch.

Please let me know if you test it.

Thanks a lot!
Sukchan

@svinson1121
Copy link
Author

svinson1121 commented Mar 27, 2024

@acetcom
Hi Sukchan,

I tested with issues3072 branch "Open5GS v2.7.0-121-g03feb47" and the issue still persists.
I have included logs and pcaps from three test:

NAM set to PS+CS with the SGsAP disabled = no issue.
NAM set to PS+CS with the SGsAP enabled = UE will not attach to the network
NAM set to PS Only with the SGsAP enabled = no issue

3072-4.zip

thank you very much for your efforts in resolving this issue.

acetcom added a commit that referenced this issue Mar 27, 2024
@acetcom
Copy link
Member

acetcom commented Mar 27, 2024

@svinson1121

Looking at the InitialContextSetupRequest+Attach accept+Activate default EPS bearer context request for each of the 3 pcaps, the NAM set to PS+CS with the SGsAP enabled looks fine.

However, I don't understand why the UE is not sending Attach complete+Activate default EPS bearer request accept.

The only difference between NAM set to PS+CS with the SGsAP disabled and NAM set to PS+CS with the SGsAP enabled is the code below.

$ diff --git a/src/mme/emm-build.c b/src/mme/emm-build.c
index e4fb76c2c..4d614e301 100644
--- a/src/mme/emm-build.c
+++ b/src/mme/emm-build.c
@@ -211,15 +211,19 @@ ogs_pkbuf_t *emm_build_attach_accept(
         ogs_assert(mme_ue->csmap);
         ogs_assert(mme_ue->p_tmsi);
 
+#if 0
         attach_accept->presencemask |=
             OGS_NAS_EPS_ATTACH_ACCEPT_LOCATION_AREA_IDENTIFICATION_PRESENT;
+#endif
         lai->nas_plmn_id = mme_ue->csmap->lai.nas_plmn_id;
         lai->lac = mme_ue->csmap->lai.lac;
         ogs_debug("    LAI[PLMN_ID:%06x,LAC:%d]",
                 ogs_plmn_id_hexdump(&lai->nas_plmn_id), lai->lac);
 
+#if 0
         attach_accept->presencemask |=
             OGS_NAS_EPS_ATTACH_ACCEPT_MS_IDENTITY_PRESENT;
+#endif
         ms_identity->length = 5;
         tmsi->spare = 0xf;
         tmsi->odd_even = 0;

I've put the above in the issues3072-disabled branch, could you please confirm that this branch is working properly?

If it's working, then I guess we can just assume that's why UE doesn't behave like that when I do #if 0 ... #endif.

Thank you so much for your effort.
Sukchan

@svinson1121
Copy link
Author

@acetcom
Hi Sukchan,

I tested branch issues3072-disabled and have the same issue, UE will not attach with NAM PS+CS.
I have included a pcap and debug logs from the test, I also ran a test with the log level set to trace and included it as well.
the UE is an iPhone I can possibility pull the logs from the UE if you think that might be helpful.

Thank you so much,

3072-5.zip

@acetcom
Copy link
Member

acetcom commented Mar 28, 2024

@svinson1121

If you compare the two pcaps below, they are identical except for the generated IDs such like MME-UE-S1AP-ID, ENB-UE-S1AP-ID, PDU address, etc.

  • 3072-4/mme-PS+CS-no-SGSAP.pcap
  • 3072-5/mme-PS+CS-issues3072-disabled.pcap

However, I don't understand why the UE is not sending Attach complete in 3072-5/mme-PS+CS-issues3072-disabled.pcap, is there anything different in the two test environments?

I hope there is some small hint provided so I can figure it out.

Thanks a lot!
Sukchan

@svinson1121
Copy link
Author

@acetcom

HI Sukchan,
it's a single test environment. only changes are the NAM settings on the HSS.

In all the PCAPs depicting unsuccessful attach attempts, I noticed that in the S1AP/NAS-EPS InitialContextSetupRequest messages, the value of the Procedure Transaction Identity field is consistently set to 0. Conversely, in all of the PCAPs capturing successful attach, this value is non-zero. While I'm unsure of its relevance, I wanted to bring this to your attention.

acetcom added a commit that referenced this issue Mar 30, 2024
@acetcom
Copy link
Member

acetcom commented Mar 30, 2024

@svinson1121

You've found what the problem was with Open5GS MME. There was an issue with handling the PTI, which was incorrectly setting the PTI to 0 when using SGsAP because the Create Bearer Request handler was performed before the InitialContextSetupRequest.

I have applied this issue to the issues3072 branch, please test again.

Thank you so much for your effort.
Sukchan

@svinson1121
Copy link
Author

@acetcom

HI Sukchan,

I tested using branch issues3072 v2.7.0-122-g287fca0 and the UE attach still fails with the NAM set to PS+CS.
I checked the PCAP and the PTI value is still 0 in packet 84.

Thank you for all of your work on this issue.

3072-6.zip

acetcom added a commit that referenced this issue Mar 30, 2024
@acetcom
Copy link
Member

acetcom commented Mar 31, 2024

@svinson1121

I fixed it again and pushed it to the issues3072 branch. I've experimented as much as I could and tried to fix this issue.

Thank you in advance for your review.
Sukchan

@svinson1121
Copy link
Author

svinson1121 commented Mar 31, 2024

@acetcom
Hi Sukchan,

I tested in many different scenarios, PS+CS, PS only, PS+CS without a valid HLR account, and with the SGsAP disabled. and I'm happy to report that everything is working as expected.

Thank you so much for all of your valuable time spent on this issue.

acetcom added a commit that referenced this issue Apr 1, 2024
First of all, it crashes when creating a Dedicated Bearer
on the default Session that is created for the first time.
This behavior should be possible, so the related ASSERT is removed.

Next, the InitialContextRequest is modified
during the Attach Request to include the first Bearer.

Finally, there was an issue where trying to create a Dedicated Bearer
with SGsAP enabled resulted in an InitialContextSetupRequest message
with a PTI of zero. This is because MME initializes the PTI to 0
upon receiving the Create Bearer Request while processing SGsAP.

All of these issues has been fixed.
acetcom added a commit that referenced this issue Apr 1, 2024
First of all, it crashes when creating a Dedicated Bearer
on the default Session that is created for the first time.
This behavior should be possible, so the related ASSERT is removed.

Next, the InitialContextRequest is modified
during the Attach Request to include the first Bearer.

Finally, there was an issue where trying to create a Dedicated Bearer
with SGsAP enabled resulted in an InitialContextSetupRequest message
with a PTI of zero. This is because MME initializes the PTI to 0
upon receiving the Create Bearer Request while processing SGsAP.

All of these issues has been fixed.
@acetcom
Copy link
Member

acetcom commented Apr 1, 2024

@svinson1121

I've merged this branch into the main branch.

Thank you so muich for raising 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 Apr 1, 2024
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