Coder Social home page Coder Social logo

cni-log's Introduction

CNI Log

The purpose of this package is to perform logging for CNI projects in NPWG. Cni-log provides general logging functionality for Container Network Interfaces (CNI). Messages can be logged to a log file and/or to standard error.

Usage

The package can function out of the box as most of its configurations have default values. Just call any of the logging functions to start logging. To further define log settings such as the log file path, the log level, as well as the lumberjack logger object, continue on to the public functions below.

Importing cni-log

Import cni-log in your go file:

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

Then perform a go mod tidy to download the package.

Please ensure that the log file is properly specified; otherwise, no information will be printed to the console. In the event that the log file is not configured correctly, relevant error messages will be printed to the console.

    ...
    logging.SetLogFile("samplelog.log")
    ...

Customizing the logging prefix/header

CNI-log allows users to modify the logging prefix/header. The default prefix is in the following format:

yyyy-mm-ddTHH:MM:SSZ [<log level>] ...

E.g.

2022-10-11T13:09:57Z [info] This is a log message with INFO log level

To change the prefix used by cni-log, you will need to provide the implementation of how the prefix string would be built. To do so you will need to create an object of type Prefixer. Prefixer is an interface with one function:

CreatePrefix(Level) string

Implement the above function with the code that would build the prefix string. In order for CNI-Log to use your custom prefix you will then need to pass in your custom prefix object using the SetPrefixer function.

Below is sample code on how to build a custom prefix:

package main
import (
  ...
  logging "github.com/k8snetworkplumbingwg/cni-log"
  ...
)

// custom prefix type
type customPrefix struct {
  prefixFormat string
  timeFormat   string
  currentFile  string
}

func main() {
  // cni-log configuration
  logging.SetLogFile("samplelog.log")
  logging.SetLogLevel(logging.DebugLevel)
  logging.SetLogStderr(true)

  // Creating the custom prefix object
  prefix := &customPrefix{
    prefixFormat: "%s | %s | %s | ",
    timeFormat:   time.RFC850,
    currentFile:  "main.go",
  }
  logging.SetPrefixer(prefix) // Tell cni-log to use your custom prefix object

  // Log messages
  logging.Infof("Info log message")
  logging.Warningf("Warning log message")
}

// Implement the CreatePrefix function using your custom prefix object. This function will be called by CNI-Log
// to build the prefix string. 
func (p *customPrefix) CreatePrefix(loggingLevel logging.Level) string {
  currentTime := time.Now()
  return fmt.Sprintf(p.prefixFormat, currentTime.Format(p.timeFormat), p.currentFile, loggingLevel)
}

Public Types & Functions

Types

Level
// Level type
type Level int

Defines the type that will represent the different log levels

Prefixer
type Prefixer interface {
  CreatePrefix(Level) string
}

Defines an interface that contains one function: CreatePrefix(Level) string. Implementing this function allows you to build your own custom prefix.

LogOptions
// LogOptions defines the configuration of the lumberjack logger
type LogOptions struct {
  MaxAge     *int  `json:"maxAge,omitempty"`
  MaxSize    *int  `json:"maxSize,omitempty"`
  MaxBackups *int  `json:"maxBackups,omitempty"`
  Compress   *bool `json:"compress,omitempty"`
}

For further details of each field, see the lumberjack documentation.

To view the default values of each field, go to the "Default values" section

Public setup functions

SetLogLevel
func SetLogLevel(level Level)

Sets the log level. The valid log levels are:

int string Level
1 panic PanicLevel
2 error ErrorLevel
3 warning WarningLevel
4 info InfoLevel
5 debug DebugLevel

The log levels above are in ascending order of verbosity. For example, setting the log level to InfoLevel would mean "panic", "error", warning", and "info" messages will get logged while "debug" will not.

GetLogLevel
func GetLogLevel() Level

Returns the current log level

StringToLevel
func StringToLevel(level string) Level

Returns the Level equivalent of a string. See SetLogLevel for valid levels.

String
func (l Level) String() string

Returns the string representation of a log level

SetLogOptions
func SetLogOptions(options *LogOptions)

Configures the lumberjack object based on the lumberjack configuration data set in the logOptions object (see logOptions struct above).

SetLogFile
func SetLogFile(filename string)

Configures where logs will be written to. If an empty filepath is used, disable logging to file. No change will occur if an invalid filepath (e.g. insufficient permissions) or a symbolic link is passed into the function.

SetLogStderr
func SetLogStderr(enable bool)

This function allows you to enable/disable logging to standard error.

NOTE: For logging, a valid log file must be set or logging to stderr must be enabled.

SetOutput
func SetOutput(out io.Writer)

Set custom output. Calling this function will discard any previously set LogOptions.

