1
0

Improve logging

This commit is contained in:
dump_stack() 2023-03-19 12:36:19 +00:00
parent 78069c6240
commit 305c6972ca
Signed by: dump_stack
GPG Key ID: BE44DA8C062D87DC

58
pew.go
View File

@ -391,13 +391,13 @@ func dumpResult(q *qemu.System, ka config.Artifact, ki config.KernelInfo,
err := addToLog(db, q, ka, ki, res, tag) err := addToLog(db, q, ka, ki, res, tag)
if err != nil { if err != nil {
log.Print("[db] addToLog (", ka, ") error:", err) log.Warn().Err(err).Msgf("[db] addToLog (%v)", ka)
} }
if binary == "" && dist != pathDevNull { if binary == "" && dist != pathDevNull {
err = os.MkdirAll(dist, os.ModePerm) err = os.MkdirAll(dist, os.ModePerm)
if err != nil { if err != nil {
log.Print("os.MkdirAll (", ka, ") error:", err) log.Warn().Err(err).Msgf("os.MkdirAll (%v)", ka)
} }
path := fmt.Sprintf("%s/%s-%s-%s", dist, ki.DistroType, path := fmt.Sprintf("%s/%s-%s-%s", dist, ki.DistroType,
@ -408,7 +408,7 @@ func dumpResult(q *qemu.System, ka config.Artifact, ki config.KernelInfo,
err = copyFile(res.BuildArtifact, path) err = copyFile(res.BuildArtifact, path)
if err != nil { if err != nil {
log.Print("copyFile (", ka, ") error:", err) log.Warn().Err(err).Msgf("copy file (%v)", ka)
} }
} }
} }
@ -420,7 +420,7 @@ func copyArtifactAndTest(q *qemu.System, ka config.Artifact,
case config.KernelModule: case config.KernelModule:
res.Run.Output, err = q.CopyAndInsmod(res.BuildArtifact) res.Run.Output, err = q.CopyAndInsmod(res.BuildArtifact)
if err != nil { if err != nil {
log.Print(res.Run.Output, err) log.Error().Err(err).Msg(res.Run.Output)
return return
} }
res.Run.Ok = true res.Run.Ok = true
@ -432,14 +432,14 @@ func copyArtifactAndTest(q *qemu.System, ka config.Artifact,
} }
err = q.CopyFile(f.User, f.Local, f.Remote) err = q.CopyFile(f.User, f.Local, f.Remote)
if err != nil { if err != nil {
log.Print("error copy err:", err, f.Local, f.Remote) log.Error().Err(err).Msg("copy test file")
return return
} }
} }
res.Test.Output, err = testKernelModule(q, ka, remoteTest) res.Test.Output, err = testKernelModule(q, ka, remoteTest)
if err != nil { if err != nil {
log.Print(res.Test.Output, err) log.Error().Err(err).Msg(res.Test.Output)
return return
} }
res.Test.Ok = true res.Test.Ok = true
@ -453,13 +453,13 @@ func copyArtifactAndTest(q *qemu.System, ka config.Artifact,
res.Test.Output, err = testKernelExploit(q, ka, remoteTest, res.Test.Output, err = testKernelExploit(q, ka, remoteTest,
remoteExploit) remoteExploit)
if err != nil { if err != nil {
log.Print(res.Test.Output) log.Error().Err(err).Msg(res.Test.Output)
return return
} }
res.Run.Ok = true // does not really used res.Run.Ok = true // does not really used
res.Test.Ok = true res.Test.Ok = true
default: default:
log.Print("Unsupported artifact type") log.Fatal().Msg("Unsupported artifact type")
} }
return return
@ -495,17 +495,23 @@ func copyStandardModules(q *qemu.System, ki config.KernelInfo) (err error) {
return q.CopyDirectory("root", ki.ModulesPath, "/lib/modules/") return q.CopyDirectory("root", ki.ModulesPath, "/lib/modules/")
} }
func whatever(swg *sizedwaitgroup.SizedWaitGroup, ka config.Artifact, func testArtifact(swg *sizedwaitgroup.SizedWaitGroup, ka config.Artifact,
ki config.KernelInfo, binaryPath, testPath string, ki config.KernelInfo, binaryPath, testPath string,
qemuTimeout, dockerTimeout time.Duration, dist, tag string, qemuTimeout, dockerTimeout time.Duration, dist, tag string,
db *sql.DB) { db *sql.DB) {
slog := log.With().
Str("distro_type", ki.DistroType.String()).
Str("distro_release", ki.DistroRelease).
Str("kernel", ki.KernelRelease).
Logger()
defer swg.Done() defer swg.Done()
kernel := qemu.Kernel{KernelPath: ki.KernelPath, InitrdPath: ki.InitrdPath} kernel := qemu.Kernel{KernelPath: ki.KernelPath, InitrdPath: ki.InitrdPath}
q, err := qemu.NewSystem(qemu.X86x64, kernel, ki.RootFS) q, err := qemu.NewSystem(qemu.X86x64, kernel, ki.RootFS)
if err != nil { if err != nil {
log.Print("Qemu creation error:", err) slog.Error().Err(err).Msg("qemu init")
return return
} }
q.Timeout = qemuTimeout q.Timeout = qemuTimeout
@ -531,7 +537,7 @@ func whatever(swg *sizedwaitgroup.SizedWaitGroup, ka config.Artifact,
err = q.Start() err = q.Start()
if err != nil { if err != nil {
log.Print("Qemu start error:", err) slog.Error().Err(err).Msg("qemu start")
return return
} }
defer q.Stop() defer q.Stop()
@ -539,10 +545,7 @@ func whatever(swg *sizedwaitgroup.SizedWaitGroup, ka config.Artifact,
go func() { go func() {
for !q.Died { for !q.Died {
time.Sleep(time.Minute) time.Sleep(time.Minute)
log.Debug().Msgf("still alive %s %s %s %s", slog.Debug().Msg("still alive")
ka.Name, ki.DistroType,
ki.DistroRelease, ki.KernelRelease)
} }
}() }()
@ -555,7 +558,7 @@ func whatever(swg *sizedwaitgroup.SizedWaitGroup, ka config.Artifact,
tmp, err := ioutil.TempDir(tmpdir, "out-of-tree_") tmp, err := ioutil.TempDir(tmpdir, "out-of-tree_")
if err != nil { if err != nil {
log.Print("Temporary directory creation error:", err) slog.Error().Err(err).Msg("making tmp directory")
return return
} }
defer os.RemoveAll(tmp) defer os.RemoveAll(tmp)
@ -568,11 +571,10 @@ func whatever(swg *sizedwaitgroup.SizedWaitGroup, ka config.Artifact,
start := time.Now() start := time.Now()
result.BuildDir, result.BuildArtifact, result.Build.Output, err = result.BuildDir, result.BuildArtifact, result.Build.Output, err =
build(tmp, ka, ki, dockerTimeout) build(tmp, ka, ki, dockerTimeout)
log.Debug().Msgf("%s %s %s Build done in %v", slog.Debug().Str("duration", time.Now().Sub(start).String()).
ki.DistroType, ki.DistroRelease, ki.KernelRelease, Msg("build done")
time.Now().Sub(start))
if err != nil { if err != nil {
log.Print(err) log.Error().Err(err).Msg("build")
return return
} }
result.Build.Ok = true result.Build.Ok = true
@ -603,25 +605,23 @@ func whatever(swg *sizedwaitgroup.SizedWaitGroup, ka config.Artifact,
start := time.Now() start := time.Now()
err = copyStandardModules(q, ki) err = copyStandardModules(q, ki)
if err != nil { if err != nil {
log.Print(err) slog.Error().Err(err).Msg("copy standard modules")
return return
} }
log.Debug().Msgf("%s %s %s Modules copied in %v", slog.Debug().Str("duration", time.Now().Sub(start).String()).
ki.DistroType, ki.DistroRelease, ki.KernelRelease, Msg("copy standard modules")
time.Now().Sub(start))
} }
err = preloadModules(q, ka, ki, dockerTimeout) err = preloadModules(q, ka, ki, dockerTimeout)
if err != nil { if err != nil {
log.Print(err) slog.Error().Err(err).Msg("preload modules")
return return
} }
start := time.Now() start := time.Now()
copyArtifactAndTest(q, ka, &result, remoteTest) copyArtifactAndTest(q, ka, &result, remoteTest)
log.Debug().Msgf("%s %s %s Tests completed in %v", slog.Debug().Str("duration", time.Now().Sub(start).String()).
ki.DistroType, ki.DistroRelease, ki.KernelRelease, Msg("test completed")
time.Now().Sub(start))
} }
func shuffleKernels(a []config.KernelInfo) []config.KernelInfo { func shuffleKernels(a []config.KernelInfo) []config.KernelInfo {
@ -661,7 +661,7 @@ func performCI(ka config.Artifact, kcfg config.KernelConfig, binaryPath,
break break
} }
swg.Add() swg.Add()
go whatever(&swg, ka, kernel, binaryPath, go testArtifact(&swg, ka, kernel, binaryPath,
testPath, qemuTimeout, dockerTimeout, testPath, qemuTimeout, dockerTimeout,
dist, tag, db) dist, tag, db)
} }