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 27, 2023
1 parent 90d0146 commit 940ac44
Show file tree
Hide file tree
Showing 9 changed files with 466 additions and 4 deletions.
28 changes: 27 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,11 @@ func getEnvArgs(envArgsString string) (*envArgs, error) {
}

func cmdAdd(args *skel.CmdArgs) error {
config.SetLogging(args.StdinData, args.ContainerID, args.Netns, 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 +185,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 +207,11 @@ func cmdAdd(args *skel.CmdArgs) error {
}

func cmdDel(args *skel.CmdArgs) error {
config.SetLogging(args.StdinData, args.ContainerID, args.Netns, 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 +221,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.Error("Cannot load config file from cache",
"func", "cmdDel",
"err", err)
return nil
}

Expand Down Expand Up @@ -261,6 +283,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
7 changes: 6 additions & 1 deletion docs/configuration-reference.md
Original file line number Diff line number Diff line change
Expand Up @@ -17,6 +17,9 @@ 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 panic, error, warning, info, debug with a default of info.
* `logFile` (string, optional): path to file for log output. By default, this will log to stderr. Logging to stderr
means that the logs will show up in crio logs (in the journal in most configurations) and in multus pod logs.


An SR-IOV CNI config with each field filled out looks like:
Expand All @@ -34,7 +37,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
23 changes: 22 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,22 @@ var (
DefaultCNIDir = "/var/lib/cni/sriov"
)

// SetLogging sets global logging parameters.
func SetLogging(stdinData []byte, containerID, netns, ifName string) {
if logLevel, logFile, err := loadLoggingConf(stdinData); err == nil {
logging.Init(logLevel, logFile, containerID, netns, ifName)
}
}

// 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 +53,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
107 changes: 107 additions & 0 deletions pkg/logging/logging.go
Original file line number Diff line number Diff line change
@@ -0,0 +1,107 @@
// 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.InfoLevel
containerID = ""
netNS = ""
ifName = ""
)

// Init initializes logging with the requested parameters.
func Init(logLevel, logFile, containerID, netns, ifName string) {
SetLogLevel(logLevel)
SetLogFile(logFile)
SetContainerID(containerID)
SetNetNS(netns)
SetIFName(ifName)
}

// 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)
cnilog.SetLogFile("")
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
}

// 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)...)
}

// 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
}
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 940ac44

Please sign in to comment.