search

edgecomllc / eupf

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

feat: UP initiated association setup/release #497

Open kade-ddnkv opened 7 months ago

kade-ddnkv commented 7 months ago

Sending and receiving Association Setup

2023/11/27 17:41:57 DBG Sent Association Setup Request to: 10.100.200.10
2023/11/27 17:41:57 DBG Received 47 bytes from 10.100.200.10:8805
2023/11/27 17:41:57 DBG Handling PFCP message from 10.100.200.10:8805
2023/11/27 17:41:57 INF Got Association Setup Response from: 10.100.200.10.
kade-ddnkv commented 7 months ago

Wrong behaviour: SMF is saying that second PFCP Association Setup Request from UPF has the same sequence ID (1), that was in the first request. Or it SMF sending transactions with the same sequence id (1) by itself? Trying to figure it out.

Aha. SMF it sending response with static SequenceNumber == 1

Logs: SMF:

2023-11-28T17:42:40.503565574Z [INFO][SMF][Main] Sending PFCP Association Request to UPF[upf.free5gc.org](10.100.200.14)
2023-11-28T17:42:44.126159664Z [INFO][SMF][PFCP] Handle PFCP Association Setup Request with NodeID[10.100.200.14]
2023-11-28T17:42:49.115146407Z [INFO][SMF][PFCP] Handle PFCP Association Setup Request with NodeID[10.100.200.14]
2023-11-28T17:42:49Z [WARN][LIB][PFCP] In PutTransaction
2023-11-28T17:42:49Z [WARN][LIB][PFCP] Consumer Addr:  10.100.200.14:8805
2023-11-28T17:42:49Z [WARN][LIB][PFCP] Sequence number  1  already exist!
2023-11-28T17:42:49Z [WARN][LIB][PFCP] PutTransaction error: Insert tx error: duplicate sequence number 1
2023-11-28T17:42:49.514670205Z [WARN][SMF][Main] Failed to setup an association with UPF[upf.free5gc.org](10.100.200.14), error:Request Transaction [1]: retry-out
2023-11-28T17:42:49.514720970Z [INFO][SMF][Main] Sending PFCP Association Request to UPF[upf.free5gc.org](10.100.200.14)

UPF:

2023/11/28 17:42:40 DBG Received 42 bytes from 10.100.200.12:8805
2023/11/28 17:42:40 DBG Handling PFCP message from 10.100.200.12:8805
2023/11/28 17:42:40 INF Got Association Setup Request from: 10.100.200.12
2023/11/28 17:42:43 DBG Received 42 bytes from 10.100.200.12:8805
2023/11/28 17:42:43 DBG Handling PFCP message from 10.100.200.12:8805
2023/11/28 17:42:43 INF Got Association Setup Request from: 10.100.200.12
2023/11/28 17:42:44 DBG Sequence ID: 1
2023/11/28 17:42:44 INF Sent Association Setup Request to: 10.100.200.12
2023/11/28 17:42:44 DBG Received 47 bytes from 10.100.200.12:8805
2023/11/28 17:42:44 DBG Handling PFCP message from 10.100.200.12:8805
2023/11/28 17:42:44 INF Got Association Setup Response from: 10.100.200.12
2023/11/28 17:42:44 INF Got Association Setup Response with CPFunctionFeatures from: 10.100.200.12. CPFunctionFeatures: 0
2023/11/28 17:42:44 INF Saving new association: &{ID:smf.free5gc.org Addr:10.100.200.12 NextSessionID:1 NextSequenceID:1 Sessions:map[] HeartbeatRetries:0 cancelRetries:<nil>}
2023/11/28 17:42:46 DBG Received 42 bytes from 10.100.200.12:8805
2023/11/28 17:42:46 DBG Handling PFCP message from 10.100.200.12:8805
2023/11/28 17:42:46 INF Got Association Setup Request from: 10.100.200.12
2023/11/28 17:42:49 DBG Stop sending Association Setup Request to 10.100.200.12
2023/11/28 17:42:49 DBG Sequence ID: 2
2023/11/28 17:42:49 INF Sent Association Setup Request to: 10.100.200.12
2023/11/28 17:42:49 DBG Received 42 bytes from 10.100.200.12:8805
2023/11/28 17:42:49 DBG Handling PFCP message from 10.100.200.12:8805
2023/11/28 17:42:49 INF Got Association Setup Request from: 10.100.200.12
2023/11/28 17:42:52 DBG Received 42 bytes from 10.100.200.12:8805
2023/11/28 17:42:52 DBG Handling PFCP message from 10.100.200.12:8805
2023/11/28 17:42:52 INF Got Association Setup Request from: 10.100.200.12
kade-ddnkv commented 7 months ago

Undefined behaviour: Situation: SMF got request from UPF and sent response, association was successfully established, heartbeats are working. However, SMF keeps sending requests to UPF. The specification says:

If the PFCP Association Setup Request contains a Node ID for which a PFCP association was already established, the UP function shall:

  • proceed with establishing the new PFCP association (regardless of the Recovery Timestamp received in the request), overwriting the existing association;
kade-ddnkv commented 7 months ago

