search

edgecomllc / eupf

5G User Plane Function (UPF) based on eBPF
Apache License 2.0
100 stars 20 forks source link

tracepipe logs are different from the one in the repo #443

Closed Satyam-git-hub closed 7 months ago

Satyam-git-hub commented 11 months ago

image My tracepipe logs are very different from the one's shared in this repo image and also only the upf_ip_entrypoint function is attached to the xdp hook of the eupf container The other three programs never trigger as they are not attached to any hook

And also here is my eupf container logs if u need image

PapaySail commented 11 months ago

@Satyam-git-hub Hello! As I can see, you trying to use docker-compose deploy. You have session established from ueransim. I will continue investigation. Additionally, please try to ping some local node address from ueransim, i.e. ping -I uesimtun0 10.100.250.2 -c1

only the upf_ip_entrypoint function is attached to the xdp hook of the eupf container

The question I redirect to @pirog-spb, can you check it?

pirog-spb commented 11 months ago

Hi @Satyam-git-hub

I actually didn't get what's the difference in logs. Could you please clarify?

and also only the upf_ip_entrypoint function is attached to the xdp hook of the eupf container The other three programs never trigger as they are not attached to any hook

upf_ip_entrypoint is the only ebpf program that is attached to network interfaces at the moment. The rest programs are just stubs. You may ignore them without any doubts.

PapaySail commented 11 months ago

@Satyam-git-hub , from your log I see inconsistency in routing.

  1. Please, check that the nat container is running: sudo docker ps |grep nat
Satyam-git-hub commented 11 months ago

@PapaySail

sudo docker ps |grep nat

image

nat logs are empty image Is it the desired output of the logs for nat?

Satyam-git-hub commented 11 months ago

@PapaySail

@Satyam-git-hub Hello! As I can see, you trying to use docker-compose deploy. You have session established from ueransim. I will continue investigation. Additionally, please try to ping some local node address from ueransim, i.e. ping -I uesimtun0 10.100.250.2 -c1

I am able to ping local nodes image

PapaySail commented 11 months ago

I am able to ping local nodes

Great! Seems your eupf itself working well. The issue might be in routing. Check it from eupf container shell. It should looks like this:

sudo docker exec -ti eupf sh
/ # ip route s table n6if
default via 10.100.250.2 dev eth1

/ # ping 10.100.250.2
PING 10.100.250.2 (10.100.250.2): 56 data bytes
64 bytes from 10.100.250.2: seq=0 ttl=64 time=0.332 ms
64 bytes from 10.100.250.2: seq=1 ttl=64 time=0.223 ms
^C
--- 10.100.250.2 ping statistics ---
2 packets transmitted, 2 packets received, 0% packet loss
round-trip min/avg/max = 0.223/0.277/0.332 ms
Satyam-git-hub commented 11 months ago

@PapaySail

I am able to ping local nodes

Great! Seems your eupf itself working well. The issue might be in routing. Check it from eupf container shell. It should looks like this:

sudo docker exec -ti eupf sh
/ # ip route s table n6if
default via 10.100.250.2 dev eth1

/ # ping 10.100.250.2
PING 10.100.250.2 (10.100.250.2): 56 data bytes
64 bytes from 10.100.250.2: seq=0 ttl=64 time=0.332 ms
64 bytes from 10.100.250.2: seq=1 ttl=64 time=0.223 ms
^C
--- 10.100.250.2 ping statistics ---
2 packets transmitted, 2 packets received, 0% packet loss
round-trip min/avg/max = 0.223/0.277/0.332 ms

image

Yes its the same

Satyam-git-hub commented 11 months ago

Hi @pirog-spb

Hi @Satyam-git-hub

I actually didn't get what's the difference in logs. Could you please clarify?

The logs i get on the tracepipe only show FIB lookup and the ones in install.md are very detail and show 

sergo@edgecom:~$ sudo cat /sys/kernel/debug/tracing/trace_pipe

          nr-gnb-4117277 [003] d.s11 266111.395788: bpf_trace_printk: upf: gtp-u received
          nr-gnb-4117277 [003] d.s11 266111.395819: bpf_trace_printk: upf: gtp pdu [ 10.100.50.236 -> 10.100.50.233 ]
          nr-gnb-4117277 [003] d.s11 266111.395825: bpf_trace_printk: upf: uplink session for teid:1 far:1 headrm:0
          nr-gnb-4117277 [003] d.s11 266111.395828: bpf_trace_printk: upf: far:1 action:2 outer_header_creation:0
          nr-gnb-4117277 [003] d.s11 266111.395831: bpf_trace_printk: upf: qer:1 gate_status:0 mbr:200000000
          nr-gnb-4117277 [003] d.s11 266111.395857: bpf_trace_printk: upf: bpf_fib_lookup 10.1.0.1 -> 1.1.1.1: nexthop: 10.100.100.1
          nr-gnb-4117277 [003] d.s11 266111.395861: bpf_trace_printk: upf: bpf_redirect: if=6 18446669071770913972 -> 18446669071770913978
          <idle>-0       [007] d.s.1 266111.396975: bpf_trace_printk: upf: downlink session for ip:10.1.0.1  far:2 action:2
          <idle>-0       [007] dNs.1 266111.396983: bpf_trace_printk: upf: qer:0 gate_status:0 mbr:0
          <idle>-0       [007] dNs.1 266111.396985: bpf_trace_printk: upf: use mapping 10.1.0.1 -> TEID:1
          <idle>-0       [007] dNs.1 266111.396987: bpf_trace_printk: upf: send gtp pdu 10.100.50.233 -> 10.100.50.236
          <idle>-0       [007] dNs.1 266111.396996: bpf_trace_printk: upf: bpf_fib_lookup 10.100.50.233 -> 10.100.50.236: nexthop: 10.100.50.236
          <idle>-0       [007] dNs.1 266111.396998: bpf_trace_printk: upf: bpf_redirect: if=4 18446669071771765924 -> 18446669071771765930