SetPrefixer
func SetPrefixer(p Prefixer)

This function allows you to override the default logging prefix with a custom prefix.

SetDefaultPrefixer
func SetDefaultPrefixer()

This function allows you to return to the default logging prefix.

Logging functions

The logger comes with 2 sets of logging functions.

Printf style functions:

// Errorf prints logging if logging level >= error
func Errorf(format string, a ...interface{}) error 

// Warningf prints logging if logging level >= warning
func Warningf(format string, a ...interface{})

// Infof prints logging if logging level >= info
func Infof(format string, a ...interface{})

// Debugf prints logging if logging level >= debug
func Debugf(format string, a ...interface{})

Structured (crio logging style) functions:

// PanicStructured provides structured logging for log level >= panic.
func PanicStructured(msg string, args ...interface{})

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

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

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

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

Default values

Variable Default Value
logLevel info
logToStderr true
Logger.Filename ""
LogOptions.MaxSize 100
LogOptions.MaxAge 5
LogOptions.MaxBackups 5
LogOptions.Compress true

cni-log's People

Contributors

andreaskaris avatar cianperill avatar dependabot[bot] avatar emmakenny avatar eoghan1232 avatar jjuele avatar lpawlikx avatar nhennigan avatar

Stargazers

 avatar  avatar

Watchers

 avatar  avatar  avatar  avatar  avatar  avatar

cni-log's Issues

Add structured logging

Most of crio's logs are structured, like:

 11 23:02:45 sno.workload.bos2.lab crio[4322]: time="2023-07-11 23:02:45.552961184Z" level=info msg="Stopped pod sandbox: 35c3b3752c664d6ac80baa037503f08d359bab27627d40502b5b80f6f1b85264" id=823e2120-adbd-44d1-963a-ea68b957dea4 name=/runtime.v1.RuntimeService/StopPodSandbo

Extend the logger so that it can provide similarly structured logs

cni-log always creates the default log file in /var/log/cni-log.log

An application using it would most likely set its own path via SetLogFile before logging any messages.
currently we end up with the default log file always being created even if logs are not written to it.

proposal:
remove default log file, force user to set it

alternative:
if log file path was not set, use default (initialize on first write)

Logger does not allow to log to stderr but not to file

The logger should support only logging to stderr. In that case, crio will forward the error logs to the journal. Instead, the logger requires that users provide a log file, even when stderr logging is on, resulting in 2 different locations always receiving logs. This seems redundant.

Current combinations:

  • log to file, stderr logging off
  • log to file, stderr logging on

Better:

  • log to file, stderr logging off
  • log to file, stderr logging on
  • stderr logging on, to not log to file

Data race in cni-log

Can be triggered by the following unit test:

+       Context("Logging from different go routines", Ordered, func() {
+               var logFile2 string
+
+               BeforeEach(func() {
+                       tempDir := os.TempDir()
+                       logFile2 = path.Join(tempDir, "test2.log")
+
+                       SetLogFile(logFile)
+                       SetLogStderr(false)
+               })
 
+               AfterEach(func() {
+                       Expect(os.RemoveAll(logFile2)).To(Succeed())
+               })
+
+               When("another go routine manipulates the logger", func() {
+                       It("does not cause a race condition", func() {
+                               go func() {
+                                       SetLogFile(logFile2)
+                               }()
+                               // expected := fmt.Sprintf(`time=".*" level=%q msg=%q`, infoStr, infoMsg)
+                               errStr := captureStdErrEvent(InfoStructured, infoMsg)
+                               Expect(errStr).To(BeEmpty())
+                               // Expect(logFileContainsRegex(logFile, expected)).To(BeTrue())
+                       })
+               })

And by running:

go test -v -race ./... .

Result:

$ go test -count=1 -race ./... --ginkgo.focus='Logging from different go routines'
Running Suite: CNI-LOG Test Suite - /home/akaris/development/cni-log
====================================================================
Random Seed: 1695739922

Will run 1 of 41 specs
SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS==================
WARNING: DATA RACE
Read at 0x000000d65450 by goroutine 34:
  github.com/k8snetworkplumbingwg/cni-log.isFileLoggingEnabled()
      /home/akaris/development/cni-log/logging.go:262 +0x84
  github.com/k8snetworkplumbingwg/cni-log.printWithPrefixf()
      /home/akaris/development/cni-log/logging.go:428 +0x8d
  github.com/k8snetworkplumbingwg/cni-log.InfoStructured()
      /home/akaris/development/cni-log/logging.go:367 +0x73
  github.com/k8snetworkplumbingwg/cni-log.captureStdErrEvent()
      /home/akaris/development/cni-log/logging_test.go:722 +0x86
  github.com/k8snetworkplumbingwg/cni-log.glob..func1.11.3.1()
      /home/akaris/development/cni-log/logging_test.go:584 +0xb5
  github.com/onsi/ginkgo/v2/internal.(*Suite).runNode.func2()
      /home/akaris/development/go/pkg/mod/github.com/onsi/ginkgo/[email protected]/internal/suite.go:596 +0xea

Previous write at 0x000000d65450 by goroutine 35:
  github.com/k8snetworkplumbingwg/cni-log.SetLogFile()
      /home/akaris/development/cni-log/logging.go:251 +0x25c
  github.com/k8snetworkplumbingwg/cni-log.glob..func1.11.3.1.1()
      /home/akaris/development/cni-log/logging_test.go:581 +0x44

Goroutine 34 (running) created at:
  github.com/onsi/ginkgo/v2/internal.(*Suite).runNode()
      /home/akaris/development/go/pkg/mod/github.com/onsi/ginkgo/[email protected]/internal/suite.go:584 +0x935
  github.com/onsi/ginkgo/v2/internal.(*group).attemptSpec()
      /home/akaris/development/go/pkg/mod/github.com/onsi/ginkgo/[email protected]/internal/group.go:181 +0xfd8
  github.com/onsi/ginkgo/v2/internal.(*group).run()
      /home/akaris/development/go/pkg/mod/github.com/onsi/ginkgo/[email protected]/internal/group.go:303 +0xe64
  github.com/onsi/ginkgo/v2/internal.(*Suite).runSpecs()
      /home/akaris/development/go/pkg/mod/github.com/onsi/ginkgo/[email protected]/internal/suite.go:304 +0xe86
  github.com/onsi/ginkgo/v2/internal.(*Suite).Run()
      /home/akaris/development/go/pkg/mod/github.com/onsi/ginkgo/[email protected]/internal/suite.go:83 +0x444
  github.com/onsi/ginkgo/v2.RunSpecs()
      /home/akaris/development/go/pkg/mod/github.com/onsi/ginkgo/[email protected]/core_dsl.go:280 +0x16a4
  github.com/k8snetworkplumbingwg/cni-log.TestLogging()
      /home/akaris/development/cni-log/logging_test.go:45 +0x55
  testing.tRunner()
      /usr/lib/golang/src/testing/testing.go:1576 +0x216
  testing.(*T).Run.func1()
      /usr/lib/golang/src/testing/testing.go:1629 +0x47

Goroutine 35 (finished) created at:
  github.com/k8snetworkplumbingwg/cni-log.glob..func1.11.3.1()
      /home/akaris/development/cni-log/logging_test.go:580 +0x96
  github.com/onsi/ginkgo/v2/internal.(*Suite).runNode.func2()
      /home/akaris/development/go/pkg/mod/github.com/onsi/ginkgo/[email protected]/internal/suite.go:596 +0xea
==================
==================
WARNING: DATA RACE
Read at 0x00c000196120 by goroutine 34:
  gopkg.in/natefinch/lumberjack%2ev2.(*Logger).filename()
      /home/akaris/development/go/pkg/mod/gopkg.in/natefinch/[email protected]/lumberjack.go:293 +0x49
  gopkg.in/natefinch/lumberjack%2ev2.(*Logger).openExistingOrNew()
      /home/akaris/development/go/pkg/mod/gopkg.in/natefinch/[email protected]/lumberjack.go:267 +0x5e
  gopkg.in/natefinch/lumberjack%2ev2.(*Logger).Write()
      /home/akaris/development/go/pkg/mod/gopkg.in/natefinch/[email protected]/lumberjack.go:147 +0x2d2
  fmt.Fprintf()
      /usr/lib/golang/src/fmt/print.go:225 +0xb1
  github.com/k8snetworkplumbingwg/cni-log.doWritef()
      /home/akaris/development/cni-log/logging.go:412 +0x6c
  github.com/k8snetworkplumbingwg/cni-log.printWithPrefixf()
      /home/akaris/development/cni-log/logging.go:441 +0x1c5
  github.com/k8snetworkplumbingwg/cni-log.InfoStructured()
      /home/akaris/development/cni-log/logging.go:367 +0x73
  github.com/k8snetworkplumbingwg/cni-log.captureStdErrEvent()
      /home/akaris/development/cni-log/logging_test.go:722 +0x86
  github.com/k8snetworkplumbingwg/cni-log.glob..func1.11.3.1()
      /home/akaris/development/cni-log/logging_test.go:584 +0xb5
  github.com/onsi/ginkgo/v2/internal.(*Suite).runNode.func2()
      /home/akaris/development/go/pkg/mod/github.com/onsi/ginkgo/[email protected]/internal/suite.go:596 +0xea

Previous write at 0x00c000196120 by goroutine 35:
  github.com/k8snetworkplumbingwg/cni-log.SetLogFile()
      /home/akaris/development/cni-log/logging.go:250 +0x206
  github.com/k8snetworkplumbingwg/cni-log.glob..func1.11.3.1.1()
      /home/akaris/development/cni-log/logging_test.go:581 +0x44

Goroutine 34 (running) created at:
  github.com/onsi/ginkgo/v2/internal.(*Suite).runNode()
      /home/akaris/development/go/pkg/mod/github.com/onsi/ginkgo/[email protected]/internal/suite.go:584 +0x935
  github.com/onsi/ginkgo/v2/internal.(*group).attemptSpec()
      /home/akaris/development/go/pkg/mod/github.com/onsi/ginkgo/[email protected]/internal/group.go:181 +0xfd8
  github.com/onsi/ginkgo/v2/internal.(*group).run()
      /home/akaris/development/go/pkg/mod/github.com/onsi/ginkgo/[email protected]/internal/group.go:303 +0xe64
  github.com/onsi/ginkgo/v2/internal.(*Suite).runSpecs()
      /home/akaris/development/go/pkg/mod/github.com/onsi/ginkgo/[email protected]/internal/suite.go:304 +0xe86
  github.com/onsi/ginkgo/v2/internal.(*Suite).Run()
      /home/akaris/development/go/pkg/mod/github.com/onsi/ginkgo/[email protected]/internal/suite.go:83 +0x444
  github.com/onsi/ginkgo/v2.RunSpecs()
      /home/akaris/development/go/pkg/mod/github.com/onsi/ginkgo/[email protected]/core_dsl.go:280 +0x16a4
  github.com/k8snetworkplumbingwg/cni-log.TestLogging()
      /home/akaris/development/cni-log/logging_test.go:45 +0x55
  testing.tRunner()
      /usr/lib/golang/src/testing/testing.go:1576 +0x216
  testing.(*T).Run.func1()
      /usr/lib/golang/src/testing/testing.go:1629 +0x47

Goroutine 35 (finished) created at:
  github.com/k8snetworkplumbingwg/cni-log.glob..func1.11.3.1()
      /home/akaris/development/cni-log/logging_test.go:580 +0x96
  github.com/onsi/ginkgo/v2/internal.(*Suite).runNode.func2()
      /home/akaris/development/go/pkg/mod/github.com/onsi/ginkgo/[email protected]/internal/suite.go:596 +0xea
==================
•

Ran 1 of 41 Specs in 0.004 seconds
SUCCESS! -- 1 Passed | 0 Failed | 0 Pending | 40 Skipped
--- FAIL: TestLogging (0.01s)
    testing.go:1446: race detected during execution of test
FAIL
FAIL	github.com/k8snetworkplumbingwg/cni-log	0.017s
FAIL

Ordering of debug and verbose

It's currently :

5 debug DebugLevel
6 verbose VerboseLevel

Shouldn't it be :

5 verbose VerboseLevel
6 debug DebugLevel

Or, should "verbose" better be called "trace"?

5 debug DebugLevel
6 trace TraceLevel

That's very subjective but I have never seen any place where "verbose" logged more info than "debug"

Release 1.0

Shall we create an initial release of this project?

Recommend Projects

  • React photo React

    A declarative, efficient, and flexible JavaScript library for building user interfaces.

  • Vue.js photo Vue.js

    🖖 Vue.js is a progressive, incrementally-adoptable JavaScript framework for building UI on the web.

  • Typescript photo Typescript

    TypeScript is a superset of JavaScript that compiles to clean JavaScript output.

  • TensorFlow photo TensorFlow

    An Open Source Machine Learning Framework for Everyone

  • Django photo Django

    The Web framework for perfectionists with deadlines.

  • D3 photo D3

    Bring data to life with SVG, Canvas and HTML. 📊📈🎉

Recommend Topics

  • javascript

    JavaScript (JS) is a lightweight interpreted programming language with first-class functions.

  • web

    Some thing interesting about web. New door for the world.

  • server

    A server is a program made to process requests and deliver data to clients.

  • Machine learning

    Machine learning is a way of modeling and interpreting data that allows a piece of software to respond intelligently.

  • Game

    Some thing interesting about game, make everyone happy.

Recommend Org

  • Facebook photo Facebook

    We are working to build community through open source technology. NB: members must have two-factor auth.

  • Microsoft photo Microsoft

    Open source projects and samples from Microsoft.

  • Google photo Google

    Google ❤️ Open Source for everyone.

  • D3 photo D3

    Data-Driven Documents codes.