Intermediate result: free5gc supports PFCP Association Setup Request, but in a "strange, incomplete" way. What I mean:

  1. free5gc SMF can receive an association setup request only from UPFs, which were already set in his configuration. I don't know if it ok or not.
  2. If you take a look at SMF HandlePfcpAssociationSetupRequest function (link), you can see, that after receiving request from UPF, it only sets UPIPInfo field for selected UPF. The association (field upf.UPFStatus, that can take values like NotAssociated, AssociatedSetUpSuccess) is not actually set. Oppositely, the function setupPfcpAssociation (link), which is sending PFCP Association Setup Request from SMF to UPF, actually sets association.
kade-ddnkv commented 7 months ago

open5gs looks like it can set association both from request and response. At least, functions ogs_pfcp_cp_handle_association_setup_request and ogs_pfcp_cp_handle_association_setup_response looks almost the same, and I assume that line ogs_gtpu_resource_add(&node->gtpu_resource_list, &info); is adding an association.

kade-ddnkv commented 7 months ago

Intermediate results:

Association Setup Procedure free5gc: incomplete support open5gs: supports (haven't checked yet)

Association Release Procedure At first sight. free5gc: supports open5gs: doesn't support

kade-ddnkv commented 7 months ago

Progress for now: being able to connect to open5gs smf, if set eupf config map like this:

interface_name: eth0
api_address: :8080
pfcp_address: :8805
metrics_address: :9090
pfcp_node: 
  - 10.244.0.16

eupf logs:

2023/12/02 21:09:37 INF Sent Association Setup Request to: 10.244.0.16
2023/12/02 21:09:37 DBG Received 35 bytes from 10.244.0.16:8805
2023/12/02 21:09:37 DBG Handling PFCP message from 10.244.0.16:8805
2023/12/02 21:09:37 INF Got Association Setup Response from: 10.244.0.16
2023/12/02 21:09:37 INF Got Association Setup Response with CPFunctionFeatures from: 10.244.0.16. CPFunctionFeatures: 0
2023/12/02 21:09:37 INF Saving new association: &{ID:10.244.0.16 Addr:10.244.0.16 NextSessionID:1 NextSequenceID:1 Sessions:map[] HeartbeatRetries:0 cancelRetries:<nil>}
2023/12/02 21:09:42 DBG Sequence ID: 2
2023/12/02 21:09:42 INF Sent Association Setup Request to: 10.244.0.16
2023/12/02 21:09:42 DBG Stop sending Association Setup Request to 10.244.0.16
2023/12/02 21:09:42 DBG Received 35 bytes from 10.244.0.16:8805
2023/12/02 21:09:42 DBG Handling PFCP message from 10.244.0.16:8805
2023/12/02 21:09:42 INF Got Association Setup Response from: 10.244.0.16
2023/12/02 21:09:42 INF Got Association Setup Response with CPFunctionFeatures from: 10.244.0.16. CPFunctionFeatures: 0
2023/12/02 21:09:42 WRN Association with NodeID: 10.244.0.16 and address: 10.244.0.16 already exists
2023/12/02 21:09:42 WRN Session retention is not yet implemented
2023/12/02 21:09:42 INF Saving new association: &{ID:10.244.0.16 Addr:10.244.0.16 NextSessionID:1 NextSequenceID:1 Sessions:map[] HeartbeatRetries:0 cancelRetries:<nil>}
2023/12/02 21:09:47 DBG Sent Heartbeat Request to: 10.244.0.16
2023/12/02 21:09:48 DBG Received 16 bytes from 10.244.0.16:8805
2023/12/02 21:09:48 DBG Handling PFCP message from 10.244.0.16:8805
2023/12/02 21:09:48 DBG Got Heartbeat Request with TS: 2023-12-02 21:00:46 +0000 UTC, from: 10.244.0.16

So: association is established by UPF initiative, heartbeats are working.

Questions left:

  1. How to get smf address dynamically (on start)? Through pode dns service?
kade-ddnkv commented 6 months ago

Magic happening:

Services (at least services with type ClusterIP) are working in local environment. If deploy with UPF version "main", everything works fine, services too. If deploy with my UPF version, services (SMF PFCP service and EUPF PFCP service) somewhy are not working.

tcpdump on both upf and smf show that request packets are sent to the corresponding services. But no response is received.

kade-ddnkv commented 6 months ago

Ok, now I have started in open5gs environment. Now I have another problem: the response from kubernetes service contains, well, service IP as sender address. Which means in UPF this association is stored as a different one.

For instance: SMF address: 10.233.78.95 SMF PFCP service address: 10.233.44.84

UPF logs:

2023/12/09 19:39:07 INF Saving new association: &{ID:10.233.78.95 Addr:10.233.44.84 NextSessionID:1 NextSequenceID:1 Sessions:map[] HeartbeatRetries:0 cancelRetries:<nil>}
2023/12/09 19:39:11 DBG Received 30 bytes from 10.233.78.95:8805
2023/12/09 19:39:11 DBG Handling PFCP message from 10.233.78.95:8805
2023/12/09 19:39:11 INF Got Association Setup Request from: 10.233.78.95
2023/12/09 19:39:11 INF 
Association Setup Request:
  Node ID: 10.233.78.95
  Recovery Time: 2023-12-08 08:08:57 +0000 UTC

2023/12/09 19:39:11 INF Saving new association: &{ID:10.233.78.95 Addr:10.233.78.95 NextSessionID:1 NextSequenceID:1 Sessions:map[] HeartbeatRetries:0 cancelRetries:<nil>}

Both associations are stored inside UPF, which is wrong.