every step in detail from gtp-u received to bpf_redirect whereas I am getting these logs

sudo cat /sys/kernel/debug/tracing/trace_pipe
          nr-gnb-936808  [006] d.s11 970987.824969: bpf_trace_printk: upf: bpf_fib_lookup 10.60.0.2 -> 142.250.207.206: nexthop: 10.100.250.2
          <idle>-0       [009] d.s.1 970987.828803: bpf_trace_printk: upf: bpf_fib_lookup 10.100.200.14 -> 10.100.200.16: nexthop: 10.100.200.16
PapaySail commented 11 months ago

@Satyam-git-hub please check if the solution from issue https://github.com/edgecomllc/eupf/issues/410#issuecomment-1722501418 will help. TLDR just run commands at the node:

sudo kubectl delete -f https://raw.githubusercontent.com/kubernetes-sigs/ip-masq-agent/master/ip-masq-agent.yaml
sudo iptables -t nat -D IP-MASQ-AGENT -m comment --comment "ip-masq-agent: outbound traffic is subject to MASQUERADE (must be last in chain)" -j MASQUERADE

And check the result pinging from the UE container. (No need to restart anything.)

If it will not help, then open nat container shell and run tcpdump:

sudo docker exec -ti nat sh
/app # apk add tcpdump
/app # tcpdump -ni eth0

next switch to ueransim at another terminal and run ping -I uesimtun0 1.1.1.1 -c1 The normal output of tcpdump should look like these:

tcpdump: verbose output suppressed, use -v[v]... for full protocol decode
listening on eth0, link-type EN10MB (Ethernet), snapshot length 262144 bytes
16:22:36.289768 ARP, Request who-has 10.100.200.14 tell 10.100.200.16, length 28
16:22:36.290084 ARP, Request who-has 10.100.200.1 tell 10.100.200.2, length 28
16:22:36.290115 ARP, Reply 10.100.200.1 is-at 02:42:09:06:82:15, length 28
16:22:36.290135 IP 10.100.200.2 > 1.1.1.1: ICMP echo request, id 55235, seq 1, length 64
16:22:36.295951 IP 1.1.1.1 > 10.100.200.2: ICMP echo reply, id 55235, seq 1, length 64
Satyam-git-hub commented 11 months ago

@PapaySail

If it will not help, then open nat container shell and run tcpdump:

sudo docker exec -ti nat sh
/app # apk add tcpdump
/app # tcpdump -ni eth0

next switch to ueransim at another terminal and run ping -I uesimtun0 1.1.1.1 -c1 The normal output of tcpdump should look like these:

tcpdump: verbose output suppressed, use -v[v]... for full protocol decode
listening on eth0, link-type EN10MB (Ethernet), snapshot length 262144 bytes
16:22:36.289768 ARP, Request who-has 10.100.200.14 tell 10.100.200.16, length 28
16:22:36.290084 ARP, Request who-has 10.100.200.1 tell 10.100.200.2, length 28
16:22:36.290115 ARP, Reply 10.100.200.1 is-at 02:42:09:06:82:15, length 28
16:22:36.290135 IP 10.100.200.2 > 1.1.1.1: ICMP echo request, id 55235, seq 1, length 64
16:22:36.295951 IP 1.1.1.1 > 10.100.200.2: ICMP echo reply, id 55235, seq 1, length 64

I am get this output for tcpdump

tcpdump -ni eth0
tcpdump: verbose output suppressed, use -v[v]... for full protocol decode
listening on eth0, link-type EN10MB (Ethernet), snapshot length 262144 bytes
06:39:28.615909 IP 10.100.200.6 > 1.1.1.1: ICMP echo request, id 48, seq 1, length 64
06:39:28.640999 IP 1.1.1.1 > 10.100.200.6: ICMP echo reply, id 48, seq 1, length 64
06:39:33.689351 ARP, Request who-has 10.100.200.1 tell 10.100.200.6, length 28
06:39:33.689409 ARP, Reply 10.100.200.1 is-at 02:42:57:85:b5:b5, length 28
06:39:33.689380 ARP, Request who-has 10.100.200.6 tell 10.100.200.1, length 28
06:39:33.689425 ARP, Reply 10.100.200.6 is-at 02:42:0a:64:c8:06, length 28
PapaySail commented 11 months ago

IP 1.1.1.1 > 10.100.200.6: ICMP echo reply, id 48, seq 1, length 64

Looks good. ICMP reqest was NATed correctly and responce received. Uplink is working, It should work in downlink too.

I just cloned repo https://github.com/edgecomllc/free5gc-compose.git, started sudo docker-compose up -d successfully.

sudo cat /sys/kernel/debug/tracing/trace_pipe
          nr-gnb-1242258 [000] d.s11 2494114.286826: bpf_trace_printk: upf: bpf_fib_lookup 10.60.0.1 -> 1.1.1.1: 7
      prometheus-3616918 [005] d.s.1 2494114.293136: bpf_trace_printk: upf: bpf_fib_lookup 10.100.200.14 -> 10.100.200.17: nexthop: 10.100.200.17

I would recommend you to undeploy all sudo docker-compose down, clone repo and start from scrutch.

pirog-spb commented 7 months ago

No any updates for far. Feel free to reopen if needed