Skip to content

Commit affe9f2

Browse files
author
Vinod Patmanathan
committed
Fix stale AMF CommunicationClient causing N1N2 transfer failures
After an AMF pod restart, SMF continues sending N1N2MessageTransfer to the old AMF pod IP, causing PDU Session Establishment to fail with T3580 expiry. This happens because: 1. CommunicationClient bakes in the AMF pod IP at session creation and is never refreshed. 2. CommunicationClient is not JSON-serializable, so it's nil after SMF recovers SMContext from MongoDB. 3. NRF accumulates stale NF registrations across pod restarts and the NRF cache (15min TTL) returns stale entries on re-discovery. 4. The HTTP client has no timeout, so TCP connect to a dead pod IP hangs for 60s+ — longer than the T3580 window. Fix: - Add SendN1N2TransferWithRediscovery() that wraps all N1N2 calls with a 5-second context timeout. On failure, it re-discovers the AMF by querying NRF directly (bypassing cache), prefers an AMF with a different NfInstanceId than the failed one, and retries. - Add RebuildCommunicationClient() on SMContext to reconstruct the HTTP client from the stored AMFProfile after DB recovery. - Replace all 5 direct CommunicationClient.N1N2MessageTransfer call sites with the retry wrapper. Verified on live cluster: after AMF pod kill, N1N2 transfer fails in 5s, re-discovers new AMF, retries successfully. Total recovery time 5.3 seconds vs permanent failure without the fix. Signed-off-by: Vinod Patmanathan <vinod.patmanathan@forsway.com>
1 parent 81ba3f8 commit affe9f2

9 files changed

Lines changed: 332 additions & 67 deletions

File tree

consumer/nf_management.go

Lines changed: 128 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -478,6 +478,134 @@ func SendNFDiscoveryServingAMF(smContext *smfContext.SMContext) (*models.Problem
478478
return nil, nil
479479
}
480480

