Skip to content

Commit

Permalink
Add debug logging for SR-IOV plugin
Browse files Browse the repository at this point in the history
Signed-off-by: Andreas Karis <[email protected]>
  • Loading branch information
andreaskaris committed Sep 20, 2023
1 parent 90d0146 commit 780f460
Show file tree
Hide file tree
Showing 9 changed files with 453 additions and 4 deletions.
42 changes: 41 additions & 1 deletion cmd/sriov/main.go
Original file line number Diff line number Diff line change
Expand Up @@ -13,6 +13,7 @@ import (
"github.com/containernetworking/plugins/pkg/ipam"
"github.com/containernetworking/plugins/pkg/ns"
"github.com/k8snetworkplumbingwg/sriov-cni/pkg/config"
"github.com/k8snetworkplumbingwg/sriov-cni/pkg/logging"
"github.com/k8snetworkplumbingwg/sriov-cni/pkg/sriov"
"github.com/k8snetworkplumbingwg/sriov-cni/pkg/utils"
"github.com/vishvananda/netlink"
Expand Down Expand Up @@ -43,6 +44,18 @@ func getEnvArgs(envArgsString string) (*envArgs, error) {
}

func cmdAdd(args *skel.CmdArgs) error {
// Set logging related info. The default log level is error, hence also do logging.Debug inside the block.
if logLevel, logFile, err := config.LoadLoggingConf(args.StdinData); err == nil {
logging.SetLogLevel(logLevel)
logging.SetLogFile(logFile)
logging.SetContainerID(args.ContainerID)
logging.SetNetNS(args.Netns)
logging.SetIFName(args.IfName)
logging.Debug("function called",
"func", "cmdAdd",
"args.Path", args.Path, "args.StdinData", string(args.StdinData), "args.Args", args.Args)
}

netConf, err := config.LoadConf(args.StdinData)
if err != nil {
return fmt.Errorf("SRIOV-CNI failed to load netconf: %v", err)
Expand Down Expand Up @@ -179,12 +192,20 @@ func cmdAdd(args *skel.CmdArgs) error {
}

// Cache NetConf for CmdDel
logging.Debug("Cache NetConf for CmdDel",
"func", "cmdAdd",
"config.DefaultCNIDir", config.DefaultCNIDir,
"netConf", netConf)
if err = utils.SaveNetConf(args.ContainerID, config.DefaultCNIDir, args.IfName, netConf); err != nil {
return fmt.Errorf("error saving NetConf %q", err)
}

// Mark the pci address as in use.
logging.Debug("Mark the pci address as in use",
"func", "cmdAdd",
"config.DefaultCNIDir", config.DefaultCNIDir,
"netConf.DeviceID", netConf.DeviceID)
allocator := utils.NewPCIAllocator(config.DefaultCNIDir)
// Mark the pci address as in used
if err = allocator.SaveAllocatedPCI(netConf.DeviceID, args.Netns); err != nil {
return fmt.Errorf("error saving the pci allocation for vf pci address %s: %v", netConf.DeviceID, err)
}
Expand All @@ -193,6 +214,18 @@ func cmdAdd(args *skel.CmdArgs) error {
}

func cmdDel(args *skel.CmdArgs) error {
// Set logging related info. The default log level is error, hence also do logging.Debug inside the block.
if logLevel, logFile, err := config.LoadLoggingConf(args.StdinData); err == nil {
logging.SetLogLevel(logLevel)
logging.SetLogFile(logFile)
logging.SetContainerID(args.ContainerID)
logging.SetNetNS(args.Netns)
logging.SetIFName(args.IfName)
logging.Debug("function called",
"func", "cmdDel",
"args.Path", args.Path, "args.StdinData", string(args.StdinData), "args.Args", args.Args)
}

netConf, cRefPath, err := config.LoadConfFromCache(args)
if err != nil {
// If cmdDel() fails, cached netconf is cleaned up by
Expand All @@ -202,6 +235,9 @@ func cmdDel(args *skel.CmdArgs) error {
// Return nil when LoadConfFromCache fails since the rest
// of cmdDel() code relies on netconf as input argument
// and there is no meaning to continue.
logging.Info("Cannot load config file from cache",
"func", "cmdDel",
"err", err)
return nil
}

Expand Down Expand Up @@ -261,6 +297,10 @@ func cmdDel(args *skel.CmdArgs) error {
}

// Mark the pci address as released
logging.Debug("Mark the pci address as released",
"func", "cmdDel",
"config.DefaultCNIDir", config.DefaultCNIDir,
"netConf.DeviceID", netConf.DeviceID)
allocator := utils.NewPCIAllocator(config.DefaultCNIDir)
if err = allocator.DeleteAllocatedPCI(netConf.DeviceID); err != nil {
return fmt.Errorf("error cleaning the pci allocation for vf pci address %s: %v", netConf.DeviceID, err)
Expand Down
6 changes: 5 additions & 1 deletion docs/configuration-reference.md
Original file line number Diff line number Diff line change
Expand Up @@ -17,6 +17,8 @@ The SR-IOV CNI configures networks through a CNI spec configuration object. In a
* `min_tx_rate` (int, optional): change the allowed minimum transmit bandwidth, in Mbps, for the VF. Setting this to 0 disables rate limiting. The min_tx_rate value should be <= max_tx_rate. Support of this feature depends on NICs and drivers.
* `max_tx_rate` (int, optional): change the allowed maximum transmit bandwidth, in Mbps, for the VF.
Setting this to 0 disables rate limiting.
* `loglevel` (string, optional): either of error, warn, info, debug with a default of error.
* `logfile` (string, optional): path to file for log output. By default, this will log to stderr and thus to crio logs (in the journal in most configurations).


An SR-IOV CNI config with each field filled out looks like:
Expand All @@ -34,7 +36,9 @@ An SR-IOV CNI config with each field filled out looks like:
"max_tx_rate": 200,
"spoofchk": "off",
"trust": "on",
"link_state": "enable"
"link_state": "enable",
"loglevel": "debug",
"logfile": "/tmp/sriov.log"
}
```

Expand Down
16 changes: 15 additions & 1 deletion pkg/config/config.go
Original file line number Diff line number Diff line change
Expand Up @@ -7,6 +7,7 @@ import (
"strings"

"github.com/containernetworking/cni/pkg/skel"
"github.com/k8snetworkplumbingwg/sriov-cni/pkg/logging"
sriovtypes "github.com/k8snetworkplumbingwg/sriov-cni/pkg/types"
"github.com/k8snetworkplumbingwg/sriov-cni/pkg/utils"
)
Expand All @@ -16,6 +17,15 @@ var (
DefaultCNIDir = "/var/lib/cni/sriov"
)

// LoadLoggingConf extracts only logging related information from the CNI NetConf.
func LoadLoggingConf(bytes []byte) (string, string, error) {
n := &sriovtypes.NetConf{}
if err := json.Unmarshal(bytes, n); err != nil {
return "", "", fmt.Errorf("LoadConf(): failed to load netconf: %v", err)
}
return n.LogLevel, n.LogFile, nil
}

// LoadConf parses and validates stdin netconf and returns NetConf object
func LoadConf(bytes []byte) (*sriovtypes.NetConf, error) {
n := &sriovtypes.NetConf{}
Expand All @@ -36,11 +46,15 @@ func LoadConf(bytes []byte) (*sriovtypes.NetConf, error) {
return nil, fmt.Errorf("LoadConf(): VF pci addr is required")
}

allocator := utils.NewPCIAllocator(DefaultCNIDir)
// Check if the device is already allocated.
// This is to prevent issues where kubelet request to delete a pod and in the same time a new pod using the same
// vf is started. we can have an issue where the cmdDel of the old pod is called AFTER the cmdAdd of the new one
// This will block the new pod creation until the cmdDel is done.
logging.Debug("Check if the device is already allocated",
"func", "LoadConf",
"DefaultCNIDir", DefaultCNIDir,
"n.DeviceID", n.DeviceID)
allocator := utils.NewPCIAllocator(DefaultCNIDir)
isAllocated, err := allocator.IsAllocated(n.DeviceID)
if err != nil {
return n, err
Expand Down
102 changes: 102 additions & 0 deletions pkg/logging/logging.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,102 @@
// package logging is a small wrapper around github.com/k8snetworkplumbingwg/cni-log

package logging

import (
cnilog "github.com/k8snetworkplumbingwg/cni-log"
)

const (
labelCNIName = "cniName"
labelContainerID = "containerID"
labelNetNS = "netns"
labelIFName = "ifname"
cniName = "sriov-cni"
)

var (
logLevelDefault = cnilog.ErrorLevel
containerID = ""
netNS = ""
ifName = ""
)

func init() {
SetLogFile("")
SetLogLevel("")
}

// SetLogLevel sets the log level to either verbose, debug, info, warn, error or panic. If an invalid string is
// provided, it uses error.
func SetLogLevel(l string) {
ll := cnilog.StringToLevel(l)
if ll == cnilog.InvalidLevel {
ll = logLevelDefault
}
cnilog.SetLogLevel(ll)
}

// SetLogFile sets the log file for logging. If the empty string is provided, it uses stderr.
func SetLogFile(fileName string) {
if fileName == "" {
cnilog.SetLogStderr(true)
return
}
cnilog.SetLogFile(fileName)
cnilog.SetLogStderr(false)
}

// SetContainerID sets the ContainerID to prepend to every log message.
func SetContainerID(cID string) {
containerID = cID
}

// SetNetNS sets the NetNS to prepend to every log message.
func SetNetNS(ns string) {
netNS = ns
}

// SetIFName sets the ifName to prepend to every log message.
func SetIFName(in string) {
ifName = in
}

// prependArgs prepends cniName, containerID, netNS and ifName to the args of every log message.
func prependArgs(args []interface{}) []interface{} {
if ifName != "" {
args = append([]interface{}{labelIFName, ifName}, args...)
}
if netNS != "" {
args = append([]interface{}{labelNetNS, netNS}, args...)
}
if containerID != "" {
args = append([]interface{}{labelContainerID, containerID}, args...)
}
args = append([]interface{}{labelCNIName, cniName}, args...)
return args
}

// Debug provides structured logging for log level >= debug.
func Debug(msg string, args ...interface{}) {
cnilog.DebugStructured(msg, prependArgs(args)...)
}

// Info provides structured logging for log level >= info.
func Info(msg string, args ...interface{}) {
cnilog.InfoStructured(msg, prependArgs(args)...)
}

// Warning provides structured logging for log level >= warning.
func Warning(msg string, args ...interface{}) {
cnilog.WarningStructured(msg, prependArgs(args)...)
}

// Error provides structured logging for log level >= error.
func Error(msg string, args ...interface{}) {
_ = cnilog.ErrorStructured(msg, prependArgs(args)...)
}

// Panic provides structured logging for log level >= panic.
func Panic(msg string, args ...interface{}) {
cnilog.PanicStructured(msg, prependArgs(args)...)
}
19 changes: 19 additions & 0 deletions pkg/logging/logging_suite_test.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,19 @@
package logging

import (
"testing"

g "github.com/onsi/ginkgo/v2"
o "github.com/onsi/gomega"
)

func TestConfig(t *testing.T) {
o.RegisterFailHandler(g.Fail)
g.RunSpecs(t, "Logging Suite")
}

var _ = g.BeforeSuite(func() {
})

var _ = g.AfterSuite(func() {
})
Loading

0 comments on commit 780f460

Please sign in to comment.