Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

logging: better timestamp precision / log when CNI request finishes processing #381

Open
wants to merge 2 commits into
base: master
Choose a base branch
from
Open

logging: better timestamp precision / log when CNI request finishes processing #381

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
2 commits
Select commit Hold shift + click to select a range
f324246
logging: use the RFC3399Nano timestamp format
maiqueb Aug 17, 2023
55ab680
logging: add logging to measure the CNI processing times
maiqueb Aug 17, 2023
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
19 changes: 15 additions & 4 deletions cmd/whereabouts.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -4,6 +4,7 @@ import (
"context"
"fmt"
"net"
"time"

"github.com/containernetworking/cni/pkg/skel"
cnitypes "github.com/containernetworking/cni/pkg/types"
Expand All @@ -18,18 +19,24 @@ import (
)

func main() {
var startTime time.Time
skel.PluginMain(func(args *skel.CmdArgs) error {
ipamConf, confVersion, err := config.LoadIPAMConfig(args.StdinData, args.Args)
if err != nil {
logging.Errorf("IPAM configuration load failed: %s", err)
return err
}
logging.Debugf("ADD - IPAM configuration successfully read: %+v", *ipamConf)

startTime = time.Now()
logging.Debugf("ADD - IPAM plugin start. Config: %+v", *ipamConf)
ipam, err := kubernetes.NewKubernetesIPAM(args.ContainerID, *ipamConf)
if err != nil {
return logging.Errorf("failed to create Kubernetes IPAM manager: %v", err)
}
defer func() { safeCloseKubernetesBackendConnection(ipam) }()
defer func() {
safeCloseKubernetesBackendConnection(ipam)
logging.Debugf("ADD - IPAM plugin finished. Took: %q Config: %+v", time.Since(startTime).String(), *ipamConf)
}()
Comment on lines +36 to +39
Copy link
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Please consider using a function that gets a string, startTime and is reused in both places
as beside ADD / DEL string it is the same

return cmdAdd(args, ipam, confVersion)
},
cmdCheck,
Expand All @@ -39,13 +46,17 @@ func main() {
logging.Errorf("IPAM configuration load failed: %s", err)
return err
}
logging.Debugf("DEL - IPAM configuration successfully read: %+v", *ipamConf)

startTime = time.Now()
logging.Debugf("DEL - IPAM plugin start. Config: %+v", *ipamConf)
ipam, err := kubernetes.NewKubernetesIPAM(args.ContainerID, *ipamConf)
if err != nil {
return logging.Errorf("IPAM client initialization error: %v", err)
}
defer func() { safeCloseKubernetesBackendConnection(ipam) }()
defer func() {
safeCloseKubernetesBackendConnection(ipam)
logging.Debugf("DEL - IPAM plugin finished. Took: %q Config: %+v", time.Since(startTime).String(), *ipamConf)
Copy link
Member

@oshoval oshoval Aug 17, 2023 •
edited
Loading

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

maybe in case of a failure better to change to finished (failed)
so we can filter the failure lines easily when benchmarking ?
unless it is not important because when benchmarking we dont run failures cases
but it is more accurate this way, because it is not finished, but finished with failure

if it is - then also on ADD please

Copy link
Collaborator Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Yes, there's no point bench marking failed results.

BUT it makes sense to log the result (or a simplified version of it).

I'll act on this.

}()
return cmdDel(args, ipam)
},
cniversion.All,
Expand Down
2 changes: 1 addition & 1 deletion pkg/logging/logging.go
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -40,7 +40,7 @@ var loggingStderr bool
var loggingFp *os.File
var loggingLevel Level

const defaultTimestampFormat = time.RFC3339
const defaultTimestampFormat = time.RFC3339Nano

func (l Level) String() string {
switch l {
Expand Down
Loading