Skip to content

Commit

Permalink
feat: log levels support (#433)
Browse files Browse the repository at this point in the history
  • Loading branch information
kade-ddnkv authored Oct 9, 2023
1 parent 1163c85 commit e988e2b
Show file tree
Hide file tree
Showing 14 changed files with 169 additions and 133 deletions.
4 changes: 4 additions & 0 deletions cmd/config/config.go
Original file line number Diff line number Diff line change
Expand Up @@ -25,6 +25,7 @@ type UpfConfig struct {
HeartbeatRetries uint32 `mapstructure:"heartbeat_retries"`
HeartbeatInterval uint32 `mapstructure:"heartbeat_interval"`
HeartbeatTimeout uint32 `mapstructure:"heartbeat_timeout"`
LoggingLevel string `mapstructure:"logging_level"`
}

func init() {
Expand All @@ -44,6 +45,7 @@ func init() {
pflag.Uint32("hbretries", 3, "Number of heartbeat retries")
pflag.Uint32("hbinterval", 5, "Heartbeat interval in seconds")
pflag.Uint32("hbtimeout", 5, "Heartbeat timeout in seconds")
pflag.String("loglvl", "", "Logging level")
pflag.Parse()

// Bind flag errors only when flag is nil, and we ignore empty cli args
Expand All @@ -61,6 +63,7 @@ func init() {
_ = v.BindPFlag("heartbeat_retries", pflag.Lookup("hbretries"))
_ = v.BindPFlag("heartbeat_interval", pflag.Lookup("hbinterval"))
_ = v.BindPFlag("heartbeat_timeout", pflag.Lookup("hbtimeout"))
_ = v.BindPFlag("logging_level", pflag.Lookup("loglvl"))

v.SetDefault("interface_name", "lo")
v.SetDefault("xdp_attach_mode", "generic")
Expand All @@ -76,6 +79,7 @@ func init() {
v.SetDefault("heartbeat_retries", 3)
v.SetDefault("heartbeat_interval", 5)
v.SetDefault("heartbeat_timeout", 5)
v.SetDefault("logging_level", "info")

v.SetConfigFile(*configPath)

Expand Down
10 changes: 5 additions & 5 deletions cmd/core/api.go
Original file line number Diff line number Diff line change
@@ -1,7 +1,6 @@
package core

import (
"log"
"net"
"net/http"
"strconv"
Expand All @@ -13,6 +12,7 @@ import (
eupfDocs "github.com/edgecomllc/eupf/cmd/docs"
"github.com/gin-contrib/cors"
"github.com/gin-gonic/gin"
"github.com/rs/zerolog/log"
swaggerFiles "github.com/swaggo/files"
ginSwagger "github.com/swaggo/gin-swagger"
)
Expand Down Expand Up @@ -270,7 +270,7 @@ func ListPfcpSessionsFiltered(pfcpSrv *PfcpConnection) func(c *gin.Context) {
func ListQerMapContent(bpfObjects *ebpf.BpfObjects) func(c *gin.Context) {
return func(c *gin.Context) {
if elements, err := ebpf.ListQerMapContents(bpfObjects.IpEntrypointObjects.QerMap); err != nil {
log.Printf("Error reading map: %s", err.Error())
log.Info().Msgf("Error reading map: %s", err.Error())
c.JSON(http.StatusInternalServerError, gin.H{"error": err.Error()})
} else {
c.IndentedJSON(http.StatusOK, elements)
Expand All @@ -291,15 +291,15 @@ func GetQerContent(bpfObjects *ebpf.BpfObjects) func(c *gin.Context) {
id := c.Param("id")
aid, err := strconv.Atoi(id)
if err != nil {
log.Printf("Error converting id to int: %s", err.Error())
log.Info().Msgf("Error converting id to int: %s", err.Error())
c.JSON(http.StatusBadRequest, gin.H{"error": err.Error()})
return
}

var value ebpf.QerInfo

if err = bpfObjects.IpEntrypointObjects.QerMap.Lookup(uint32(aid), unsafe.Pointer(&value)); err != nil {
log.Printf("Error reading map: %s", err.Error())
log.Info().Msgf("Error reading map: %s", err.Error())
c.JSON(http.StatusInternalServerError, gin.H{"error": err.Error()})
return
}
Expand All @@ -325,7 +325,7 @@ func GetQerContent(bpfObjects *ebpf.BpfObjects) func(c *gin.Context) {
func ListUpfPipeline(bpfObjects *ebpf.BpfObjects) func(c *gin.Context) {
return func(c *gin.Context) {
if elements, err := ebpf.ListMapProgArrayContents(bpfObjects.UpfXdpObjects.UpfPipeline); err != nil {
log.Printf("Error reading map: %s", err.Error())
log.Info().Msgf("Error reading map: %s", err.Error())
c.JSON(http.StatusInternalServerError, gin.H{"error": err.Error()})
} else {
c.IndentedJSON(http.StatusOK, elements)
Expand Down
8 changes: 4 additions & 4 deletions cmd/core/display_utils.go
Original file line number Diff line number Diff line change
Expand Up @@ -3,10 +3,10 @@ package core
import (
"encoding/binary"
"fmt"
"log"
"strings"
"time"

"github.com/rs/zerolog/log"
"github.com/wmnsk/go-pfcp/ie"
"github.com/wmnsk/go-pfcp/message"
)
Expand All @@ -31,7 +31,7 @@ func printAssociationSetupRequest(req *message.AssociationSetupRequest) {
writeLineTabbed(&sb, fmt.Sprintf("Recovery Time: %s", recoveryTime.String()), 1)
}
}
log.Print(sb.String())
log.Info().Msg(sb.String())
}

func printSessionEstablishmentRequest(req *message.SessionEstablishmentRequest) {
Expand Down Expand Up @@ -62,7 +62,7 @@ func printSessionEstablishmentRequest(req *message.SessionEstablishmentRequest)
sb.WriteString(" Create")
displayBar(&sb, req.CreateBAR)
}
log.Print(sb.String())
log.Info().Msg(sb.String())
}

// IE Contents of Create/Update/Remove are mostly the same
Expand Down Expand Up @@ -163,7 +163,7 @@ func printSessionModificationRequest(req *message.SessionModificationRequest) {
writeLineTabbed(&sb, fmt.Sprintf("BAR ID: %d ", barId), 2)
}
}
log.Print(sb.String())
log.Info().Msg(sb.String())
}

func printSessionDeleteRequest(req *message.SessionDeletionRequest) {
Expand Down
24 changes: 12 additions & 12 deletions cmd/core/pfcp_connection.go
Original file line number Diff line number Diff line change
Expand Up @@ -2,12 +2,12 @@ package core

import (
"fmt"
"log"
"net"
"time"

"github.com/edgecomllc/eupf/cmd/config"
"github.com/edgecomllc/eupf/cmd/ebpf"
"github.com/rs/zerolog/log"

"github.com/wmnsk/go-pfcp/message"
)
Expand All @@ -33,20 +33,20 @@ func (connection *PfcpConnection) GetAssociation(assocAddr string) *NodeAssociat
func CreatePfcpConnection(addr string, pfcpHandlerMap PfcpHandlerMap, nodeId string, n3Ip string, mapOperations ebpf.ForwardingPlaneController) (*PfcpConnection, error) {
udpAddr, err := net.ResolveUDPAddr("udp", addr)
if err != nil {
log.Panicf("Can't resolve UDP address: %s", err.Error())
log.Panic().Msgf("Can't resolve UDP address: %s", err.Error())
return nil, err
}
udpConn, err := net.ListenUDP("udp", udpAddr)
if err != nil {
log.Printf("Can't listen UDP address: %s", err.Error())
log.Info().Msgf("Can't listen UDP address: %s", err.Error())
return nil, err
}

n3Addr := net.ParseIP(n3Ip)
if n3Addr == nil {
return nil, fmt.Errorf("failed to parse N3 IP address ID: %s", n3Ip)
}
log.Printf("Starting PFCP connection: %v with Node ID: %v and N3 address: %v", udpAddr, nodeId, n3Addr)
log.Info().Msgf("Starting PFCP connection: %v with Node ID: %v and N3 address: %v", udpAddr, nodeId, n3Addr)

return &PfcpConnection{
udpConn: udpConn,
Expand All @@ -71,11 +71,11 @@ func (connection *PfcpConnection) Run() {
for {
n, addr, err := connection.Receive(buf)
if err != nil {
log.Printf("Error reading from UDP socket: %s", err.Error())
log.Info().Msgf("Error reading from UDP socket: %s", err.Error())
time.Sleep(1 * time.Second)
continue
}
log.Printf("Received %d bytes from %s", n, addr)
log.Info().Msgf("Received %d bytes from %s", n, addr)
connection.Handle(buf[:n], addr)
}
}
Expand All @@ -91,7 +91,7 @@ func (connection *PfcpConnection) Receive(b []byte) (n int, addr *net.UDPAddr, e
func (connection *PfcpConnection) Handle(b []byte, addr *net.UDPAddr) {
err := connection.pfcpHandlerMap.Handle(connection, b, addr)
if err != nil {
log.Printf("Error handling PFCP message: %s", err.Error())
log.Info().Msgf("Error handling PFCP message: %s", err.Error())
}
}

Expand All @@ -102,11 +102,11 @@ func (connection *PfcpConnection) Send(b []byte, addr *net.UDPAddr) (int, error)
func (connection *PfcpConnection) SendMessage(msg message.Message, addr *net.UDPAddr) error {
responseBytes := make([]byte, msg.MarshalLen())
if err := msg.MarshalTo(responseBytes); err != nil {
log.Print(err)
log.Info().Msg(err.Error())
return err
}
if _, err := connection.Send(responseBytes, addr); err != nil {
log.Print(err)
log.Info().Msg(err.Error())
return err
}
return nil
Expand All @@ -116,7 +116,7 @@ func (connection *PfcpConnection) SendMessage(msg message.Message, addr *net.UDP
func (connection *PfcpConnection) RefreshAssociations() {
for assocAddr, assoc := range connection.NodeAssociations {
if assoc.IsExpired() {
log.Printf("Pruning expired node association: %s", assocAddr)
log.Info().Msgf("Pruning expired node association: %s", assocAddr)
connection.DeleteAssociation(assocAddr)
}
}
Expand All @@ -130,9 +130,9 @@ func (connection *PfcpConnection) RefreshAssociations() {
// DeleteAssociation deletes an association and all sessions associated with it.
func (connection *PfcpConnection) DeleteAssociation(assocAddr string) {
assoc := connection.GetAssociation(assocAddr)
log.Printf("Pruning expired node association: %s", assocAddr)
log.Info().Msgf("Pruning expired node association: %s", assocAddr)
for sessionId, session := range assoc.Sessions {
log.Printf("Deleting session: %d", sessionId)
log.Info().Msgf("Deleting session: %d", sessionId)
connection.DeleteSession(session)
}
delete(connection.NodeAssociations, assocAddr)
Expand Down
22 changes: 11 additions & 11 deletions cmd/core/pfcp_handlers.go
Original file line number Diff line number Diff line change
@@ -1,10 +1,10 @@
package core

import (
"log"
"net"
"time"

"github.com/rs/zerolog/log"
"github.com/wmnsk/go-pfcp/ie"
"github.com/wmnsk/go-pfcp/message"
)
Expand All @@ -14,10 +14,10 @@ type PfcpFunc func(conn *PfcpConnection, msg message.Message, addr string) (mess
type PfcpHandlerMap map[uint8]PfcpFunc

func (handlerMap PfcpHandlerMap) Handle(conn *PfcpConnection, buf []byte, addr *net.UDPAddr) error {
log.Printf("Handling PFCP message from %s", addr)
log.Info().Msgf("Handling PFCP message from %s", addr)
incomingMsg, err := message.Parse(buf)
if err != nil {
log.Printf("Ignored undecodable message: %x, error: %s", buf, err)
log.Info().Msgf("Ignored undecodable message: %x, error: %s", buf, err)
return err
}
PfcpMessageRx.WithLabelValues(incomingMsg.MessageTypeName()).Inc()
Expand All @@ -27,7 +27,7 @@ func (handlerMap PfcpHandlerMap) Handle(conn *PfcpConnection, buf []byte, addr *
stringIpAddr := addr.IP.String()
outgoingMsg, err := handler(conn, incomingMsg, stringIpAddr)
if err != nil {
log.Printf("Error handling PFCP message: %s", err.Error())
log.Info().Msgf("Error handling PFCP message: %s", err.Error())
return err
}
duration := time.Since(startTime)
Expand All @@ -39,17 +39,17 @@ func (handlerMap PfcpHandlerMap) Handle(conn *PfcpConnection, buf []byte, addr *
}
return nil
} else {
log.Printf("Got unexpected message %s: %s, from: %s", incomingMsg.MessageTypeName(), incomingMsg, addr)
log.Info().Msgf("Got unexpected message %s: %s, from: %s", incomingMsg.MessageTypeName(), incomingMsg, addr)
}
return nil
}

// https://www.etsi.org/deliver/etsi_ts/129200_129299/129244/16.04.00_60/ts_129244v160400p.pdf page 95
func HandlePfcpAssociationSetupRequest(conn *PfcpConnection, msg message.Message, addr string) (message.Message, error) {
asreq := msg.(*message.AssociationSetupRequest)
log.Printf("Got Association Setup Request from: %s. \n", addr)
log.Info().Msgf("Got Association Setup Request from: %s. \n", addr)
if asreq.NodeID == nil {
log.Printf("Got Association Setup Request without NodeID from: %s", addr)
log.Info().Msgf("Got Association Setup Request without NodeID from: %s", addr)
// Reject with cause

PfcpMessageRxErrors.WithLabelValues(msg.MessageTypeName(), causeToString(ie.CauseMandatoryIEMissing)).Inc()
Expand All @@ -62,7 +62,7 @@ func HandlePfcpAssociationSetupRequest(conn *PfcpConnection, msg message.Message
// Get NodeID
remoteNodeID, err := asreq.NodeID.NodeID()
if err != nil {
log.Printf("Got Association Setup Request with invalid NodeID from: %s", addr)
log.Info().Msgf("Got Association Setup Request with invalid NodeID from: %s", addr)
PfcpMessageRxErrors.WithLabelValues(msg.MessageTypeName(), causeToString(ie.CauseMandatoryIEMissing)).Inc()
asres := message.NewAssociationSetupResponse(asreq.SequenceNumber,
ie.NewCause(ie.CauseMandatoryIEMissing),
Expand All @@ -71,9 +71,9 @@ func HandlePfcpAssociationSetupRequest(conn *PfcpConnection, msg message.Message
}
// Check if the PFCP Association Setup Request contains a Node ID for which a PFCP association was already established
if _, ok := conn.NodeAssociations[remoteNodeID]; ok {
log.Printf("Association Setup Request with NodeID: %s from: %s already exists", remoteNodeID, addr)
log.Info().Msgf("Association Setup Request with NodeID: %s from: %s already exists", remoteNodeID, addr)
// retain the PFCP sessions that were established with the existing PFCP association and that are requested to be retained, if the PFCP Session Retention Information IE was received in the request; otherwise, delete the PFCP sessions that were established with the existing PFCP association;
log.Println("Session retention is not yet implemented")
log.Info().Msg("Session retention is not yet implemented")
}

// If the PFCP Association Setup Request contains a Node ID for which a PFCP association was already established
Expand All @@ -84,7 +84,7 @@ func HandlePfcpAssociationSetupRequest(conn *PfcpConnection, msg message.Message
remoteNode := NewNodeAssociation(remoteNodeID, addr)
// Add or replace RemoteNode to NodeAssociationMap
conn.NodeAssociations[addr] = remoteNode
log.Printf("Saving new association: %+v", remoteNode)
log.Info().Msgf("Saving new association: %+v", remoteNode)

// shall send a PFCP Association Setup Response including:
asres := message.NewAssociationSetupResponse(asreq.SequenceNumber,
Expand Down
21 changes: 11 additions & 10 deletions cmd/core/pfcp_hearbeat.go
Original file line number Diff line number Diff line change
@@ -1,10 +1,11 @@
package core

import (
"net"

"github.com/rs/zerolog/log"
"github.com/wmnsk/go-pfcp/ie"
"github.com/wmnsk/go-pfcp/message"
"log"
"net"
)

func HandlePfcpHeartbeatRequest(conn *PfcpConnection, msg message.Message, addr string) (message.Message, error) {
Expand All @@ -14,25 +15,25 @@ func HandlePfcpHeartbeatRequest(conn *PfcpConnection, msg message.Message, addr
}
ts, err := hbreq.RecoveryTimeStamp.RecoveryTimeStamp()
if err != nil {
log.Printf("Got Heartbeat Request with invalid TS: %s, from: %s", err, addr)
log.Info().Msgf("Got Heartbeat Request with invalid TS: %s, from: %s", err, addr)
return nil, err
} else {
log.Printf("Got Heartbeat Request with TS: %s, from: %s", ts, addr)
log.Debug().Msgf("Got Heartbeat Request with TS: %s, from: %s", ts, addr)
}

hbres := message.NewHeartbeatResponse(hbreq.SequenceNumber, ie.NewRecoveryTimeStamp(conn.RecoveryTimestamp))
log.Printf("Sent Heartbeat Response to: %s", addr)
log.Debug().Msgf("Sent Heartbeat Response to: %s", addr)
return hbres, nil
}

func HandlePfcpHeartbeatResponse(conn *PfcpConnection, msg message.Message, addr string) (message.Message, error) {
hbresp := msg.(*message.HeartbeatResponse)
ts, err := hbresp.RecoveryTimeStamp.RecoveryTimeStamp()
if err != nil {
log.Printf("Got Heartbeat Response with invalid TS: %s, from: %s", err, addr)
log.Info().Msgf("Got Heartbeat Response with invalid TS: %s, from: %s", err, addr)
return nil, err
} else {
log.Printf("Got Heartbeat Response with TS: %s, from: %s", ts, addr)
log.Debug().Msgf("Got Heartbeat Response with TS: %s, from: %s", ts, addr)
}
if association := conn.GetAssociation(addr); association != nil {
association.RefreshRetries()
Expand All @@ -42,13 +43,13 @@ func HandlePfcpHeartbeatResponse(conn *PfcpConnection, msg message.Message, addr

func SendHeartbeatRequest(conn *PfcpConnection, sequenceID uint32, associationAddr string) {
hbreq := message.NewHeartbeatRequest(sequenceID, ie.NewRecoveryTimeStamp(conn.RecoveryTimestamp), nil)
log.Printf("Sent Heartbeat Request to: %s", associationAddr)
log.Debug().Msgf("Sent Heartbeat Request to: %s", associationAddr)
udpAddr, err := net.ResolveUDPAddr("udp", associationAddr+":8805")
if err == nil {
if err := conn.SendMessage(hbreq, udpAddr); err != nil {
log.Printf("Failed to send Heartbeat Request: %s\n", err.Error())
log.Info().Msgf("Failed to send Heartbeat Request: %s\n", err.Error())
}
} else {
log.Printf("Failed to send Heartbeat Request: %s\n", err.Error())
log.Info().Msgf("Failed to send Heartbeat Request: %s\n", err.Error())
}
}
Loading

0 comments on commit e988e2b

Please sign in to comment.