edgecomllc / eupf

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

Can't delete PDR with v0.6.0 #527

Closed Sabreu closed 4 months ago

Sabreu commented 5 months ago

Updated eupf to v0.6.0 and got this kind of issue. There are two "Put PDR uplink: teid=359, can same teid be used for two?

Open5gs smf says the following: [smf] ERROR: No PFCP session deletion response[6]

2024/01/10 14:04:18 DBG EBPF: Put PDR Downlink: ipv4=10.25.0.3, pdrInfo={OuterHeaderRemoval:0 FarId:0 QerId:0 SdfFilter:<nil>}
2024/01/10 14:04:18 DBG EBPF: Put PDR Uplink: teid=359, pdrInfo={OuterHeaderRemoval:0 FarId:1 QerId:0 SdfFilter:<nil>}
2024/01/10 14:04:18 DBG EBPF: Put PDR Uplink: teid=16507, pdrInfo={OuterHeaderRemoval:0 FarId:0 QerId:0 SdfFilter:<nil>}
2024/01/10 14:04:18 Matched groups: [permit out 58 from ff02::2/128 to assigned 58 ff02::2 128  assigned  ]
2024/01/10 14:04:18 DBG EBPF: Put PDR Uplink: teid=359, pdrInfo={OuterHeaderRemoval:0 FarId:2 QerId:0 SdfFilter:{Protocol:4 SrcAddress:{Type:2 Ip:ff02::2 Mask:ffffffffffffffffffffffffffffffff} SrcPortRange:{LowerBound:0 UpperBound:65535} DstAddress:{Type:0 Ip:<nil> Mask:<nil>} DstPortRange:{LowerBound:0 UpperBound:65535}}}
2024/01/10 14:04:18 INF Session Establishment Request from 10.10.1.3 accepted.
2024/01/10 14:04:18 DBG Received 70 bytes from 10.10.1.3:8805
2024/01/10 14:04:18 DBG Handling PFCP message from 10.10.1.3:8805
2024/01/10 14:04:18 INF Got Session Modification Request from: 10.10.1.3.
2024/01/10 14:04:18 INF Finding association for 10.10.1.3
2024/01/10 14:04:18 INF Finding session 2
2024/01/10 14:04:18 INF
Session Modification Request:
  UpdateFAR ID: 1
    Apply Action: [2 0]
    Update forwarding Parameters:
[33B blob data]
      Outer Header Creation: &{OuterHeaderCreationDescription:256 TEID:3286499618 IPv4Address:10.10.10.41 IPv6Address:<nil> PortNumber:0 CTag:0 STag:0}
