restructure logging

Signed-off-by: Avi Deitcher <avi@deitcher.net>
This commit is contained in:
Avi Deitcher 2024-10-01 12:01:36 +03:00
parent 8556f024ef
commit 67e9e22a36
7 changed files with 44 additions and 29 deletions

View File

@ -122,13 +122,13 @@ jobs:
- name: Build Packages - name: Build Packages
# Skip s390x as emulation is unreliable # Skip s390x as emulation is unreliable
run: | run: |
make OPTIONS="-v --skip-platforms linux/s390x" -C pkg build make OPTIONS="-v 2 --skip-platforms linux/s390x" -C pkg build
- name: Build Test Packages - name: Build Test Packages
# ensures that the test packages are in linuxkit cache when we need them for tests later # ensures that the test packages are in linuxkit cache when we need them for tests later
# Skip s390x as emulation is unreliable # Skip s390x as emulation is unreliable
run: | run: |
make OPTIONS="-v --skip-platforms linux/s390x" -C test/pkg build make OPTIONS="-v 2 --skip-platforms linux/s390x" -C test/pkg build
- name: Check Kernel Dependencies up to date - name: Check Kernel Dependencies up to date
# checks that any kernel dependencies are up to date. # checks that any kernel dependencies are up to date.
@ -145,7 +145,7 @@ jobs:
# ensures that the kernel packages are in linuxkit cache when we need them for tests later # ensures that the kernel packages are in linuxkit cache when we need them for tests later
# no need for excluding s390x, as each build.yml in the kernel explicitly lists archs # no need for excluding s390x, as each build.yml in the kernel explicitly lists archs
run: | run: |
make OPTIONS="-v" -C kernel build make OPTIONS="-v 2" -C kernel build
- name: list cache contents - name: list cache contents
run: | run: |

View File