481+
// n1n2TransferTimeout is the HTTP timeout for a single N1N2MessageTransfer attempt.
482+
// Kept short so that retries with AMF re-discovery can happen within the UE's T3580 window.
483+
const n1n2TransferTimeout = 5 * time.Second
484+
485+
// SendN1N2TransferWithRediscovery sends an N1N2MessageTransfer request using the
486+
// SMContext's CommunicationClient. If the request fails (including timeout), it
487+
// queries NRF directly (bypassing the cache) and tries every other AMF candidate
488+
// until one succeeds. This handles the case where NRF has multiple stale
489+
// registrations left behind by prior AMF pod restarts.
490+
func SendN1N2TransferWithRediscovery(ctx context.Context, smContext *smfContext.SMContext,
491+
n1n2Request models.N1N2MessageTransferRequest,
492+
) (*models.N1N2MessageTransferRspData, error) {
493+
if smContext.CommunicationClient == nil {
494+
// Client was never built (e.g. recovered from DB with stale AMFProfile).
495+
// Use the first candidate from NRF to seed it; if it fails, the retry loop below takes over.
496+
if err := selectFirstAmfFromNrf(smContext); err != nil {
497+
return nil, fmt.Errorf("AMF discovery failed: %w", err)
498+
}
499+
}
500+
501+
// First attempt with the currently-selected AMF
502+
rspData, err := tryN1N2Transfer(ctx, smContext, n1n2Request)
503+
if err == nil {
504+
return rspData, nil
505+
}
506+
firstErr := err
507+
smContext.SubPduSessLog.Warnf("N1N2Transfer failed (%v), attempting AMF re-discovery", err)
508+
509+
// First attempt failed — fetch all AMF candidates from NRF (bypassing cache)
510+
// and try each one that isn't the NfInstanceId we already failed on.
511+
candidates, discErr := fetchAmfCandidates()
512+
if discErr != nil {
513+
return nil, fmt.Errorf("N1N2Transfer failed (%w) and AMF re-discovery failed: %v", firstErr, discErr)
514+
}
515+
516+
attempted := 0
517+
for _, candidate := range selectableAmfCandidates(candidates, smContext.ServingNfId) {
518+
if err := useAmfProfile(smContext, candidate); err != nil {
519+
smContext.SubPduSessLog.Warnf("AMF candidate %s unusable: %v", candidate.NfInstanceId, err)
520+
continue
521+
}
522+
attempted++
523+
smContext.SubPduSessLog.Infof("AMF re-discovery retry %d: trying NfInstanceId %s", attempted, candidate.NfInstanceId)
524+
rspData, err = tryN1N2Transfer(ctx, smContext, n1n2Request)
525+
if err == nil {
526+
smContext.SubPduSessLog.Infof("AMF re-discovery succeeded on attempt %d with NfInstanceId %s", attempted, candidate.NfInstanceId)
527+
return rspData, nil
528+
}
529+
smContext.SubPduSessLog.Warnf("AMF re-discovery retry %d failed: %v", attempted, err)
530+
}
531+
532+
if attempted == 0 {
533+
return nil, fmt.Errorf("N1N2Transfer failed (%w) and no alternative AMF candidates available", firstErr)
534+
}
535+
return nil, fmt.Errorf("N1N2Transfer failed after %d AMF candidates; last error: %w", attempted, err)
536+
}
537+
538+
// tryN1N2Transfer makes a single N1N2MessageTransfer call with a short timeout.
539+
func tryN1N2Transfer(ctx context.Context, smContext *smfContext.SMContext,
540+
n1n2Request models.N1N2MessageTransferRequest,
541+
) (*models.N1N2MessageTransferRspData, error) {
542+
tryCtx, cancel := context.WithTimeout(ctx, n1n2TransferTimeout)
543+
defer cancel()
544+
apiReq := smContext.CommunicationClient.
545+
N1N2MessageCollectionCollectionAPI.
546+
N1N2MessageTransfer(tryCtx, smContext.Supi).
547+
N1N2MessageTransferReqData(n1n2Request.GetJsonData())
548+
if binaryDataN1Message := n1n2Request.GetBinaryDataN1Message(); binaryDataN1Message != nil {
549+
apiReq = apiReq.BinaryDataN1Message(binaryDataN1Message)
550+
}
551+
if binaryDataN2Information := n1n2Request.GetBinaryDataN2Information(); binaryDataN2Information != nil {
552+
apiReq = apiReq.BinaryDataN2Information(binaryDataN2Information)
553+
}
554+
rspData, _, err := smContext.CommunicationClient.
555+
N1N2MessageCollectionCollectionAPI.
556+
N1N2MessageTransferExecute(apiReq)
557+
return rspData, err
558+
}
559+
560+
// selectableAmfCandidates returns candidates whose NfInstanceId differs from failedNfId,
561+
// preserving order. Used to filter out the AMF profile that just failed an N1N2 transfer.
562+
func selectableAmfCandidates(candidates []models.NFProfileDiscovery, failedNfId string) []models.NFProfileDiscovery {
563+
out := make([]models.NFProfileDiscovery, 0, len(candidates))
564+
for _, c := range candidates {
565+
if c.NfInstanceId == failedNfId {
566+
continue
567+
}
568+
out = append(out, c)
569+
}
570+
return out
571+
}
572+
573+
// fetchAmfCandidates queries NRF directly (bypassing the cache) for all registered AMFs.
574+
func fetchAmfCandidates() ([]models.NFProfileDiscovery, error) {
575+
localVarOptionals := Nnrf_NFDiscovery.ApiSearchNFInstancesRequest{}
576+
ctx := context.Background()
577+
result, err := SendNrfForNfInstance(ctx, smfContext.SMF_Self().NrfUri, models.NFTYPE_AMF, models.NFTYPE_SMF, localVarOptionals)
578+
if err != nil {
579+
return nil, fmt.Errorf("broad AMF discovery failed: %w", err)
580+
}
581+
if result == nil || result.NfInstances == nil || len(result.NfInstances) == 0 {
582+
return nil, fmt.Errorf("broad AMF discovery returned no AMF instances")
583+
}
584+
return result.NfInstances, nil
585+
}
586+
587+
// useAmfProfile selects the given AMF profile on the SMContext and rebuilds the CommunicationClient.
588+
func useAmfProfile(smContext *smfContext.SMContext, profile models.NFProfileDiscovery) error {
589+
smContext.AMFProfile = deepcopy.Copy(profile).(models.NFProfileDiscovery)
590+
smContext.ServingNfId = smContext.AMFProfile.NfInstanceId
591+
smContext.RebuildCommunicationClient()
592+
if smContext.CommunicationClient == nil {
593+
return fmt.Errorf("AMF profile %s has no Namf_Communication service", profile.NfInstanceId)
594+
}
595+
return nil
596+
}
597+
598+
// selectFirstAmfFromNrf picks the first AMF from a direct NRF query and installs it on the SMContext.
599+
// Used only to bootstrap a nil CommunicationClient after DB recovery.
600+
func selectFirstAmfFromNrf(smContext *smfContext.SMContext) error {
601+
smContext.SubPduSessLog.Infof("AMF discovery: querying NRF directly (bypassing cache)")
602+
candidates, err := fetchAmfCandidates()
603+
if err != nil {
604+
return err
605+
}
606+
return useAmfProfile(smContext, candidates[0])
607+
}
608+
481609
func SendCreateSubscription(nrfUri string, nrfSubscriptionData models.SubscriptionData) (nrfSubData *models.SubscriptionData, problemDetails *models.ProblemDetails, err error) {
482610
logger.ConsumerLog.Debugln("send Create Subscription")
483611

Lines changed: 68 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,68 @@
1+
// SPDX-FileCopyrightText: 2026 Forsway Solutions AB
2+
// SPDX-License-Identifier: Apache-2.0
3+
4+
package consumer
5+
6+
import (
7+
"testing"
8+
9+
"github.com/omec-project/openapi/v2/models"
10+
)
11+
12+
func amfDiscoveryProfile(nfInstanceId, apiPrefix string) models.NFProfileDiscovery {
13+
return models.NFProfileDiscovery{
14+
NfInstanceId: nfInstanceId,
15+
NfType: models.NFTYPE_AMF,
16+
NfStatus: models.NFSTATUS_REGISTERED,
17+
NfServices: []models.NFService{
18+
{ServiceName: models.SERVICENAME_NAMF_COMM, ApiPrefix: &apiPrefix},
19+
},
20+
}
21+
}
22+
23+
func TestSelectableAmfCandidates_SkipsFailedNfInstanceId(t *testing.T) {
24+
a := amfDiscoveryProfile("amf-a", "http://10.42.0.10:29518")
25+
b := amfDiscoveryProfile("amf-b", "http://10.42.0.20:29518")
26+
c := amfDiscoveryProfile("amf-c", "http://10.42.0.30:29518")
27+
28+
got := selectableAmfCandidates([]models.NFProfileDiscovery{a, b, c}, "amf-b")
29+
if len(got) != 2 {
30+
t.Fatalf("expected 2 candidates after filtering, got %d", len(got))
31+
}
32+
if got[0].NfInstanceId != "amf-a" || got[1].NfInstanceId != "amf-c" {
33+
t.Errorf("expected order [amf-a, amf-c], got [%s, %s]", got[0].NfInstanceId, got[1].NfInstanceId)
34+
}
35+
}
36+
37+
func TestSelectableAmfCandidates_PreservesOrder(t *testing.T) {
38+
a := amfDiscoveryProfile("amf-a", "http://10.42.0.10:29518")
39+
b := amfDiscoveryProfile("amf-b", "http://10.42.0.20:29518")
40+
c := amfDiscoveryProfile("amf-c", "http://10.42.0.30:29518")
41+
42+
got := selectableAmfCandidates([]models.NFProfileDiscovery{a, b, c}, "does-not-match-any")
43+
if len(got) != 3 {
44+
t.Fatalf("expected 3 candidates when no match, got %d", len(got))
45+
}
46+
for i, want := range []string{"amf-a", "amf-b", "amf-c"} {
47+
if got[i].NfInstanceId != want {
48+
t.Errorf("position %d: got %s, want %s", i, got[i].NfInstanceId, want)
49+
}
50+
}
51+
}
52+
53+
func TestSelectableAmfCandidates_AllFiltered_ReturnsEmpty(t *testing.T) {
54+
a := amfDiscoveryProfile("amf-x", "http://10.42.0.10:29518")
55+
b := amfDiscoveryProfile("amf-x", "http://10.42.0.20:29518")
56+
57+
got := selectableAmfCandidates([]models.NFProfileDiscovery{a, b}, "amf-x")
58+
if len(got) != 0 {
59+
t.Errorf("expected empty result when every candidate matches failed NfId, got %d", len(got))
60+
}
61+
}
62+
63+
func TestSelectableAmfCandidates_EmptyInput_ReturnsEmpty(t *testing.T) {
64+
got := selectableAmfCandidates(nil, "anything")
65+
if len(got) != 0 {
66+
t.Errorf("expected empty result for nil input, got %d", len(got))
67+
}
68+
}

context/db.go

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -323,6 +323,7 @@ func GetSMContextByRefInDB(ref string) (smContext *SMContext) {
323323
logger.DataRepoLog.Errorf("smContext unmarshall error: %v", err)
324324
return nil
325325
}
326+
smContext.RebuildCommunicationClient()
326327
} else {
327328
logger.DataRepoLog.Warnf("SmContext doesn't exist with ref: %v", ref)
328329
return nil

context/sm_context.go

Lines changed: 21 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -372,6 +372,27 @@ func (smContext *SMContext) SetCreateData(createData *models.SmContextCreateData
372372
smContext.ServingNfId = createData.GetServingNfId()
373373
}
374374

375+
// RebuildCommunicationClient reconstructs the Namf_Communication API client
376+
// from the stored AMFProfile. This is needed after recovering an SMContext from
377+
// MongoDB, since CommunicationClient is not serializable.
378+
func (smContext *SMContext) RebuildCommunicationClient() {
379+
if smContext.AMFProfile.NfServices == nil {
380+
return
381+
}
382+
for _, service := range smContext.AMFProfile.NfServices {
383+
if service.ServiceName == models.SERVICENAME_NAMF_COMM {
384+
communicationConf := Namf_Communication.NewConfiguration()
385+
serverConfig := &communicationConf.Servers[0]
386+
if apiRootVar, exists := serverConfig.Variables["apiRoot"]; exists {
387+
apiRootVar.DefaultValue = service.GetApiPrefix()
388+
serverConfig.Variables["apiRoot"] = apiRootVar
389+
}
390+
smContext.CommunicationClient = Namf_Communication.NewAPIClient(communicationConf)
391+
return
392+
}
393+
}
394+
}
395+
375396
func (smContext *SMContext) BuildCreatedData() (createdData *models.SmContextCreatedData) {
376397
createdData = models.NewSmContextCreatedData()
377398
createdData.SNssai = smContext.Snssai

context/sm_context_rebuild_test.go

Lines changed: 107 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,107 @@
1+
// SPDX-FileCopyrightText: 2026 Forsway Solutions AB
2+
// SPDX-License-Identifier: Apache-2.0
3+
4+
package context
5+
6+
import (
7+
"strings"
8+
"testing"
9+
10+
"github.com/omec-project/openapi/v2/models"
11+
)
12+
13+
func amfProfileWithNamfComm(apiPrefix string) models.NFProfileDiscovery {
14+
commService := models.NFService{
15+
ServiceName: models.SERVICENAME_NAMF_COMM,
16+
ApiPrefix: &apiPrefix,
17+
}
18+
return models.NFProfileDiscovery{
19+
NfInstanceId: "amf-instance-1",
20+
NfType: models.NFTYPE_AMF,
21+
NfStatus: models.NFSTATUS_REGISTERED,
22+
NfServices: []models.NFService{commService},
23+
}
24+
}
25+
26+
func TestRebuildCommunicationClient_WithNamfComm_BuildsClientAndSetsApiRoot(t *testing.T) {
27+
const apiPrefix = "http://10.42.0.42:29518"
28+
29+
smCtx := &SMContext{}
30+
smCtx.AMFProfile = amfProfileWithNamfComm(apiPrefix)
31+
32+
smCtx.RebuildCommunicationClient()
33+
34+
if smCtx.CommunicationClient == nil {
35+
t.Fatalf("expected CommunicationClient to be non-nil after RebuildCommunicationClient")
36+
}
37+
// Ensure the apiRoot variable was wired through to the configuration.
38+
cfg := smCtx.CommunicationClient.GetConfig()
39+
if cfg == nil || len(cfg.Servers) == 0 {
40+
t.Fatalf("expected client configuration with at least one server")
41+
}
42+
apiRootVar, ok := cfg.Servers[0].Variables["apiRoot"]
43+
if !ok {
44+
t.Fatalf("expected apiRoot variable to be present on server[0]")
45+
}
46+
if apiRootVar.DefaultValue != apiPrefix {
47+
t.Errorf("apiRoot DefaultValue = %q, want %q", apiRootVar.DefaultValue, apiPrefix)
48+
}
49+
}
50+
51+
func TestRebuildCommunicationClient_NoServices_LeavesClientNil(t *testing.T) {
52+
smCtx := &SMContext{}
53+
// AMFProfile.NfServices is nil here.
54+
55+
smCtx.RebuildCommunicationClient()
56+
57+
if smCtx.CommunicationClient != nil {
58+
t.Errorf("expected CommunicationClient to remain nil when NfServices is nil")
59+
}
60+
}
61+
62+
func TestRebuildCommunicationClient_NoNamfComm_LeavesClientNil(t *testing.T) {
63+
apiPrefix := "http://10.42.0.42:29518"
64+
smCtx := &SMContext{}
65+
smCtx.AMFProfile = models.NFProfileDiscovery{
66+
NfInstanceId: "amf-instance-2",
67+
NfType: models.NFTYPE_AMF,
68+
NfStatus: models.NFSTATUS_REGISTERED,
69+
NfServices: []models.NFService{
70+
{ServiceName: models.SERVICENAME_NAMF_EVTS, ApiPrefix: &apiPrefix},
71+
},
72+
}
73+
74+
smCtx.RebuildCommunicationClient()
75+
76+
if smCtx.CommunicationClient != nil {
77+
t.Errorf("expected CommunicationClient to remain nil when no namf-comm service is present")
78+
}
79+
}
80+
81+
// Belt-and-braces: a fresh build replaces any previously held client.
82+
func TestRebuildCommunicationClient_RebuildReplacesExistingClient(t *testing.T) {
83+
const firstApiPrefix = "http://10.42.0.10:29518"
84+
const secondApiPrefix = "http://10.42.0.20:29518"
85+
86+
smCtx := &SMContext{}
87+
smCtx.AMFProfile = amfProfileWithNamfComm(firstApiPrefix)
88+
smCtx.RebuildCommunicationClient()
89+
if smCtx.CommunicationClient == nil {
90+
t.Fatalf("setup: expected non-nil CommunicationClient after first build")
91+
}
92+
first := smCtx.CommunicationClient
93+
94+
smCtx.AMFProfile = amfProfileWithNamfComm(secondApiPrefix)
95+
smCtx.RebuildCommunicationClient()
96+
97+
if smCtx.CommunicationClient == nil {
98+
t.Fatalf("expected non-nil CommunicationClient after second build")
99+
}
100+
if smCtx.CommunicationClient == first {
101+
t.Errorf("expected a fresh CommunicationClient instance after rebuild, got the same pointer")
102+
}
103+
apiRootVar := smCtx.CommunicationClient.GetConfig().Servers[0].Variables["apiRoot"]
104+
if !strings.Contains(apiRootVar.DefaultValue, "10.42.0.20") {
105+
t.Errorf("apiRoot DefaultValue = %q, expected it to reflect the second AMF endpoint", apiRootVar.DefaultValue)
106+
}
107+
}

pfcp/handler/handler.go

Lines changed: 2 additions & 10 deletions
Original file line numberDiff line numberDiff line change
@@ -13,6 +13,7 @@ import (
1313

1414
"github.com/omec-project/openapi/v2"
1515
"github.com/omec-project/openapi/v2/models"
16+
"github.com/omec-project/smf/consumer"
1617
smf_context "github.com/omec-project/smf/context"
1718
"github.com/omec-project/smf/factory"
1819
"github.com/omec-project/smf/logger"
@@ -747,16 +748,7 @@ func HandlePfcpSessionReportRequest(msg *udp.Message) {
747748
},
748749
}
749750

750-
apiN1N2MessageTransferRequest := smContext.CommunicationClient.N1N2MessageCollectionCollectionAPI.N1N2MessageTransfer(context.Background(), smContext.Supi)
751-
apiN1N2MessageTransferRequest = apiN1N2MessageTransferRequest.N1N2MessageTransferReqData(n1n2Request.GetJsonData())
752-
if binaryDataN1Message := n1n2Request.GetBinaryDataN1Message(); binaryDataN1Message != nil {
753-
apiN1N2MessageTransferRequest = apiN1N2MessageTransferRequest.BinaryDataN1Message(binaryDataN1Message)
754-
}
755-
if binaryDataN2Information := n1n2Request.GetBinaryDataN2Information(); binaryDataN2Information != nil {
756-
apiN1N2MessageTransferRequest = apiN1N2MessageTransferRequest.BinaryDataN2Information(binaryDataN2Information)
757-
}
758-
var rspData *models.N1N2MessageTransferRspData
759-
rspData, _, err = smContext.CommunicationClient.N1N2MessageCollectionCollectionAPI.N1N2MessageTransferExecute(apiN1N2MessageTransferRequest)
751+
rspData, err := consumer.SendN1N2TransferWithRediscovery(context.Background(), smContext, n1n2Request)
760752
if err != nil {
761753
smContext.SubPfcpLog.Warnf("Send N1N2Transfer failed")
762754
}

0 commit comments

Comments
 (0)