free5gc / upf

Apache License 2.0
32 stars 51 forks source link

With kernel 5.4.0-73-generic(ubuntu 18.04) or newer, gtp5g failed to decap UL gtp pkts larger than 144 bytes #28

Open mmadnac1313 opened 3 years ago

mmadnac1313 commented 3 years ago

I have set "dbg_trace_lvl = 4;", but there were still no useful kernel messages dumped. And free5gc UPF also had no error message to see the reason why drop the UL GTP packets. I have printed out "sk_buff->data" to kernel message, and I found "sk_buff->data" was corrupted since the byte of "next extention header type". Is there any workaround to solve this issue, instead of replacing the kernel?(it's OK with Linux kernel 5.4.0-42) The ping test was performed with "free5gc 3.0.5"(5.4.0-73-generic or 5.4.0-77-generic) and "UERANSIM-3.2.1"(5.8.0-59-generic). [12658.461182] upfgtp:[gtp5g] gtp5g_dellink: deregistered 5G GTP interface [12663.635080] gtp5g: enable gtp5g on 11, 5 [12663.638400] upfgtp:[gtp5g] gtp5g_newlink: Registered a new 5G GTP interface [12679.993822] upfgtp:[gtp5g] gtp5g_gnl_add_far: FAR-Add: id[2] success [12679.993997] upfgtp:[gtp5g] gtp5g_gnl_add_far: FAR-Add: id[4] success [12679.994422] upfgtp:[gtp5g] gtp5g_gnl_add_pdr: PDR-Add: id[1] success [12679.994756] upfgtp:[gtp5g] gtp5g_gnl_add_pdr: PDR-Add: id[3] success [12680.028290] upfgtp:[gtp5g] gtp5g_gnl_add_far: FAR-Add: update id[4] success [12697.260816] [gtp5g] gtp5g_push_header: SKBLen(96) GTP-U V1(8) Opt(4) DL_PDU(4) [12697.260865] [gtp5g] gtp5g_push_header: QER Found GTP-U Flg(48) GTPU-L(96) SkbLen(104) [12763.867799] [gtp5g] gtp5g_push_header: SKBLen(96) GTP-U V1(8) Opt(4) DL_PDU(4) [12763.867820] [gtp5g] gtp5g_push_header: QER Found GTP-U Flg(48) GTPU-L(96) SkbLen(104) [12764.870294] [gtp5g] gtp5g_push_header: SKBLen(96) GTP-U V1(8) Opt(4) DL_PDU(4) [12764.870315] [gtp5g] gtp5g_push_header: QER Found GTP-U Flg(48) GTPU-L(96) SkbLen(104) [12765.873635] [gtp5g] gtp5g_push_header: SKBLen(96) GTP-U V1(8) Opt(4) DL_PDU(4) [12765.873656] [gtp5g] gtp5g_push_header: QER Found GTP-U Flg(48) GTPU-L(96) SkbLen(104) [12766.874944] [gtp5g] gtp5g_push_header: SKBLen(96) GTP-U V1(8) Opt(4) DL_PDU(4) [12766.874965] [gtp5g] gtp5g_push_header: QER Found GTP-U Flg(48) GTPU-L(96) SkbLen(104) [12767.875578] [gtp5g] gtp5g_push_header: SKBLen(96) GTP-U V1(8) Opt(4) DL_PDU(4) [12767.875600] [gtp5g] gtp5g_push_header: QER Found GTP-U Flg(48) GTPU-L(96) SkbLen(104) [12768.880723] [gtp5g] gtp5g_push_header: SKBLen(96) GTP-U V1(8) Opt(4) DL_PDU(4) [12768.880743] [gtp5g] gtp5g_push_header: QER Found GTP-U Flg(48) GTPU-L(96) SkbLen(104) [12769.881218] [gtp5g] gtp5g_push_header: SKBLen(96) GTP-U V1(8) Opt(4) DL_PDU(4) [12769.881238] [gtp5g] gtp5g_push_header: QER Found GTP-U Flg(48) GTPU-L(96) SkbLen(104) [12770.884266] [gtp5g] gtp5g_push_header: SKBLen(96) GTP-U V1(8) Opt(4) DL_PDU(4) [12770.884286] [gtp5g] gtp5g_push_header: QER Found GTP-U Flg(48) GTPU-L(96) SkbLen(104) [12771.885505] [gtp5g] gtp5g_push_header: SKBLen(96) GTP-U V1(8) Opt(4) DL_PDU(4) [12771.885526] [gtp5g] gtp5g_push_header: QER Found GTP-U Flg(48) GTPU-L(96) SkbLen(104) [12772.887002] [gtp5g] gtp5g_push_header: SKBLen(96) GTP-U V1(8) Opt(4) DL_PDU(4) [12772.887024] [gtp5g] gtp5g_push_header: QER Found GTP-U Flg(48) GTPU-L(96) SkbLen(104) [12773.889643] [gtp5g] gtp5g_push_header: SKBLen(96) GTP-U V1(8) Opt(4) DL_PDU(4) [12773.889665] [gtp5g] gtp5g_push_header: QER Found GTP-U Flg(48) GTPU-L(96) SkbLen(104) [12774.891166] [gtp5g] gtp5g_push_header: SKBLen(96) GTP-U V1(8) Opt(4) DL_PDU(4) [12774.891198] [gtp5g] gtp5g_push_header: QER Found GTP-U Flg(48) GTPU-L(96) SkbLen(104) [12775.895024] [gtp5g] gtp5g_push_header: SKBLen(96) GTP-U V1(8) Opt(4) DL_PDU(4) [12775.895055] [gtp5g] gtp5g_push_header: QER Found GTP-U Flg(48) GTPU-L(96) SkbLen(104) [12776.896408] [gtp5g] gtp5g_push_header: SKBLen(96) GTP-U V1(8) Opt(4) DL_PDU(4) [12776.896424] [gtp5g] gtp5g_push_header: QER Found GTP-U Flg(48) GTPU-L(96) SkbLen(104) [12777.898152] [gtp5g] gtp5g_push_header: SKBLen(96) GTP-U V1(8) Opt(4) DL_PDU(4) [12777.898173] [gtp5g] gtp5g_push_header: QER Found GTP-U Flg(48) GTPU-L(96) SkbLen(104) [12778.899750] [gtp5g] gtp5g_push_header: SKBLen(96) GTP-U V1(8) Opt(4) DL_PDU(4) [12778.899781] [gtp5g] gtp5g_push_header: QER Found GTP-U Flg(48) GTPU-L(96) SkbLen(104) [12779.902446] [gtp5g] gtp5g_push_header: SKBLen(96) GTP-U V1(8) Opt(4) DL_PDU(4) [12779.902477] [gtp5g] gtp5g_push_header: QER Found GTP-U Flg(48) GTPU-L(96) SkbLen(104) [12780.903726] [gtp5g] gtp5g_push_header: SKBLen(96) GTP-U V1(8) Opt(4) DL_PDU(4) [12780.903749] [gtp5g] gtp5g_push_header: QER Found GTP-U Flg(48) GTPU-L(96) SkbLen(104) [12781.906110] [gtp5g] gtp5g_push_header: SKBLen(96) GTP-U V1(8) Opt(4) DL_PDU(4) [12781.906143] [gtp5g] gtp5g_push_header: QER Found GTP-U Flg(48) GTPU-L(96) SkbLen(104)

muthuramanecs03g commented 3 years ago

Hi @mmadnac1313 ,

I have some doubt about your logs,

[12658.461182] upfgtp:[gtp5g] gtp5g_dellink: deregistered 5G GTP interface [12663.635080] gtp5g: enable gtp5g on 11, 5 [12663.638400] upfgtp:[gtp5g] gtp5g_newlink: Registered a new 5G GTP interface [12679.993822] upfgtp:[gtp5g] gtp5g_gnl_add_far: FAR-Add: id[2] success [12679.993997] upfgtp:[gtp5g] gtp5g_gnl_add_far: FAR-Add: id[4] success [12679.994422] upfgtp:[gtp5g] gtp5g_gnl_add_pdr: PDR-Add: id[1] success [12679.994756] upfgtp:[gtp5g] gtp5g_gnl_add_pdr: PDR-Add: id[3] success [12680.028290] upfgtp:[gtp5g] gtp5g_gnl_add_far: FAR-Add: update id[4] success [12697.260816] [gtp5g] gtp5g_push_header: SKBLen(96) GTP-U V1(8) Opt(4) DL_PDU(4) [12697.260865] [gtp5g] gtp5g_push_header: QER Found GTP-U Flg(48) GTPU-L(96) SkbLen(104)

Why there is no QER add in your log but seen QER Found message,

Could you capture wireshark trace of N3 and send it to me.

mmadnac1313 commented 3 years ago

Here you are. It sounds UPF of Free5gc 3.05 has sent an incorrect icmp packet to outside. gtp.zip

mmadnac1313 commented 3 years ago

By the way, I capture the netlog after I upgrade the Linux kernel to 5.4.0-77-generic(ubuntu 18.04) for Free5gc VM. Here is the netlog that was run with Free5gc 3.04 gtp_free5gc304.zip It sounds that Free5gc has the different decap result under 5.4.0-73-generic and 5.4.0-77-generic.

muthuramanecs03g commented 3 years ago

Hi @mmadnac1313,

I suspect your codebase of free5GC UPF and gtp5g, I will take a look at your attachment and let you know.

You can read the forum of the free5GC compatibility issue

https://forum.free5gc.org/t/free5gc-gtp-payload-doesnt-contain-pdu-session-container-in-ul-and-dl/863/28

mmadnac1313 commented 3 years ago

Here is my free5gc latest git log: ommit 04340eb8493ba98178ecc725e38ed8677f08d16e (HEAD, tag: v3.0.5) Merge: 92c741a 3ca89b1 Author: free5gc-org free5gc.org@gmail.com Date: Sun Jan 31 19:27:17 2021 +0000

Release v3.0.5: Merge branch master into main

And I copy gtp5g by "git clone https://github.com/free5gc/gtp5g.git"

mmadnac1313 commented 3 years ago

Here is the git log of gtp5g: I think I have got the latest commit! commit adfdbf574b41d5518b01b8dc769869e661fdef01 (HEAD -> master, origin/master, origin/HEAD) Author: Muthuraman Elangovan 76576790+muthuramanecs03g@users.noreply.github.com Date: Fri Jun 25 14:49:10 2021 +0800

Update README.md

commit 56a709fbaf7e3cb95b691ec7c57496fedea61df0 Merge: 0343588 5c42058 Author: Muthuraman Elangovan 76576790+muthuramanecs03g@users.noreply.github.com Date: Tue Jun 15 22:00:20 2021 +0800

Merge pull request #10 from free5gc/n9_interface_support

N9 interface support
muthuramanecs03g commented 3 years ago

Hi @mmadnac1313 ,

Both gtp.zip & gtp_free5gc304.zip, the uplink GTP-U has an "Extension header for UL PDU" but there is no extension header for DL PDU. It may happen due to the QER record is not present in gtp5g.

Here you are. It sounds UPF of Free5gc 3.05 has sent an incorrect icmp packet to outside. gtp.zip What do you mean? You mean it downlink packet with the extension header.

You didn't understand my question

I have some doubt about your logs,

[12658.461182] upfgtp:[gtp5g] gtp5g_dellink: deregistered 5G GTP interface [12663.635080] gtp5g: enable gtp5g on 11, 5 [12663.638400] upfgtp:[gtp5g] gtp5g_newlink: Registered a new 5G GTP interface [12679.993822] upfgtp:[gtp5g] gtp5g_gnl_add_far: FAR-Add: id[2] success [12679.993997] upfgtp:[gtp5g] gtp5g_gnl_add_far: FAR-Add: id[4] success [12679.994422] upfgtp:[gtp5g] gtp5g_gnl_add_pdr: PDR-Add: id[1] success [12679.994756] upfgtp:[gtp5g] gtp5g_gnl_add_pdr: PDR-Add: id[3] success [12680.028290] upfgtp:[gtp5g] gtp5g_gnl_add_far: FAR-Add: update id[4] success [12697.260816] [gtp5g] gtp5g_push_header: SKBLen(96) GTP-U V1(8) Opt(4) DL_PDU(4) [12697.260865] [gtp5g] gtp5g_push_header: QER Found GTP-U Flg(48) GTPU-L(96) SkbLen(104)

Why there is no QER add in your log but seen QER Found message,

You should see a message like below when QER is present while SMF sending PFCP message to UPF, and then gtp5g kernel can print like it below

[3913909.802101] gtp5gtest:[gtp5g] gtp5g_gnl_add_qer: QER-Add: QER_ID(123) success [3913909.823839] gtp5gtest:[gtp5g] gtp5g_gnl_add_qer: QER-Add: QER_ID(321) success

The answer is, you are using an incompatible source code of free5GC UPF and gtp5g. I confirmed by attached Wireshark capture.

How to sync the latest code of free5GC is shown below,

cd ~/free5gc git checkout main git submodule sync git submodule update --init --jobs nproc git submodule foreach git checkout main git submodule foreach git pull --jobs nproc

mmadnac1313 commented 3 years ago

OK , after I sync the latest code according to your comment, the GTP5G dmesg is as below [17699.335348] upfgtp:[gtp5g] gtp5g_newlink: registered new 5G GTP interface [17715.159183] upfgtp:[gtp5g] gtp5g_gnl_add_far: FAR-Add: id[1] success [17715.159435] upfgtp:[gtp5g] gtp5g_gnl_add_far: FAR-Add: id[2] success [17715.159621] upfgtp:[gtp5g] gtp5g_gnl_add_qer: QER-Add: QER_ID(1) success [17715.161715] upfgtp:[gtp5g] gtp5g_gnl_add_pdr: PDR-Add: id[1] success [17715.162030] upfgtp:[gtp5g] gtp5g_gnl_add_pdr: PDR-Add: id[2] success [17715.197740] upfgtp:[gtp5g] gtp5g_gnl_add_far: FAR-Add: update id[2] success [17717.560849] [gtp5g] gtp5g_push_header: SKBLen(96) GTP-U V1(8) Opt(4) DL_PDU(4) [17717.560887] [gtp5g] gtp5g_push_header: QER Found GTP-U Flg(52) GTPU-L(104) SkbLen(112) [17718.563094] [gtp5g] gtp5g_push_header: SKBLen(96) GTP-U V1(8) Opt(4) DL_PDU(4) [17718.563133] [gtp5g] gtp5g_push_header: QER Found GTP-U Flg(52) GTPU-L(104) SkbLen(112) [17719.566333] [gtp5g] gtp5g_push_header: SKBLen(96) GTP-U V1(8) Opt(4) DL_PDU(4) [17719.566372] [gtp5g] gtp5g_push_header: QER Found GTP-U Flg(52) GTPU-L(104) SkbLen(112) [17720.570319] [gtp5g] gtp5g_push_header: SKBLen(96) GTP-U V1(8) Opt(4) DL_PDU(4) [17720.570358] [gtp5g] gtp5g_push_header: QER Found GTP-U Flg(52) GTPU-L(104) SkbLen(112) [17721.572542] [gtp5g] gtp5g_push_header: SKBLen(96) GTP-U V1(8) Opt(4) DL_PDU(4) [17721.572582] [gtp5g] gtp5g_push_header: QER Found GTP-U Flg(52) GTPU-L(104) SkbLen(112) [17722.575643] [gtp5g] gtp5g_push_header: SKBLen(96) GTP-U V1(8) Opt(4) DL_PDU(4) [17722.575682] [gtp5g] gtp5g_push_header: QER Found GTP-U Flg(52) GTPU-L(104) SkbLen(112) [17723.577768] [gtp5g] gtp5g_push_header: SKBLen(96) GTP-U V1(8) Opt(4) DL_PDU(4) [17723.577807] [gtp5g] gtp5g_push_header: QER Found GTP-U Flg(52) GTPU-L(104) SkbLen(112) [17724.583670] [gtp5g] gtp5g_push_header: SKBLen(96) GTP-U V1(8) Opt(4) DL_PDU(4) [17724.583710] [gtp5g] gtp5g_push_header: QER Found GTP-U Flg(52) GTPU-L(104) SkbLen(112) [17725.587667] [gtp5g] gtp5g_push_header: SKBLen(96) GTP-U V1(8) Opt(4) DL_PDU(4) [17725.587702] [gtp5g] gtp5g_push_header: QER Found GTP-U Flg(52) GTPU-L(104) SkbLen(112) [17726.588575] [gtp5g] gtp5g_push_header: SKBLen(96) GTP-U V1(8) Opt(4) DL_PDU(4) [17726.588609] [gtp5g] gtp5g_push_header: QER Found GTP-U Flg(52) GTPU-L(104) SkbLen(112) [17727.590440] [gtp5g] gtp5g_push_header: SKBLen(96) GTP-U V1(8) Opt(4) DL_PDU(4) [17727.590475] [gtp5g] gtp5g_push_header: QER Found GTP-U Flg(52) GTPU-L(104) SkbLen(112) [17728.593841] [gtp5g] gtp5g_push_header: SKBLen(96) GTP-U V1(8) Opt(4) DL_PDU(4) [17728.593875] [gtp5g] gtp5g_push_header: QER Found GTP-U Flg(52) GTPU-L(104) SkbLen(112) [17729.600427] [gtp5g] gtp5g_push_header: SKBLen(96) GTP-U V1(8) Opt(4) DL_PDU(4) [17729.600460] [gtp5g] gtp5g_push_header: QER Found GTP-U Flg(52) GTPU-L(104) SkbLen(112) [17730.601667] [gtp5g] gtp5g_push_header: SKBLen(96) GTP-U V1(8) Opt(4) DL_PDU(4) [17730.601699] [gtp5g] gtp5g_push_header: QER Found GTP-U Flg(52) GTPU-L(104) SkbLen(112) [17731.609459] [gtp5g] gtp5g_push_header: SKBLen(96) GTP-U V1(8) Opt(4) DL_PDU(4) [17731.609492] [gtp5g] gtp5g_push_header: QER Found GTP-U Flg(52) GTPU-L(104) SkbLen(112) [17732.611875] [gtp5g] gtp5g_push_header: SKBLen(96) GTP-U V1(8) Opt(4) DL_PDU(4) [17732.611927] [gtp5g] gtp5g_push_header: QER Found GTP-U Flg(52) GTPU-L(104) SkbLen(112) [17733.614442] [gtp5g] gtp5g_push_header: SKBLen(96) GTP-U V1(8) Opt(4) DL_PDU(4) [17733.614475] [gtp5g] gtp5g_push_header: QER Found GTP-U Flg(52) GTPU-L(104) SkbLen(112) [17734.617437] [gtp5g] gtp5g_push_header: SKBLen(96) GTP-U V1(8) Opt(4) DL_PDU(4) [17734.617471] [gtp5g] gtp5g_push_header: QER Found GTP-U Flg(52) GTPU-L(104) SkbLen(112) [17735.619439] [gtp5g] gtp5g_push_header: SKBLen(96) GTP-U V1(8) Opt(4) DL_PDU(4) [17735.619473] [gtp5g] gtp5g_push_header: QER Found GTP-U Flg(52) GTPU-L(104) SkbLen(112) [17736.620607] [gtp5g] gtp5g_push_header: SKBLen(96) GTP-U V1(8) Opt(4) DL_PDU(4) [17736.620640] [gtp5g] gtp5g_push_header: QER Found GTP-U Flg(52) GTPU-L(104) SkbLen(112) [17737.623118] [gtp5g] gtp5g_push_header: SKBLen(96) GTP-U V1(8) Opt(4) DL_PDU(4) [17737.623152] [gtp5g] gtp5g_push_header: QER Found GTP-U Flg(52) GTPU-L(104) SkbLen(112) [17738.625249] [gtp5g] gtp5g_push_header: SKBLen(96) GTP-U V1(8) Opt(4) DL_PDU(4) [17738.625255] [gtp5g] gtp5g_push_header: QER Found GTP-U Flg(52) GTPU-L(104) SkbLen(112) [17739.627779] [gtp5g] gtp5g_push_header: SKBLen(96) GTP-U V1(8) Opt(4) DL_PDU(4) [17739.627833] [gtp5g] gtp5g_push_header: QER Found GTP-U Flg(52) GTPU-L(104) SkbLen(112) [17740.630114] [gtp5g] gtp5g_push_header: SKBLen(96) GTP-U V1(8) Opt(4) DL_PDU(4) [17740.630147] [gtp5g] gtp5g_push_header: QER Found GTP-U Flg(52) GTPU-L(104) SkbLen(112) And the DL gtp pkt has included QFI now, but the same problem still occurr. new_gtp_log.zip

muthuramanecs03g commented 3 years ago

Hi @mmadnac1313,

You mean there is a problem with the following print

[17740.630114] [gtp5g] gtp5g_push_header: SKBLen(96) GTP-U V1(8) Opt(4) DL_PDU(4)

[17740.630147] [gtp5g] gtp5g_push_header: QER Found GTP-U Flg(52) GTPU-L(104) SkbLen(112)

GTPU-L -> denotes the GTP-u payload length SkbLen -> denotes the total length (GTP-U Header + Payload)

I randomly picked the packet trace flow of Uplink and Downlink from new_gtp_log.zip. For example, frame from 271 to 276.

You can compare the prints like what do you mentioned here with wireshark trace.
Screen Shot 2021-06-28 at 1 48 01 AM

mmadnac1313 commented 3 years ago

NO, I mean the payload size of ping reply didn't match that of ping request. Ping Reply Ping Request

muthuramanecs03g commented 3 years ago

As per your Wireshark trace, there is no loss happened while the gtp5g kernel processing the downlink packet.

You have to troubleshoot the N6 interface downlink reply, and so on.

This issue is not related to the gtp5g kernel module.

mmadnac1313 commented 3 years ago

Thank you for your reply! Should I copy this issue to the corresponding git repo of N6 interface?

muthuramanecs03g commented 3 years ago

Hi @mmadnac1313 ,

No, there is no separate repo of the N6 interface.

I mean, you have to troubleshoot yourself because we didn't encounter this problem. You have to analyze like,

1) Without free5GC, if you ping to 8.8.8.8 with 256B or more payload then what is the ping reply.

and so on.

muthuramanecs03g commented 3 years ago

Hi @mmadnac1313 ,

Now, we created a repo under free5gc, and you can report upcoming issues

https://github.com/free5gc/gtp5g

muthuramanecs03g commented 3 years ago

Hi @mmadnac1313,

We have one more fix in gtp5g which may relate to your problem.

Please, verify it and let me know.

mmadnac1313 commented 3 years ago

Hi @mmadnac1313,

We have one more fix in gtp5g which may relate to your problem.

Please, verify it and let me know. As attachment, it still doesn't work. gtp.zip The ping request include 1000 bytes payload, but the ping reply only include 68 bytes payload. The ping reply should also include 1000bytes payload!

free5gc-org commented 3 years ago

@mmadnac1313

There may be some backward compatible issue between gtp5g and free5gc. If you get and install the latest gtp5g, please also get the latest free5gc to test:

git clone https://github.com/free5gc/gtp5g.git
cd gtp5g
make
sudo make install
    cd ~/free5gc
    git checkout main
    git submodule sync
    git submodule update --init --jobs `nproc`
    git submodule foreach git checkout main
    git submodule foreach git pull --jobs `nproc`
    make