@ -21,7 +21,6 @@ import (
"github.com/google/go-containerregistry/pkg/v1/types" "github.com/google/go-containerregistry/pkg/v1/types"
lktspec "github.com/linuxkit/linuxkit/src/cmd/linuxkit/spec" lktspec "github.com/linuxkit/linuxkit/src/cmd/linuxkit/spec"
"github.com/linuxkit/linuxkit/src/cmd/linuxkit/util" "github.com/linuxkit/linuxkit/src/cmd/linuxkit/util"
lktutil "github.com/linuxkit/linuxkit/src/cmd/linuxkit/util"
imagespec "github.com/opencontainers/image-spec/specs-go/v1" imagespec "github.com/opencontainers/image-spec/specs-go/v1"
log "github.com/sirupsen/logrus" log "github.com/sirupsen/logrus"
) )
@ -58,17 +57,17 @@ func (p *Provider) ImagePull(ref *reference.Spec, trustedRef, architecture strin
// unless alwaysPull is set to true, check locally first // unless alwaysPull is set to true, check locally first
if alwaysPull { if alwaysPull {
log.Printf("Instructed always to pull, so pulling image %s arch %s", image, architecture) log.Debugf("Instructed always to pull, so pulling image %s arch %s", image, architecture)
} else { } else {
imgSrc, err := p.ValidateImage(ref, architecture) imgSrc, err := p.ValidateImage(ref, architecture)
switch { switch {
case err == nil && imgSrc != nil: case err == nil && imgSrc != nil:
log.Printf("Image %s arch %s found in local cache, not pulling", image, architecture) log.Debugf("Image %s arch %s found in local cache, not pulling", image, architecture)
return imgSrc, nil return imgSrc, nil
case err != nil && errors.Is(err, &noReferenceError{}): case err != nil && errors.Is(err, &noReferenceError{}):
log.Printf("Image %s arch %s not found in local cache, pulling", image, architecture) log.Debugf("Image %s arch %s not found in local cache, pulling", image, architecture)
default: default:
log.Printf("Image %s arch %s incomplete or invalid in local cache, error %v, pulling", image, architecture, err) log.Debugf("Image %s arch %s incomplete or invalid in local cache, error %v, pulling", image, architecture, err)
} }
// there was an error, so try to pull // there was an error, so try to pull
} }
@ -318,7 +317,7 @@ func (p *Provider) IndexWrite(ref *reference.Spec, descriptors ...v1.Descriptor)
appliedManifests[m.Digest] = true appliedManifests[m.Digest] = true
continue continue
} }
value, ok := m.Annotations[lktutil.AnnotationDockerReferenceDigest] value, ok := m.Annotations[util.AnnotationDockerReferenceDigest]
if !ok { if !ok {
manifest.Manifests = append(manifest.Manifests, m) manifest.Manifests = append(manifest.Manifests, m)
appliedManifests[m.Digest] = true appliedManifests[m.Digest] = true

View File

@ -44,7 +44,8 @@ func readConfig() {
func newCmd() *cobra.Command { func newCmd() *cobra.Command {
var ( var (
flagQuiet bool flagQuiet bool
flagVerbose bool flagVerbose int
flagVerboseName = "verbose"
) )
cmd := &cobra.Command{ cmd := &cobra.Command{
Use: "linuxkit", Use: "linuxkit",
@ -54,7 +55,7 @@ func newCmd() *cobra.Command {
readConfig() readConfig()
// Set up logging // Set up logging
return util.SetupLogging(flagQuiet, flagVerbose) return util.SetupLogging(flagQuiet, flagVerbose, cmd.Flag(flagVerboseName).Changed)
}, },
} }
@ -69,7 +70,7 @@ func newCmd() *cobra.Command {
cmd.PersistentFlags().StringVar(&cacheDir, "cache", defaultLinuxkitCache(), fmt.Sprintf("Directory for caching and finding cached image, overrides env var %s", envVarCacheDir)) cmd.PersistentFlags().StringVar(&cacheDir, "cache", defaultLinuxkitCache(), fmt.Sprintf("Directory for caching and finding cached image, overrides env var %s", envVarCacheDir))
cmd.PersistentFlags().BoolVarP(&flagQuiet, "quiet", "q", false, "Quiet execution") cmd.PersistentFlags().BoolVarP(&flagQuiet, "quiet", "q", false, "Quiet execution")
cmd.PersistentFlags().BoolVarP(&flagVerbose, "verbose", "v", false, "Verbose execution") cmd.PersistentFlags().IntVarP(&flagVerbose, flagVerboseName, "v", 1, "Verbosity of logging: 0 = quiet, 1 = info, 2 = debug, 3 = trace. Default is info. Setting it explicitly will create structured logging lines.")
return cmd return cmd
} }

View File

@ -237,7 +237,7 @@ func ImageTar(location string, ref *reference.Spec, prefix string, tw tarWriter,
hdr.PAXRecords[moby.PaxRecordLinuxkitSource] = ref.String() hdr.PAXRecords[moby.PaxRecordLinuxkitSource] = ref.String()
hdr.PAXRecords[moby.PaxRecordLinuxkitLocation] = location hdr.PAXRecords[moby.PaxRecordLinuxkitLocation] = location
if exclude[hdr.Name] { if exclude[hdr.Name] {
log.Debugf("image tar: %s %s exclude %s", ref, prefix, hdr.Name) log.Tracef("image tar: %s %s exclude %s", ref, prefix, hdr.Name)
_, err = io.Copy(io.Discard, tr) _, err = io.Copy(io.Discard, tr)
if err != nil { if err != nil {
return err return err
@ -248,7 +248,7 @@ func ImageTar(location string, ref *reference.Spec, prefix string, tw tarWriter,
hdr.Size = int64(len(contents)) hdr.Size = int64(len(contents))
hdr.Name = prefix + hdr.Name hdr.Name = prefix + hdr.Name
hdr.ModTime = defaultModTime hdr.ModTime = defaultModTime
log.Debugf("image tar: %s %s add %s (replaced)", ref, prefix, hdr.Name) log.Tracef("image tar: %s %s add %s (replaced)", ref, prefix, hdr.Name)
if err := tw.WriteHeader(hdr); err != nil { if err := tw.WriteHeader(hdr); err != nil {
return err return err
} }
@ -263,7 +263,7 @@ func ImageTar(location string, ref *reference.Spec, prefix string, tw tarWriter,
hdr.Typeflag = tar.TypeSymlink hdr.Typeflag = tar.TypeSymlink
hdr.Linkname = resolv hdr.Linkname = resolv
hdr.ModTime = defaultModTime hdr.ModTime = defaultModTime
log.Debugf("image tar: %s %s add resolv symlink /etc/resolv.conf -> %s", ref, prefix, resolv) log.Tracef("image tar: %s %s add resolv symlink /etc/resolv.conf -> %s", ref, prefix, resolv)
if err := tw.WriteHeader(hdr); err != nil { if err := tw.WriteHeader(hdr); err != nil {
return err return err
} }
@ -274,12 +274,12 @@ func ImageTar(location string, ref *reference.Spec, prefix string, tw tarWriter,
} }
} else { } else {
if found, ok := touch[hdr.Name]; ok { if found, ok := touch[hdr.Name]; ok {
log.Debugf("image tar: %s %s add %s (touch)", ref, prefix, hdr.Name) log.Tracef("image tar: %s %s add %s (touch)", ref, prefix, hdr.Name)
hdr.ModTime = found.ModTime hdr.ModTime = found.ModTime
// record that we saw this one // record that we saw this one
touchFound[hdr.Name] = true touchFound[hdr.Name] = true
} else { } else {
log.Debugf("image tar: %s %s add %s (original)", ref, prefix, hdr.Name) log.Tracef("image tar: %s %s add %s (original)", ref, prefix, hdr.Name)
} }
hdr.Name = prefix + hdr.Name hdr.Name = prefix + hdr.Name
if hdr.Typeflag == tar.TypeLink { if hdr.Typeflag == tar.TypeLink {
@ -304,7 +304,7 @@ func ImageTar(location string, ref *reference.Spec, prefix string, tw tarWriter,
sort.Strings(touchNames) sort.Strings(touchNames)
for _, name := range touchNames { for _, name := range touchNames {
if touchFound[name] { if touchFound[name] {
log.Debugf("image tar: %s already found in original image", name) log.Tracef("image tar: %s already found in original image", name)
continue continue
} }
hdr := touch[name] hdr := touch[name]
@ -326,9 +326,9 @@ func ImageTar(location string, ref *reference.Spec, prefix string, tw tarWriter,
hdr.Size = 0 hdr.Size = 0
hdr.Typeflag = tar.TypeSymlink hdr.Typeflag = tar.TypeSymlink
hdr.Linkname = resolv hdr.Linkname = resolv
log.Debugf("image tar: %s %s add resolv symlink /etc/resolv.conf -> %s", ref, prefix, resolv) log.Tracef("image tar: %s %s add resolv symlink /etc/resolv.conf -> %s", ref, prefix, resolv)
} }
log.Debugf("image tar: creating %s", name) log.Tracef("image tar: creating %s", name)
if err := tw.WriteHeader(&hdr); err != nil { if err := tw.WriteHeader(&hdr); err != nil {
return err return err
} }
@ -489,7 +489,7 @@ func ImageBundle(prefix, location string, ref *reference.Spec, config []byte, ru
return err return err
} }
log.Debugf("image bundle: %s %s cfg: %s runtime: %s", prefix, ref, string(config), string(runtimeConfig)) log.Tracef("image bundle: %s %s cfg: %s runtime: %s", prefix, ref, string(config), string(runtimeConfig))
return nil return nil
} }

View File

@ -446,7 +446,7 @@ func AppendConfig(m0, m1 Moby) (Moby, error) {
// NewImage validates an parses yaml or json for a Image // NewImage validates an parses yaml or json for a Image
func NewImage(config []byte) (Image, error) { func NewImage(config []byte) (Image, error) {
log.Debugf("Reading label config: %s", string(config)) log.Tracef("Reading label config: %s", string(config))
mi := Image{} mi := Image{}

View File

@ -25,23 +25,38 @@ func (f *infoFormatter) Format(entry *log.Entry) ([]byte, error) {
} }
// SetupLogging once the flags have been parsed, setup the logging // SetupLogging once the flags have been parsed, setup the logging
func SetupLogging(quiet, verbose bool) error { func SetupLogging(quiet bool, verbose int, verboseSet bool) error {
// Set up logging // Set up logging
log.SetFormatter(new(infoFormatter)) log.SetFormatter(new(infoFormatter))
log.SetLevel(log.InfoLevel) log.SetLevel(log.InfoLevel)
if quiet && verbose { if quiet && verboseSet && verbose > 0 {
return errors.New("can't set quiet and verbose flag at the same time") return errors.New("can't set quiet and verbose flag at the same time")
} }
if quiet { switch {
case quiet, verbose == 0:
log.SetLevel(log.ErrorLevel) log.SetLevel(log.ErrorLevel)
case verbose == 1:
if verboseSet {
// Switch back to the standard formatter
log.SetFormatter(defaultLogFormatter)
} }
if verbose { log.SetLevel(log.InfoLevel)
case verbose == 2:
// Switch back to the standard formatter // Switch back to the standard formatter
log.SetFormatter(defaultLogFormatter) log.SetFormatter(defaultLogFormatter)
log.SetLevel(log.DebugLevel) log.SetLevel(log.DebugLevel)
// set go-containerregistry logging as well // set go-containerregistry logging as well
ggcrlog.Warn = stdlog.New(log.StandardLogger().WriterLevel(log.WarnLevel), "", 0) ggcrlog.Warn = stdlog.New(log.StandardLogger().WriterLevel(log.WarnLevel), "", 0)
ggcrlog.Debug = stdlog.New(log.StandardLogger().WriterLevel(log.DebugLevel), "", 0) ggcrlog.Debug = stdlog.New(log.StandardLogger().WriterLevel(log.DebugLevel), "", 0)
case verbose == 3:
// Switch back to the standard formatter
log.SetFormatter(defaultLogFormatter)
log.SetLevel(log.TraceLevel)
// set go-containerregistry logging as well
ggcrlog.Warn = stdlog.New(log.StandardLogger().WriterLevel(log.WarnLevel), "", 0)
ggcrlog.Debug = stdlog.New(log.StandardLogger().WriterLevel(log.DebugLevel), "", 0)
default:
return errors.New("verbose flag can only be set to 0, 1, 2 or 3")
} }
ggcrlog.Progress = stdlog.New(log.StandardLogger().WriterLevel(log.InfoLevel), "", 0) ggcrlog.Progress = stdlog.New(log.StandardLogger().WriterLevel(log.InfoLevel), "", 0)
return nil return nil

View File

@ -21,7 +21,7 @@ logfile=$(mktemp)
# do not include the sbom, because the SBoM unique IDs per file/package are *not* deterministic, # do not include the sbom, because the SBoM unique IDs per file/package are *not* deterministic,
# (currently based upon syft), and thus will make the file non-reproducible # (currently based upon syft), and thus will make the file non-reproducible
linuxkit build --no-sbom --format tar --o "${NAME}-1.tar" ./test1.yml linuxkit build --no-sbom --format tar --o "${NAME}-1.tar" ./test1.yml
linuxkit build -v --no-sbom --format tar --input-tar "${NAME}-1.tar" --o "${NAME}-2.tar" ./test2.yml 2>&1 | tee ${logfile} linuxkit build -v 2 --no-sbom --format tar --input-tar "${NAME}-1.tar" --o "${NAME}-2.tar" ./test2.yml 2>&1 | tee ${logfile}
# the logfile should indicate which parts were copied and which not # the logfile should indicate which parts were copied and which not
# we only know this because we built the test2.yml manually # we only know this because we built the test2.yml manually