2024/01/10 14:04:18 INF Updating FAR info: 1, {FarInfo:{Action:2 OuterHeaderCreation:1 Teid:3286499618 RemoteIP:688523786 LocalIP:17041930 TransportLevelMarking:0} GlobalId:0}
2024/01/10 14:04:18 DBG EBPF: Update FAR: internalId=0, farInfo={Action:2 OuterHeaderCreation:1 Teid:3286499618 RemoteIP:688523786 LocalIP:17041930 TransportLevelMarking:0}
[GIN] 2024/01/10 - 14:04:19 | 200 |    3.168907ms |       10.10.5.1 | GET      "/metrics"
2024/01/10 14:04:20 DBG Received 16 bytes from 10.10.1.3:8805
2024/01/10 14:04:20 DBG Handling PFCP message from 10.10.1.3:8805
2024/01/10 14:04:20 DBG Got Heartbeat Request with TS: 2024-01-10 14:00:49 +0200 EET, from: 10.10.1.3
2024/01/10 14:04:20 DBG Sent Heartbeat Response to: 10.10.1.3
2024/01/10 14:04:21 DBG Sent Heartbeat Request to: 10.10.1.3
2024/01/10 14:04:21 DBG Received 16 bytes from 10.10.1.3:8805
2024/01/10 14:04:21 DBG Handling PFCP message from 10.10.1.3:8805
2024/01/10 14:04:21 DBG Got Heartbeat Response with TS: 2024-01-10 14:00:49 +0200 EET, from: 10.10.1.3
2024/01/10 14:04:27 DBG Received 16 bytes from 10.10.1.3:8805
2024/01/10 14:04:27 DBG Handling PFCP message from 10.10.1.3:8805
2024/01/10 14:04:27 INF Got Session Deletion Request from: 10.10.1.3.
2024/01/10 14:04:27 DBG EBPF: Delete PDR Uplink: teid=359
2024/01/10 14:04:27 DBG EBPF: Delete PDR Downlink: ipv4=10.25.0.3
2024/01/10 14:04:27 DBG EBPF: Delete PDR Uplink: teid=359
2024/01/10 14:04:27 WRN Error handling PFCP message: Can't delete GTP PDR: delete: key does not exist
2024/01/10 14:04:27 WRN Error handling PFCP message: Can't delete GTP PDR: delete: key does not exist
[GIN] 2024/01/10 - 14:04:29 | 200 |    4.845805ms |       10.10.5.1 | GET      "/metrics"
2024/01/10 14:04:30 DBG Received 16 bytes from 10.10.1.3:8805
2024/01/10 14:04:30 DBG Handling PFCP message from 10.10.1.3:8805
2024/01/10 14:04:30 INF Got Session Deletion Request from: 10.10.1.3.
2024/01/10 14:04:30 DBG EBPF: Delete PDR Uplink: teid=359
2024/01/10 14:04:30 WRN Error handling PFCP message: Can't delete GTP PDR: delete: key does not exist
2024/01/10 14:04:30 WRN Error handling PFCP message: Can't delete GTP PDR: delete: key does not exist
2024/01/10 14:04:31 DBG Received 16 bytes from 10.10.1.3:8805
2024/01/10 14:04:31 DBG Handling PFCP message from 10.10.1.3:8805
2024/01/10 14:04:31 DBG Got Heartbeat Request with TS: 2024-01-10 14:00:49 +0200 EET, from: 10.10.1.3
2024/01/10 14:04:31 DBG Sent Heartbeat Response to: 10.10.1.3
2024/01/10 14:04:31 DBG Sent Heartbeat Request to: 10.10.1.3
2024/01/10 14:04:31 DBG Received 16 bytes from 10.10.1.3:8805
2024/01/10 14:04:31 DBG Handling PFCP message from 10.10.1.3:8805
2024/01/10 14:04:31 DBG Got Heartbeat Response with TS: 2024-01-10 14:00:49 +0200 EET, from: 10.10.1.3
2024/01/10 14:04:32 DBG Received 16 bytes from 10.10.1.3:8805
2024/01/10 14:04:32 DBG Handling PFCP message from 10.10.1.3:8805
2024/01/10 14:04:32 INF Got Session Deletion Request from: 10.10.1.3.
2024/01/10 14:04:32 DBG EBPF: Delete PDR Downlink: ipv4=10.25.0.3
2024/01/10 14:04:32 WRN Error handling PFCP message: Can't delete IPv4 PDR: delete: key does not exist
2024/01/10 14:04:32 WRN Error handling PFCP message: Can't delete IPv4 PDR: delete: key does not exist
pirog-spb commented 5 months ago

Hi @Sabreu

There are two "Put PDR uplink: teid=359, can same teid be used for two?

Yes, it's possible. In your case two PDRs were installed with the same TEID both. First for the whole GTP tunnel by TEID. Second - for a part of traffic of tunnel with specified TEID and matched by SDF Filter.

But there is a bug in deletion procedure for this case...

Going to fix it ASAP. Thanks for highlighting that

Sabreu commented 5 months ago

Hi @pirog-spb

Also having this kind of issue after running eUPF for a while. eUPF will reject session establishment requests.

2024/01/18 09:11:20 INF Saving FAR info to session: 1, {Action:12 OuterHeaderCreation:0 Teid:0 RemoteIP:0 LocalIP:17044490 TransportLevelMarking:0}
2024/01/18 09:11:20 INF Can't put FAR: pool is empty
2024/01/18 09:11:20 INF Rejecting Session Establishment Request from: pool is empty (error in applying IEs)
Sabreu commented 4 months ago

seems like these issues not visible with v0.6.1, so closing this one