Skip to content

Commit

Permalink
pfcp: Improve logging and error handling during session create/modify…
Browse files Browse the repository at this point in the history 
…/delete

Before this patch, eupf would silently (info log level) skip PDR
creation failures due to map sizes being too small, accepting the the
PFCP session creation request.
This patch makes sure:
* The issue is reported at a meaningful log level (warn or error)
* The PFCP session creation request is rejectedt
  • Loading branch information
@pespin
pespin committed Feb 4, 2025
1 parent 54ed069 commit c4255fb
Show file tree
Hide file tree
Showing 2 changed files with 61 additions and 43 deletions.
12 changes: 8 additions & 4 deletions cmd/core/pdr.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -10,20 +10,24 @@ import (

const flagPresentIPv4 = 2

func applyPDR(spdrInfo SPDRInfo, mapOperations ebpf.ForwardingPlaneController) {
func applyPDR(spdrInfo SPDRInfo, mapOperations ebpf.ForwardingPlaneController) error {
if spdrInfo.Ipv4 != nil {
if err := mapOperations.PutPdrDownlink(spdrInfo.Ipv4, spdrInfo.PdrInfo); err != nil {
log.Info().Msgf("Can't apply IPv4 PDR: %s", err.Error())
log.Error().Msgf("Can't apply IPv4 PDR: %s", err.Error())
return err
}
} else if spdrInfo.Ipv6 != nil {
if err := mapOperations.PutDownlinkPdrIp6(spdrInfo.Ipv6, spdrInfo.PdrInfo); err != nil {
log.Info().Msgf("Can't apply IPv6 PDR: %s", err.Error())
log.Error().Msgf("Can't apply IPv6 PDR: %s", err.Error())
return err
}
} else {
if err := mapOperations.PutPdrUplink(spdrInfo.Teid, spdrInfo.PdrInfo); err != nil {
log.Info().Msgf("Can't apply GTP PDR: %s", err.Error())
log.Error().Msgf("Can't apply GTP PDR: %s", err.Error())
return err
}
}
return nil
}

func processCreatedPDRs(createdPDRs []SPDRInfo, n3Address net.IP) []*ie.IE {
Expand Down
92 changes: 53 additions & 39 deletions cmd/core/pfcp_session_handlers.go
View file
Original file line number Diff line number Diff line change
Expand Up @@ -22,14 +22,14 @@ func HandlePfcpSessionEstablishmentRequest(conn *PfcpConnection, msg message.Mes
log.Info().Msgf("Got Session Establishment Request from: %s.", addr)
remoteSEID, err := validateRequest(req.NodeID, req.CPFSEID)
if err != nil {
log.Info().Msgf("Rejecting Session Establishment Request from: %s (missing NodeID or F-SEID)", addr)
log.Warn().Msgf("Rejecting Session Establishment Request from: %s (missing NodeID or F-SEID)", addr)
PfcpMessageRxErrors.WithLabelValues(msg.MessageTypeName(), causeToString(ie.CauseMandatoryIEMissing)).Inc()
return message.NewSessionEstablishmentResponse(0, 0, 0, req.Sequence(), 0, newIeNodeID(conn.nodeId), convertErrorToIeCause(err)), nil
}

association, ok := conn.NodeAssociations[addr]
if !ok {
log.Info().Msgf("Rejecting Session Establishment Request from: %s (no association)", addr)
log.Warn().Msgf("Rejecting Session Establishment Request from: %s (no association)", addr)
PfcpMessageRxErrors.WithLabelValues(msg.MessageTypeName(), causeToString(ie.CauseNoEstablishedPFCPAssociation)).Inc()
return message.NewSessionEstablishmentResponse(0, 0, 0, req.Sequence(), 0, newIeNodeID(conn.nodeId), ie.NewCause(ie.CauseNoEstablishedPFCPAssociation)), nil
}
Expand All @@ -48,16 +48,16 @@ func HandlePfcpSessionEstablishmentRequest(conn *PfcpConnection, msg message.Mes
for _, far := range req.CreateFAR {
farInfo, err := composeFarInfo(far, conn.n3Address.To4(), conn.n9Address.To4(), ebpf.FarInfo{})
if err != nil {
log.Info().Msgf("Error extracting FAR info: %s", err.Error())
continue
log.Error().Msgf("Error extracting FAR info: %s", err.Error())
return err
}

farid, _ := far.FARID()
log.Info().Msgf("Saving FAR info to session: %d, %+v", farid, farInfo)
if internalId, err := mapOperations.NewFar(farInfo); err == nil {
session.NewFar(farid, internalId, farInfo)
} else {
log.Info().Msgf("Can't put FAR: %s", err.Error())
log.Error().Msgf("Can't put FAR: %s", err.Error())
return err
}
}
Expand All @@ -73,7 +73,7 @@ func HandlePfcpSessionEstablishmentRequest(conn *PfcpConnection, msg message.Mes
if internalId, err := mapOperations.NewQer(qerInfo); err == nil {
session.NewQer(qerId, internalId, qerInfo)
} else {
log.Info().Msgf("Can't put QER: %s", err.Error())
log.Error().Msgf("Can't put QER: %s", err.Error())
return err
}
}
Expand All @@ -89,7 +89,7 @@ func HandlePfcpSessionEstablishmentRequest(conn *PfcpConnection, msg message.Mes
if internalId, err := mapOperations.NewUrr(urrInfo); err == nil {
session.NewUrr(urrId, internalId, urrInfo)
} else {
log.Info().Msgf("Can't put URR: %s", err.Error())
log.Error().Msgf("Can't put URR: %s", err.Error())
return err
}
}
Expand All @@ -98,25 +98,29 @@ func HandlePfcpSessionEstablishmentRequest(conn *PfcpConnection, msg message.Mes
// PDR should be created last, because we need to reference FARs and QERs global id
pdrId, err := pdr.PDRID()
if err != nil {
continue
return err
}

spdrInfo := SPDRInfo{PdrID: uint32(pdrId)}

if err := pdrContext.extractPDR(pdr, &spdrInfo); err == nil {
session.PutPDR(spdrInfo.PdrID, spdrInfo)
applyPDR(spdrInfo, mapOperations)
createdPDRs = append(createdPDRs, spdrInfo)
if err := applyPDR(spdrInfo, mapOperations); err == nil {
createdPDRs = append(createdPDRs, spdrInfo)
} else {
return err
}
} else {
log.Error().Msgf("error extracting PDR info: %s", err.Error())
return err
}
}

return nil
}()

if err != nil {
log.Info().Msgf("Rejecting Session Establishment Request from: %s (error in applying IEs)", err)
log.Warn().Msgf("Rejecting Session Establishment Request from: %s (error in applying IEs)", err)
PfcpMessageRxErrors.WithLabelValues(msg.MessageTypeName(), causeToString(ie.CauseRuleCreationModificationFailure)).Inc()
return message.NewSessionEstablishmentResponse(0, 0, remoteSEID.SEID, req.Sequence(), 0, newIeNodeID(conn.nodeId), ie.NewCause(ie.CauseRuleCreationModificationFailure)), nil
}
Expand Down Expand Up @@ -146,15 +150,15 @@ func HandlePfcpSessionDeletionRequest(conn *PfcpConnection, msg message.Message,
log.Info().Msgf("Got Session Deletion Request from: %s. \n", addr)
association, ok := conn.NodeAssociations[addr]
if !ok {
log.Info().Msgf("Rejecting Session Deletion Request from: %s (no association)", addr)
log.Warn().Msgf("Rejecting Session Deletion Request from: %s (no association)", addr)
PfcpMessageRxErrors.WithLabelValues(msg.MessageTypeName(), causeToString(ie.CauseNoEstablishedPFCPAssociation)).Inc()
return message.NewSessionDeletionResponse(0, 0, 0, req.Sequence(), 0, newIeNodeID(conn.nodeId), ie.NewCause(ie.CauseNoEstablishedPFCPAssociation)), nil
}
printSessionDeleteRequest(req)

session, ok := association.Sessions[req.SEID()]
if !ok {
log.Info().Msgf("Rejecting Session Deletion Request from: %s (unknown SEID)", addr)
log.Warn().Msgf("Rejecting Session Deletion Request from: %s (unknown SEID)", addr)
PfcpMessageRxErrors.WithLabelValues(msg.MessageTypeName(), causeToString(ie.CauseSessionContextNotFound)).Inc()
return message.NewSessionDeletionResponse(0, 0, 0, req.Sequence(), 0, newIeNodeID(conn.nodeId), ie.NewCause(ie.CauseSessionContextNotFound)), nil
}
Expand Down Expand Up @@ -182,7 +186,7 @@ func HandlePfcpSessionDeletionRequest(conn *PfcpConnection, msg message.Message,
for id, urr := range session.URRs {
err, urrInfo := mapOperations.DeleteUrr(id)
if err != nil {
log.Info().Msgf("WARN: mapOperations failed to delete URR: %d, %s", id, err.Error())
log.Error().Msgf("WARN: mapOperations failed to delete URR: %d, %s", id, err.Error())
continue
}
urr.ReportSeqNumber = urr.ReportSeqNumber + 1
Expand Down Expand Up @@ -220,15 +224,15 @@ func HandlePfcpSessionModificationRequest(conn *PfcpConnection, msg message.Mess
log.Info().Msgf("Finding association for %s", addr)
association, ok := conn.NodeAssociations[addr]
if !ok {
log.Info().Msgf("Rejecting Session Modification Request from: %s (no association)", addr)
log.Warn().Msgf("Rejecting Session Modification Request from: %s (no association)", addr)
PfcpMessageRxErrors.WithLabelValues(msg.MessageTypeName(), causeToString(ie.CauseNoEstablishedPFCPAssociation)).Inc()
return message.NewSessionModificationResponse(0, 0, req.SEID(), req.Sequence(), 0, newIeNodeID(conn.nodeId), ie.NewCause(ie.CauseNoEstablishedPFCPAssociation)), nil
}

log.Info().Msgf("Finding session %d", req.SEID())
session, ok := association.Sessions[req.SEID()]
if !ok {
log.Info().Msgf("Rejecting Session Modification Request from: %s (unknown SEID)", addr)
log.Warn().Msgf("Rejecting Session Modification Request from: %s (unknown SEID)", addr)
PfcpMessageRxErrors.WithLabelValues(msg.MessageTypeName(), causeToString(ie.CauseSessionContextNotFound)).Inc()
return message.NewSessionModificationResponse(0, 0, 0, req.Sequence(), 0, newIeNodeID(conn.nodeId), ie.NewCause(ie.CauseSessionContextNotFound)), nil
}
Expand Down Expand Up @@ -258,16 +262,16 @@ func HandlePfcpSessionModificationRequest(conn *PfcpConnection, msg message.Mess
for _, far := range req.CreateFAR {
farInfo, err := composeFarInfo(far, conn.n3Address.To4(), conn.n9Address.To4(), ebpf.FarInfo{})
if err != nil {
log.Info().Msgf("Error extracting FAR info: %s", err.Error())
continue
log.Warn().Msgf("Error extracting FAR info: %s", err.Error())
return err
}

farid, _ := far.FARID()
log.Info().Msgf("Saving FAR info to session: %d, %+v", farid, farInfo)
if internalId, err := mapOperations.NewFar(farInfo); err == nil {
session.NewFar(farid, internalId, farInfo)
} else {
log.Info().Msgf("Can't put FAR: %s", err.Error())
log.Error().Msgf("Can't put FAR: %s", err.Error())
return err
}
}
Expand All @@ -280,13 +284,14 @@ func HandlePfcpSessionModificationRequest(conn *PfcpConnection, msg message.Mess
sFarInfo := session.GetFar(farid)
sFarInfo.FarInfo, err = composeFarInfo(far, conn.n3Address.To4(), conn.n9Address.To4(), sFarInfo.FarInfo)
if err != nil {
log.Info().Msgf("Error extracting FAR info: %s", err.Error())
continue
log.Warn().Msgf("Error extracting FAR info: %s", err.Error())
return err
}
log.Info().Msgf("Updating FAR info: %d, %+v", farid, sFarInfo)
session.UpdateFar(farid, sFarInfo.FarInfo)
if err := mapOperations.UpdateFar(sFarInfo.GlobalId, sFarInfo.FarInfo); err != nil {
log.Info().Msgf("Can't update FAR: %s", err.Error())
log.Error().Msgf("Can't update FAR: %s", err.Error())
return err
}
}

Expand All @@ -295,7 +300,8 @@ func HandlePfcpSessionModificationRequest(conn *PfcpConnection, msg message.Mess
log.Info().Msgf("Removing FAR: %d", farid)
sFarInfo := session.RemoveFar(farid)
if err := mapOperations.DeleteFar(sFarInfo.GlobalId); err != nil {
log.Info().Msgf("Can't remove FAR: %s", err.Error())
log.Error().Msgf("Can't remove FAR: %s", err.Error())
return err
}
}

Expand All @@ -310,7 +316,7 @@ func HandlePfcpSessionModificationRequest(conn *PfcpConnection, msg message.Mess
if internalId, err := mapOperations.NewQer(qerInfo); err == nil {
session.NewQer(qerId, internalId, qerInfo)
} else {
log.Info().Msgf("Can't put QER: %s", err.Error())
log.Error().Msgf("Can't put QER: %s", err.Error())
return err
}
}
Expand All @@ -325,7 +331,7 @@ func HandlePfcpSessionModificationRequest(conn *PfcpConnection, msg message.Mess
log.Info().Msgf("Updating QER ID: %d, QER Info: %+v", qerId, sQerInfo)
session.UpdateQer(qerId, sQerInfo.QerInfo)
if err := mapOperations.UpdateQer(sQerInfo.GlobalId, sQerInfo.QerInfo); err != nil {
log.Info().Msgf("Can't update QER: %s", err.Error())
log.Error().Msgf("Can't update QER: %s", err.Error())
return err
}
}
Expand All @@ -338,7 +344,7 @@ func HandlePfcpSessionModificationRequest(conn *PfcpConnection, msg message.Mess
log.Info().Msgf("Removing QER ID: %d", qerId)
sQerInfo := session.RemoveQer(qerId)
if err := mapOperations.DeleteQer(sQerInfo.GlobalId); err != nil {
log.Info().Msgf("Can't remove QER: %s", err.Error())
log.Error().Msgf("Can't remove QER: %s", err.Error())
return err
}
}
Expand All @@ -354,7 +360,7 @@ func HandlePfcpSessionModificationRequest(conn *PfcpConnection, msg message.Mess
if internalId, err := mapOperations.NewUrr(urrInfo); err == nil {
session.NewUrr(urrId, internalId, urrInfo)
} else {
log.Info().Msgf("Can't put URR: %s", err.Error())
log.Error().Msgf("Can't put URR: %s", err.Error())
return err
}
}
Expand All @@ -369,7 +375,7 @@ func HandlePfcpSessionModificationRequest(conn *PfcpConnection, msg message.Mess
log.Info().Msgf("Updating URR ID: %d, URR Info: %+v", urrId, sUrrInfo)
session.UpdateUrr(urrId, sUrrInfo.UrrInfo)
if err := mapOperations.UpdateUrr(sUrrInfo.GlobalId, sUrrInfo.UrrInfo); err != nil {
log.Info().Msgf("Can't update URR: %s", err.Error())
log.Error().Msgf("Can't update URR: %s", err.Error())
return err
}
}
Expand All @@ -384,8 +390,8 @@ func HandlePfcpSessionModificationRequest(conn *PfcpConnection, msg message.Mess

err, urrInfo := mapOperations.DeleteUrr(sUrrInfo.GlobalId)
if err != nil {
log.Warn().Msgf("Can't remove URR: %s", err.Error())
continue
log.Error().Msgf("Can't remove URR: %s", err.Error())
return err
}

sUrrInfo.ReportSeqNumber = sUrrInfo.ReportSeqNumber + 1
Expand All @@ -402,18 +408,22 @@ func HandlePfcpSessionModificationRequest(conn *PfcpConnection, msg message.Mess
// PDR should be created last, because we need to reference FARs and QERs global id
pdrId, err := pdr.PDRID()
if err != nil {
log.Info().Msgf("PDR ID missing")
continue
log.Warn().Msgf("PDR ID missing")
return err
}

spdrInfo := SPDRInfo{PdrID: uint32(pdrId)}

if err := pdrContext.extractPDR(pdr, &spdrInfo); err == nil {
session.PutPDR(spdrInfo.PdrID, spdrInfo)
applyPDR(spdrInfo, mapOperations)
createdPDRs = append(createdPDRs, spdrInfo)
if err := applyPDR(spdrInfo, mapOperations); err == nil {
createdPDRs = append(createdPDRs, spdrInfo)
} else {
return err
}
} else {
log.Info().Msgf("Error extracting PDR info: %s", err.Error())
return err
}
}

Expand All @@ -426,9 +436,12 @@ func HandlePfcpSessionModificationRequest(conn *PfcpConnection, msg message.Mess
spdrInfo := session.GetPDR(pdrId)
if err := pdrContext.extractPDR(pdr, &spdrInfo); err == nil {
session.PutPDR(uint32(pdrId), spdrInfo)
applyPDR(spdrInfo, mapOperations)
if err := applyPDR(spdrInfo, mapOperations); err != nil {
return err
}
} else {
log.Printf("Error extracting PDR info: %s", err.Error())
log.Warn().Msgf("Error extracting PDR info: %s", err.Error())
return err
}
}

Expand All @@ -439,15 +452,16 @@ func HandlePfcpSessionModificationRequest(conn *PfcpConnection, msg message.Mess
sPDRInfo := session.RemovePDR(uint32(pdrId))

if err := pdrContext.deletePDR(sPDRInfo, mapOperations); err != nil {
log.Info().Msgf("Failed to remove uplink PDR: %v", err)
log.Error().Msgf("Failed to remove uplink PDR: %v", err)
return err
}
}
}

return nil
}()
if err != nil {
log.Info().Msgf("Rejecting Session Modification Request from: %s (failed to apply rules)", err)
log.Warn().Msgf("Rejecting Session Modification Request from: %s (failed to apply rules)", err)
PfcpMessageRxErrors.WithLabelValues(msg.MessageTypeName(), causeToString(ie.CauseRuleCreationModificationFailure)).Inc()
return message.NewSessionModificationResponse(0, 0, session.RemoteSEID, req.Sequence(), 0, newIeNodeID(conn.nodeId), ie.NewCause(ie.CauseRuleCreationModificationFailure)), nil
}
Expand Down Expand Up @@ -478,7 +492,7 @@ func convertErrorToIeCause(err error) *ie.IE {
case errNoEstablishedAssociation:
return ie.NewCause(ie.CauseNoEstablishedPFCPAssociation)
default:
log.Info().Msgf("Unknown error: %s", err.Error())
log.Warn().Msgf("Unknown error: %s", err.Error())
return ie.NewCause(ie.CauseRequestRejected)
}
}
Expand Down

0 comments on commit c4255fb

Please sign in to comment.