From bb375e52748754a36daae84c7a9e5e64e0ca72de Mon Sep 17 00:00:00 2001 From: Andreas Karis Date: Thu, 27 Jul 2023 10:48:05 +0200 Subject: [PATCH] Add debug logging for SR-IOV plugin Signed-off-by: Andreas Karis --- cmd/sriov/main.go | 42 +++++- docs/configuration-reference.md | 7 +- pkg/config/config.go | 16 +- pkg/logging/logging.go | 103 +++++++++++++ pkg/logging/logging_suite_test.go | 19 +++ pkg/logging/logging_test.go | 240 ++++++++++++++++++++++++++++++ pkg/sriov/sriov.go | 47 ++++++ pkg/types/types.go | 2 + pkg/utils/pci_allocator.go | 7 +- 9 files changed, 479 insertions(+), 4 deletions(-) create mode 100644 pkg/logging/logging.go create mode 100644 pkg/logging/logging_suite_test.go create mode 100644 pkg/logging/logging_test.go diff --git a/cmd/sriov/main.go b/cmd/sriov/main.go index e785a5e00..cb660808f 100644 --- a/cmd/sriov/main.go +++ b/cmd/sriov/main.go @@ -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" @@ -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) @@ -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) } @@ -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 @@ -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 } @@ -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) diff --git a/docs/configuration-reference.md b/docs/configuration-reference.md index aebc9eb60..c9e0795e5 100644 --- a/docs/configuration-reference.md +++ b/docs/configuration-reference.md @@ -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 error. +* `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: @@ -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" } ``` diff --git a/pkg/config/config.go b/pkg/config/config.go index fd692a47a..6325dc28f 100644 --- a/pkg/config/config.go +++ b/pkg/config/config.go @@ -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" ) @@ -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{} @@ -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 diff --git a/pkg/logging/logging.go b/pkg/logging/logging.go new file mode 100644 index 000000000..b7b6a2a83 --- /dev/null +++ b/pkg/logging/logging.go @@ -0,0 +1,103 @@ +// 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) + 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 +} + +// 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)...) +} diff --git a/pkg/logging/logging_suite_test.go b/pkg/logging/logging_suite_test.go new file mode 100644 index 000000000..6f85b94ef --- /dev/null +++ b/pkg/logging/logging_suite_test.go @@ -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() { +}) diff --git a/pkg/logging/logging_test.go b/pkg/logging/logging_test.go new file mode 100644 index 000000000..d66e709f9 --- /dev/null +++ b/pkg/logging/logging_test.go @@ -0,0 +1,240 @@ +package logging + +import ( + "fmt" + "io" + "os" + + g "github.com/onsi/ginkgo/v2" + o "github.com/onsi/gomega" +) + +var _ = g.Describe("Logging", func() { + var origStderr *os.File + var stderrFile *os.File + + g.BeforeEach(func() { + var err error + stderrFile, err = os.CreateTemp("", "") + o.Expect(err).NotTo(o.HaveOccurred()) + origStderr = os.Stderr + os.Stderr = stderrFile + }) + + g.AfterEach(func() { + os.Stderr = origStderr + o.Expect(stderrFile.Close()).To(o.Succeed()) + o.Expect(os.RemoveAll(stderrFile.Name())).To(o.Succeed()) + }) + + g.Context("log argument prepender", func() { + g.When("none of netns, containerID, ifName are specified", func() { + g.BeforeEach(func() { + SetLogFile("") + SetLogLevel("") + }) + + g.It("should only prepend the cniName", func() { + Panic("test message", "a", "b") + _, _ = stderrFile.Seek(0, 0) + out, err := io.ReadAll(stderrFile) + o.Expect(err).NotTo(o.HaveOccurred()) + o.Expect(out).Should(o.ContainSubstring(fmt.Sprintf(`%s="%s"`, labelCNIName, cniName))) + o.Expect(out).ShouldNot(o.ContainSubstring(labelContainerID)) + o.Expect(out).ShouldNot(o.ContainSubstring(labelNetNS)) + o.Expect(out).ShouldNot(o.ContainSubstring(labelIFName)) + }) + }) + + g.When("netns, containerID and ifName are specified", func() { + const ( + testContainerID = "test-containerid" + testNetNS = "test-netns" + testIFName = "test-ifname" + ) + + g.BeforeEach(func() { + SetLogFile("") + SetLogLevel("") + SetContainerID(testContainerID) + SetNetNS(testNetNS) + SetIFName(testIFName) + }) + + g.It("should log cniName, netns, containerID and ifName", func() { + Panic("test message", "a", "b") + _, _ = stderrFile.Seek(0, 0) + out, err := io.ReadAll(stderrFile) + o.Expect(err).NotTo(o.HaveOccurred()) + o.Expect(out).Should(o.ContainSubstring(fmt.Sprintf(`%s="%s"`, labelCNIName, cniName))) + o.Expect(out).Should(o.ContainSubstring(fmt.Sprintf(`%s="%s"`, labelContainerID, testContainerID))) + o.Expect(out).Should(o.ContainSubstring(fmt.Sprintf(`%s="%s"`, labelNetNS, testNetNS))) + o.Expect(out).Should(o.ContainSubstring(fmt.Sprintf(`%s="%s"`, labelIFName, testIFName))) + }) + }) + }) + + g.Context("log levels", func() { + g.When("the defaults are used", func() { + g.BeforeEach(func() { + SetLogFile("") + SetLogLevel("") + }) + + g.It("panic messages are logged to stderr", func() { + Panic("test message", "a", "b") + _, _ = stderrFile.Seek(0, 0) + out, err := io.ReadAll(stderrFile) + o.Expect(err).NotTo(o.HaveOccurred()) + o.Expect(out).Should(o.ContainSubstring("test message")) + }) + + g.It("error messages are logged to stderr and look as expected", func() { + Error("test message", "a", "b") + _, _ = stderrFile.Seek(0, 0) + out, err := io.ReadAll(stderrFile) + o.Expect(err).NotTo(o.HaveOccurred()) + o.Expect(out).Should(o.ContainSubstring(`msg="test message"`)) + o.Expect(out).Should(o.ContainSubstring(`a="b"`)) + o.Expect(out).Should(o.ContainSubstring(`level="error"`)) + }) + + g.It("warning messages are not logged to stderr", func() { + Warning("test message", "a", "b") + _, _ = stderrFile.Seek(0, 0) + out, err := io.ReadAll(stderrFile) + o.Expect(err).NotTo(o.HaveOccurred()) + o.Expect(out).ShouldNot(o.ContainSubstring("test message")) + }) + }) + + g.When("the log level is lowered to warning", func() { + g.BeforeEach(func() { + SetLogFile("") + SetLogLevel("warning") + }) + + g.It("panic messages are logged to stderr", func() { + Panic("test message", "a", "b") + _, _ = stderrFile.Seek(0, 0) + out, err := io.ReadAll(stderrFile) + o.Expect(err).NotTo(o.HaveOccurred()) + o.Expect(out).Should(o.ContainSubstring("test message")) + }) + + g.It("error messages are logged to stderr", func() { + Error("test message", "a", "b") + _, _ = stderrFile.Seek(0, 0) + out, err := io.ReadAll(stderrFile) + o.Expect(err).NotTo(o.HaveOccurred()) + o.Expect(out).Should(o.ContainSubstring("test message")) + }) + + g.It("warning messages are logged to stderr", func() { + Warning("test message", "a", "b") + _, _ = stderrFile.Seek(0, 0) + out, err := io.ReadAll(stderrFile) + o.Expect(err).NotTo(o.HaveOccurred()) + o.Expect(out).Should(o.ContainSubstring("test message")) + }) + + g.It("info messages are not logged to stderr", func() { + Info("test message", "a", "b") + _, _ = stderrFile.Seek(0, 0) + out, err := io.ReadAll(stderrFile) + o.Expect(err).NotTo(o.HaveOccurred()) + o.Expect(out).ShouldNot(o.ContainSubstring("test message")) + }) + }) + + g.When("the log level is set to an invalid value", func() { + g.BeforeEach(func() { + SetLogFile("") + SetLogLevel("I'm invalid") + }) + + g.It("panic messages are logged to stderr", func() { + Panic("test message", "a", "b") + _, _ = stderrFile.Seek(0, 0) + out, err := io.ReadAll(stderrFile) + o.Expect(err).NotTo(o.HaveOccurred()) + o.Expect(out).Should(o.ContainSubstring("test message")) + }) + + g.It("error messages are logged to stderr", func() { + Error("test message", "a", "b") + _, _ = stderrFile.Seek(0, 0) + out, err := io.ReadAll(stderrFile) + o.Expect(err).NotTo(o.HaveOccurred()) + o.Expect(out).Should(o.ContainSubstring("test message")) + }) + + g.It("warning messages are not logged to stderr", func() { + Warning("test message", "a", "b") + _, _ = stderrFile.Seek(0, 0) + out, err := io.ReadAll(stderrFile) + o.Expect(err).NotTo(o.HaveOccurred()) + o.Expect(out).ShouldNot(o.ContainSubstring("test message")) + }) + }) + }) + + g.Context("log files", func() { + var logFile *os.File + + g.BeforeEach(func() { + var err error + logFile, err = os.CreateTemp("", "") + o.Expect(err).NotTo(o.HaveOccurred()) + }) + + g.AfterEach(func() { + o.Expect(logFile.Close()).To(o.Succeed()) + o.Expect(os.RemoveAll(logFile.Name())).To(o.Succeed()) + }) + + g.When("the log file is set", func() { + g.BeforeEach(func() { + SetLogFile(logFile.Name()) + SetLogLevel("") + }) + + g.It("error messages are logged to log file but not to stderr", func() { + Error("test message", "a", "b") + _, _ = stderrFile.Seek(0, 0) + out, err := io.ReadAll(logFile) + o.Expect(err).NotTo(o.HaveOccurred()) + o.Expect(out).Should(o.ContainSubstring("test message")) + + _, _ = stderrFile.Seek(0, 0) + out, err = io.ReadAll(stderrFile) + o.Expect(err).NotTo(o.HaveOccurred()) + o.Expect(out).ShouldNot(o.ContainSubstring("test message")) + }) + }) + + // TODO: This triggers a data race in github.com/k8snetworkplumbingwg/cni-log; fix the datarace in the + // logging component and then uncomment this test. + g.When("the log file is set and then unset", func() { + g.BeforeEach(func() { + SetLogLevel("") + SetLogFile(logFile.Name()) + SetLogFile("") + }) + + g.It("logs to stderr but not to file", func() { + g.Skip("https://github.com/k8snetworkplumbingwg/cni-log/issues/15") + Error("test message", "a", "b") + _, _ = stderrFile.Seek(0, 0) + out, err := io.ReadAll(logFile) + o.Expect(err).NotTo(o.HaveOccurred()) + o.Expect(out).ShouldNot(o.ContainSubstring("test message")) + + _, _ = stderrFile.Seek(0, 0) + out, err = io.ReadAll(stderrFile) + o.Expect(err).NotTo(o.HaveOccurred()) + o.Expect(out).Should(o.ContainSubstring("test message")) + }) + }) + }) +}) diff --git a/pkg/sriov/sriov.go b/pkg/sriov/sriov.go index c82c4fad8..6a2bef5d2 100644 --- a/pkg/sriov/sriov.go +++ b/pkg/sriov/sriov.go @@ -2,8 +2,10 @@ package sriov import ( "fmt" + "github.com/containernetworking/plugins/pkg/ns" + "github.com/k8snetworkplumbingwg/sriov-cni/pkg/logging" sriovtypes "github.com/k8snetworkplumbingwg/sriov-cni/pkg/types" "github.com/k8snetworkplumbingwg/sriov-cni/pkg/utils" "github.com/vishvananda/netlink" @@ -69,11 +71,18 @@ func (s *sriovManager) SetupVF(conf *sriovtypes.NetConf, podifName string, netns tempName := fmt.Sprintf("%s%d", "temp_", linkObj.Attrs().Index) // 1. Set link down + logging.Debug("1. Set link down", + "func", "SetupVF", + "linkObj", linkObj) if err := s.nLink.LinkSetDown(linkObj); err != nil { return fmt.Errorf("failed to down vf device %q: %v", linkName, err) } // 2. Set temp name + logging.Debug("2. Set temp name", + "func", "SetupVF", + "linkObj", linkObj, + "tempName", tempName) if err := s.nLink.LinkSetName(linkObj, tempName); err != nil { return fmt.Errorf("error setting temp IF name %s for %s", tempName, linkName) } @@ -82,6 +91,11 @@ func (s *sriovManager) SetupVF(conf *sriovtypes.NetConf, podifName string, netns conf.OrigVfState.EffectiveMAC = linkObj.Attrs().HardwareAddr.String() // 3. Set MAC address if conf.MAC != "" { + logging.Debug("3. Set MAC address", + "func", "SetupVF", + "s.nLink", s.nLink, + "tempName", tempName, + "conf.MAC", conf.MAC) err = utils.SetVFEffectiveMAC(s.nLink, tempName, conf.MAC) if err != nil { return fmt.Errorf("failed to set netlink MAC address to %s: %v", conf.MAC, err) @@ -89,21 +103,35 @@ func (s *sriovManager) SetupVF(conf *sriovtypes.NetConf, podifName string, netns } // 4. Change netns + logging.Debug("4. Change netns", + "func", "SetupVF", + "linkObj", linkObj, + "netns.Fd()", int(netns.Fd())) if err := s.nLink.LinkSetNsFd(linkObj, int(netns.Fd())); err != nil { return fmt.Errorf("failed to move IF %s to netns: %q", tempName, err) } if err := netns.Do(func(_ ns.NetNS) error { // 5. Set Pod IF name + logging.Debug("5. Set Pod IF name", + "func", "SetupVF", + "linkObj", linkObj, + "podifName", podifName) if err := s.nLink.LinkSetName(linkObj, podifName); err != nil { return fmt.Errorf("error setting container interface name %s for %s", linkName, tempName) } // 6. Enable IPv4 ARP notify and IPv6 Network Discovery notify // Error is ignored here because enabling this feature is only a performance enhancement. + logging.Debug("6. Enable IPv4 ARP notify and IPv6 Network Discovery notify", + "func", "SetupVF", + "podifName", podifName) _ = s.utils.EnableArpAndNdiscNotify(podifName) // 7. Bring IF up in Pod netns + logging.Debug("7. Bring IF up in Pod netns", + "func", "SetupVF", + "linkObj", linkObj) if err := s.nLink.LinkSetUp(linkObj); err != nil { return fmt.Errorf("error bringing interface up in container ns: %q", err) } @@ -125,17 +153,27 @@ func (s *sriovManager) ReleaseVF(conf *sriovtypes.NetConf, podifName string, net return netns.Do(func(_ ns.NetNS) error { // get VF device + logging.Debug("Get VF device", + "func", "ReleaseVF", + "podifName", podifName) linkObj, err := s.nLink.LinkByName(podifName) if err != nil { return fmt.Errorf("failed to get netlink device with name %s: %q", podifName, err) } // shutdown VF device + logging.Debug("Shutdown VF device", + "func", "ReleaseVF", + "linkObj", linkObj) if err = s.nLink.LinkSetDown(linkObj); err != nil { return fmt.Errorf("failed to set link %s down: %q", podifName, err) } // rename VF device + logging.Debug("Rename VF device", + "func", "ReleaseVF", + "linkObj", linkObj, + "conf.OrigVfState.HostIFName", conf.OrigVfState.HostIFName) err = s.nLink.LinkSetName(linkObj, conf.OrigVfState.HostIFName) if err != nil { return fmt.Errorf("failed to rename link %s to host name %s: %q", podifName, conf.OrigVfState.HostIFName, err) @@ -143,6 +181,11 @@ func (s *sriovManager) ReleaseVF(conf *sriovtypes.NetConf, podifName string, net if conf.MAC != "" { // reset effective MAC address + logging.Debug("Reset effective MAC address", + "func", "ReleaseVF", + "s.nLink", s.nLink, + "conf.OrigVfState.HostIFName", conf.OrigVfState.HostIFName, + "conf.OrigVfState.EffectiveMAC", conf.OrigVfState.EffectiveMAC) err = utils.SetVFEffectiveMAC(s.nLink, conf.OrigVfState.HostIFName, conf.OrigVfState.EffectiveMAC) if err != nil { return fmt.Errorf("failed to restore original effective netlink MAC address %s: %v", conf.OrigVfState.EffectiveMAC, err) @@ -150,6 +193,10 @@ func (s *sriovManager) ReleaseVF(conf *sriovtypes.NetConf, podifName string, net } // move VF device to init netns + logging.Debug("Move VF device to init netns", + "func", "ReleaseVF", + "linkObj", linkObj, + "initns.Fd()", int(initns.Fd())) if err = s.nLink.LinkSetNsFd(linkObj, int(initns.Fd())); err != nil { return fmt.Errorf("failed to move interface %s to init netns: %v", conf.OrigVfState.HostIFName, err) } diff --git a/pkg/types/types.go b/pkg/types/types.go index 6bd69d741..a476c2470 100644 --- a/pkg/types/types.go +++ b/pkg/types/types.go @@ -50,4 +50,6 @@ type NetConf struct { RuntimeConfig struct { Mac string `json:"mac,omitempty"` } `json:"runtimeConfig,omitempty"` + LogLevel string `json:"loglevel,omitempty"` + LogFile string `json:"logfile,omitempty"` } diff --git a/pkg/utils/pci_allocator.go b/pkg/utils/pci_allocator.go index 1dd7201ce..3bf6ff054 100644 --- a/pkg/utils/pci_allocator.go +++ b/pkg/utils/pci_allocator.go @@ -2,9 +2,11 @@ package utils import ( "fmt" - "github.com/containernetworking/plugins/pkg/ns" "os" "path/filepath" + + "github.com/containernetworking/plugins/pkg/ns" + "github.com/k8snetworkplumbingwg/sriov-cni/pkg/logging" ) type PCIAllocation interface { @@ -73,6 +75,9 @@ func (p *PCIAllocator) IsAllocated(pciAddress string) (bool, error) { // we release the PCI address networkNamespace, err := ns.GetNS(string(dat)) if err != nil { + logging.Debug("Mark the PCI address as released", + "func", "IsAllocated", + "pciAddress", pciAddress) err = p.DeleteAllocatedPCI(pciAddress) if err != nil { return false, fmt.Errorf("error deleting the pci allocation for vf pci address %s: %v", pciAddress, err)