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

ogs_gtp_xact_update_tx() failed #326

Open
srinidhikrs opened this issue May 29, 2024 · 6 comments
Open

ogs_gtp_xact_update_tx() failed #326

srinidhikrs opened this issue May 29, 2024 · 6 comments

Comments

@srinidhikrs
Copy link

We have a Volte testbed with srsenb (USRP_B210) + open5gs + kamailio IMS + IMS Application server.
We are testing Video Ringbacktone service using our IMS application server.
When B-party is ringing , IMS applicaion server upgrades audio session to video session between A-party and Video Tone service .
At the same instance mmed is aborting with the following trace :

05/29 05:18:35.732: [esm] DEBUG: Modify EPS bearer context accept (../src/mme/esm-sm.c:331)
05/29 05:18:35.732: [esm] DEBUG: IMSI[001010123456793] PTI[0] EBI[7] (../src/mme/esm-sm.c:332)
05/29 05:18:35.732: [mme] DEBUG: Update Bearer Response (../src/mme/mme-s11-build.c:660)
05/29 05:18:35.732: [mme] DEBUG: MME_S11_TEID[1011] SGW_S11_TEID[201] (../src/mme/mme-s11-build.c:661)
05/29 05:18:35.732: [core] TRACE: BUILD L#0 [Cause] T:2 L:0 I:0 (cls:9 vsz:24) off:0x7f9aa17f5c40 (../lib/core/ogs-tlv-msg.c:386)
05/29 05:18:35.732: [core] TRACE: BUILD C#1 [Bearer Context] T:93 I:0 (vsz=616) off:0x7f9aa17f5c58 (../lib/core/ogs-tlv-msg.c:364)
05/29 05:18:35.732: [core] TRACE: BUILD L#0 [EBI] T:73 L:1 I:0 (cls:0 vsz:16) off:0x7f9aa17f5c60 (../lib/core/ogs-tlv-msg.c:386)
05/29 05:18:35.732: [core] TRACE: BUILD L#11 [Cause] T:2 L:0 I:0 (cls:9 vsz:24) off:0x7f9aa17f5d60 (../lib/core/ogs-tlv-msg.c:386)
05/29 05:18:35.732: [core] TRACE: BUILD L#9 [UE Time Zone] T:114 L:0 I:0 (cls:9 vsz:24) off:0x7f9aa17f5f60 (../lib/core/ogs-tlv-msg.c:386)
05/29 05:18:35.732: [core] TRACE: BUILD L#10 [ULI] T:86 L:0 I:0 (cls:9 vsz:24) off:0x7f9aa17f5f78 (../lib/core/ogs-tlv-msg.c:386)
05/29 05:18:35.732: [gtp] DEBUG: [10] REMOTE UPD TX-98 peer [127.0.0.3]:2123 (../lib/gtp/xact.c:348)
05/29 05:18:35.732: [gtp] ERROR: invalid step[2] (../lib/gtp/xact.c:393)
05/29 05:18:35.732: [mme] ERROR: ogs_gtp_xact_update_tx() failed (../src/mme/mme-gtp-path.c:460)
05/29 05:18:35.732: [esm] FATAL: esm_state_active: Assertion `OGS_OK == mme_gtp_send_update_bearer_response( bearer, OGS_GTP2_CAUSE_REQUEST_ACCEPTED)' failed. (../src/mme/esm-sm.c:335)
05/29 05:18:35.732: [core] FATAL: backtrace() returned 9 addresses (../lib/core/ogs-abort.c:37)
./open5gs-mmed(+0x74746) [0x55bd04fe5746]
/root/open5gs/install/lib/x86_64-linux-gnu/libogscore.so.2(ogs_fsm_dispatch+0x119) [0x7f9b205d8bc6]
./open5gs-mmed(+0x8b4f0) [0x55bd04ffc4f0]
/root/open5gs/install/lib/x86_64-linux-gnu/libogscore.so.2(ogs_fsm_dispatch+0x119) [0x7f9b205d8bc6]
./open5gs-mmed(+0x9e99) [0x55bd04f7ae99]
/root/open5gs/install/lib/x86_64-linux-gnu/libogscore.so.2(+0x11934) [0x7f9b205c9934]
/lib/x86_64-linux-gnu/libc.so.6(+0x94ac3) [0x7f9b1fecaac3]
/lib/x86_64-linux-gnu/libc.so.6(+0x126850) [0x7f9b1ff5c850]

Please help us to fix this issue.

volte_testcall1.zip
open5gs_logs.zip

Thanks
Srinidhi

@herlesupreeth
Copy link
Owner

Hey @srinidhikrs I havent worked that much with Application Server involved. I will try to look over the pcap tomorrow.

@srinidhikrs
Copy link
Author

Hi ,

Thanks for the response.

I had also raised this issue in open5gs forum.

Sukchan has identified a bug in open5gs-mmed.

open5gs/open5gs#3240

So waiting for Sukchan to provide the fix so that I can continue testing.

Thanks
Srinidhi

@srinidhikrs
Copy link
Author

srinidhikrs commented May 31, 2024

Hi ,

I have updated the sip flow in IMS Application server to avoid second bearer update before first update response is executed .

Now the mmed is not aborting.

But the media packets from IMS MRF is not reaching the UE.

The service call flow is as follows :

1)A-party makes call to B-party

2)B-party phone starts ringing

3)IMS Application server(172.19.118.233) connects media (audio+video) between A-party and IMS MRF (172.19.118.233) using SIP Update request

4)IMS MRF starts playing media (audio+video) to A-party .

Observations when A-party is connected with IMS MRF server for media:

1)In the captured pcap file , GTP (Error Indication) packets are seen

2)In smf.log the following error is observed around same time
06/01 05:07:37.010: [smf] ERROR: [001010123456793:ims] Error Indication from SGW-C (../src/smf/n4-handler.c:1366)

3)In sgwc.log , the following error is seen
06/01 05:07:36.961: [sgwc] ERROR: [001010123456793] Error Indication(Dedicated Bearer) from SMF (../src/sgwc/sxa-handler.c:1501)

4)In sgwu.log , the following error is seen
06/01 05:07:36.960: [sgwu] ERROR: [127.0.0.6] Send Error Indication [TEID:0xc44e] to [127.0.1.1] (../src/sgwu/gtp-path.c:212)

5)IN upf.log , the following error is seen
06/01 05:07:36.952: [upf] ERROR: [127.0.0.7] Send Error Indication [TEID:0xb36a] to [127.0.0.6] (../src/upf/gtp-path.c:474)

6)In enb.log , the following errors are seen :

2024-06-01T05:06:41.601201 [PDCP ] [W] Setting discard timer to 1500ms, to avoid issues with lingering SDUs in the Unacknowledged SDUs map. LCID=4
2024-06-01T05:07:35.409730 [RRC ] [E] Expected RRCReconfigurationComplete with transaction ID: 0, got 1
2024-06-01T05:07:35.431703 [RRC ] [E] Expected RRCReconfigurationComplete with transaction ID: 0, got 1
2024-06-01T05:07:36.811721 [RRC ] [E] Expected RRCReconfigurationComplete with transaction ID: 0, got 1
2024-06-01T05:07:36.960647 [GTPU ] [E] gtpu_read_header - Unhandled GTP-U Extension Header Type: 0x40
2024-06-01T05:07:36.976486 [GTPU ] [E] gtpu_read_header - Unhandled GTP-U Extension Header Type: 0x40
2024-06-01T05:07:36.984053 [GTPU ] [E] gtpu_read_header - Unhandled GTP-U Extension Header Type: 0x40
2024-06-01T05:07:37.011184 [GTPU ] [E] gtpu_read_header - Unhandled GTP-U Extension Header Type: 0x40

Please help in identifying and fixing the media issue from IMS-MRF (172.19.118.233) to A-party

Thanks
Srinidhi

conf.zip
open5gs_logs.zip
volte_test_call_pcap.zip
enb.zip

@herlesupreeth
Copy link
Owner

But the media packets from IMS MRF is not reaching the UE.

Cant confirm completely since your ESP packets are encrypted, but I think the ports in the packet filters maybe wrong.

Can you re-try the above scenario by adding the following kamailio_pcscf.cfg and re-attach + re-take the pcap?

modparam("ims_ipsec_pcscf", "ipsec_preferred_ealg", "null")

@srinidhikrs
Copy link
Author

Hi,

With the following config :
modparam("ims_ipsec_pcscf", "ipsec_preferred_ealg", "null")

The pcscf did not come up with error : ipsec_preferred_ealg is invalid

I updated open5gs to the latest main branch to include the latest patch (open5gs/open5gs#3240) and made a test call.
But now smf is aborting :
06/04 04:46:08.977: [core] TRACE: PARSE L#3 [ULI] T:86 L:0 I:0 (cls:9 vsz:24) off:0x7f432d7f8208 (../lib/core/ogs-tlv-msg.c:721)
06/04 04:46:08.977: [gtp] DEBUG: [3] LOCAL Find GTPv2 peer [127.0.0.3]:2123 (../lib/gtp/xact.c:963)
06/04 04:46:08.977: [gtp] DEBUG: [3] LOCAL Receive peer [127.0.0.3]:2123 (../lib/gtp/xact.c:980)
06/04 04:46:08.977: [gtp] DEBUG: [3] LOCAL UPD RX-98 peer [127.0.0.3]:2123 (../lib/gtp/xact.c:448)
06/04 04:46:08.977: [smf] FATAL: smf_s5c_handle_update_bearer_response: Assertion `sess' failed. (../src/smf/s5c-handler.c:853)
06/04 04:46:08.977: [core] FATAL: backtrace() returned 8 addresses (../lib/core/ogs-abort.c:37)
./open5gs-smfd(+0x4a413) [0x55cdb845f413]
./open5gs-smfd(+0x24e79) [0x55cdb8439e79]
/root/open5gs/install/lib/x86_64-linux-gnu/libogscore.so.2(ogs_fsm_dispatch+0x119) [0x7f43b8ce2c6e]
./open5gs-smfd(+0x10418) [0x55cdb8425418]
/root/open5gs/install/lib/x86_64-linux-gnu/libogscore.so.2(+0x119dc) [0x7f43b8cd39dc]
/lib/x86_64-linux-gnu/libc.so.6(+0x94ac3) [0x7f43b7be6ac3]
/lib/x86_64-linux-gnu/libc.so.6(+0x126850) [0x7f43b7c78850]

Still there is no media between A-party and IMS MRF.

Please help in resolving the smf abort issues and also the media issue

In enb.log observing the following error:

2024-06-04T04:46:08.812902 [RRC ] [D] Content:
[
{
"UL-DCCH-Message": {
"message": {
"c1": {
"rrcConnectionReconfigurationComplete": {
"rrc-TransactionIdentifier": 1,
"criticalExtensions": {
"rrcConnectionReconfigurationComplete-r8": {
}
}
}
}
}
}
}
]
2024-06-04T04:46:08.812905 [MAC ] [D] [ 2991] SCHED: Allocated PRACH RBs mask=0fc0000000000000000000000 for tti_tx_ul=3001
2024-06-04T04:46:08.812906 [RRC ] [E] Expected RRCReconfigurationComplete with transaction ID: 0, got 1

Thanks
Srinidhi

volte_testlogs.zip

@herlesupreeth
Copy link
Owner

modparam("ims_ipsec_pcscf", "ipsec_preferred_ealg", "null")

The pcscf did not come up with error : ipsec_preferred_ealg is invalid

Then, you are not using the latest commits from this repo (which uses latest kamailio code)

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

2 participants