feat: UP initiated association setup/release #497

kade-ddnkv · 2023-11-27T17:47:30Z

No description provided.

kade-ddnkv · 2023-11-27T18:04:27Z

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 · 2023-11-28T17:56:38Z

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 · 2023-11-28T17:57:35Z

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 · 2023-11-28T18:55:20Z

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

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.
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 · 2023-11-28T19:08:51Z

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 · 2023-11-28T19:13:54Z

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 · 2023-12-02T21:12:00Z

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:

How to get smf address dynamically (on start)? Through pode dns service?

kade-ddnkv · 2023-12-07T14:45:23Z

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 · 2023-12-09T19:47:40Z

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.

…initiated-association-setup-release

kade-ddnkv added 2 commits November 27, 2023 17:52

try 1

c378051

try 2

43696cd

kade-ddnkv linked an issue Nov 27, 2023 that may be closed by this pull request

UP initiated association setup #78

Open

assoc setup response parsing

14584cf

kade-ddnkv added 2 commits November 28, 2023 22:34

sequence id incrementing (only inside setup requests)

22e872f

safe request and response handling

08c6a3c

some edits

337f27a

preventive error fix

9946e73

kade-ddnkv mentioned this pull request Dec 9, 2023

UP initiated association setup #78

Open

Merge branch 'main' of https://github.com/edgecomllc/eupf into 78-up-…

1b05cb7

…initiated-association-setup-release

kade-ddnkv marked this pull request as ready for review December 19, 2023 01:45

kade-ddnkv requested a review from pirog-spb December 19, 2023 01:45

kade-ddnkv and others added 4 commits December 20, 2023 14:27

configuration

3ebfc7a

Merge branch 'main' of https://github.com/edgecomllc/eupf into 78-up-…

819978b

…initiated-association-setup-release

delete debug msg

7175091

Merge branch 'main' into 78-up-initiated-association-setup-release

5e6d6a8

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

feat: UP initiated association setup/release #497

feat: UP initiated association setup/release #497

kade-ddnkv commented Nov 27, 2023

kade-ddnkv commented Nov 27, 2023

kade-ddnkv commented Nov 28, 2023 •

edited

kade-ddnkv commented Nov 28, 2023 •

edited

kade-ddnkv commented Nov 28, 2023

kade-ddnkv commented Nov 28, 2023

kade-ddnkv commented Nov 28, 2023 •

edited

kade-ddnkv commented Dec 2, 2023

kade-ddnkv commented Dec 7, 2023

kade-ddnkv commented Dec 9, 2023

feat: UP initiated association setup/release #497

Are you sure you want to change the base?

feat: UP initiated association setup/release #497

Conversation

kade-ddnkv commented Nov 27, 2023

kade-ddnkv commented Nov 27, 2023

kade-ddnkv commented Nov 28, 2023 • edited

kade-ddnkv commented Nov 28, 2023 • edited

kade-ddnkv commented Nov 28, 2023

kade-ddnkv commented Nov 28, 2023

kade-ddnkv commented Nov 28, 2023 • edited

kade-ddnkv commented Dec 2, 2023

kade-ddnkv commented Dec 7, 2023

kade-ddnkv commented Dec 9, 2023

kade-ddnkv commented Nov 28, 2023 •

edited

kade-ddnkv commented Nov 28, 2023 •

edited

kade-ddnkv commented Nov 28, 2023 •

edited