go/neo/t/tzodb.go: Switch to tasks and task-integrated logging

See previous commits.

go/neo/t/tzodb.go

-// Copyright (C) 2017-2020  Nexedi SA and Contributors.
+// Copyright (C) 2017-2021  Nexedi SA and Contributors.
 //                          Kirill Smelkov <kirr@nexedi.com>
 //
 // This program is free software: you can Use, Study, Modify and Redistribute
@@ -33,7 +33,6 @@ import (
 	"hash/adler32"
 	"hash/crc32"
 	"io"
-	"log"
 	"os"
 	"sync/atomic"
 	"testing"
@@ -42,6 +41,8 @@ import (
 	"lab.nexedi.com/kirr/go123/prog"
 	"lab.nexedi.com/kirr/go123/xerr"
 	"lab.nexedi.com/kirr/go123/xsync"
+	"lab.nexedi.com/kirr/neo/go/internal/log"
+	"lab.nexedi.com/kirr/neo/go/internal/task"
 
 	"lab.nexedi.com/kirr/neo/go/zodb"
 	_ "lab.nexedi.com/kirr/neo/go/zodb/wks"
@@ -66,7 +67,7 @@ func (h nullHasher) BlockSize() int              { return 1 }
 
 
 // hashFlags installs common hash flags and returns function to retrieve selected hasher.
-func hashFlags(flags *flag.FlagSet) func() hasher {
+func hashFlags(ctx context.Context, flags *flag.FlagSet) func() hasher {
 	fnull    := flags.Bool("null",	false, "don't compute hash - just read data")
 	fadler32 := flags.Bool("adler32",false, "compute Adler32 checksum")
 	fcrc32   := flags.Bool("crc32",	false, "compute CRC32 checksum")
@@ -78,7 +79,7 @@ func hashFlags(flags *flag.FlagSet) func() hasher {
 		var h hasher
 		inith := func(name string, ctor func() hash.Hash) {
 			if h.name != "" {
-				log.Fatalf("duplicate hashes: %s and %s specified", h.name, name)
+				log.Fatalf(ctx, "duplicate hashes: %s and %s specified", h.name, name)
 			}
 
 			h.name = name
@@ -114,7 +115,7 @@ func zhashMain(argv []string) {
 	flags := flag.NewFlagSet("", flag.ExitOnError)
 	flags.Usage = func() { zhashUsage(os.Stderr); flags.PrintDefaults() }
 
-	fhash    := hashFlags(flags)
+	fhash    := hashFlags(ctx, flags)
 	fcheck   := flags.String("check", "",   "verify resulting hash to be = expected")
 	fbench   := flags.String("bench", "",   "use benchmarking format for output")
 	useprefetch := flags.Bool("useprefetch", false, "prefetch loaded objects")
@@ -130,17 +131,17 @@ func zhashMain(argv []string) {
 
 	h := fhash()
 	if h.Hash == nil {
-		log.Fatal("no hash function specified")
+		log.Fatal(ctx, "no hash function specified")
 	}
 
 	err := zhash(ctx, url, h, *useprefetch, *fbench, *fcheck)
 	if err != nil {
-		log.Fatal(err)
+		log.Fatal(ctx, err)
 	}
 }
 
 func zhash(ctx context.Context, url string, h hasher, useprefetch bool, bench, check string) (err error) {
-	defer xerr.Context(&err, "zhash")
+	defer task.Running(&ctx, "zhash")(&err)
 
 	stor, err := zodb.Open(ctx, url, &zodb.OpenOptions{ReadOnly: true})
 	if err != nil {
@@ -253,7 +254,7 @@ func zwrkMain(argv []string) {
 	flags := flag.NewFlagSet("", flag.ExitOnError)
 	flags.Usage = func() { zwrkUsage(os.Stderr); flags.PrintDefaults() }
 
-	fhash    := hashFlags(flags)
+	fhash    := hashFlags(ctx, flags)
 	fcheck   := flags.String("check", "",   "verify whole-database hash to be = expected")
 	fbench   := flags.String("bench", "",   "benchmarking format for output")
 	fnclient := flags.Int("nclient", 1,     "simulate so many clients")
@@ -267,19 +268,19 @@ func zwrkMain(argv []string) {
 
 	// XXX kill -bench and use labels in neotest
 	if *fbench == "" {
-		log.Fatal("-bench must be provided")
+		log.Fatal(ctx, "-bench must be provided")
 	}
 
 	url := flags.Arg(0)
 
 	h := fhash()
 	if (*fcheck != "") != (h.Hash != nil) {
-		log.Fatal("-check and -<hash> must be used together")
+		log.Fatal(ctx, "-check and -<hash> must be used together")
 	}
 
 	err := zwrk(ctx, url, *fnclient, h, *fbench, *fcheck)
 	if err != nil {
-		log.Fatal(err)
+		log.Fatal(ctx, err)
 	}
 }
 
@@ -319,7 +320,7 @@ func zwrk(ctx context.Context, url string, nwrk int, h hasher, bench, check stri
 
 
 	// benchmark parallel loads
-	defer xerr.Contextf(&err, "zwrk-%d/bench", nwrk)
+	defer task.Runningf(&ctx, "zwrk-%d/bench", nwrk)(&err)
 	r := testing.Benchmark(func (b *testing.B) {
 		wg := xsync.NewWorkGroup(ctx)
 		var n int64
@@ -378,7 +379,7 @@ func zwrk(ctx context.Context, url string, nwrk int, h hasher, bench, check stri
 
 // zwrkPreconnect establishes nwrk connections and warms them up.
 func zwrkPreconnect(ctx context.Context, url string, at zodb.Tid, nwrk int) (_ []zodb.IStorage, err error) {
-	defer xerr.Contextf(&err, "zwrk-%d/preconnect", nwrk)
+	defer task.Runningf(&ctx, "zwrk-%d/preconnect", nwrk)(&err)
 	storv := make([]zodb.IStorage, nwrk)
 
 	wg := xsync.NewWorkGroup(ctx)
@@ -440,7 +441,7 @@ func zwrkPreconnect(ctx context.Context, url string, at zodb.Tid, nwrk int) (_ [
 
 // zwrkPrepare serially reads all objects and computes per-object crc32.
 func zwrkPrepare(ctx context.Context, url string, h hasher, check string) (at zodb.Tid, objcheckv []uint32, err error) {
-	defer xerr.Context(&err, "zwrk/prepare")
+	defer task.Running(&ctx, "zwrk/prepare")(&err)
 
 	stor, err := zodb.Open(ctx, url, &zodb.OpenOptions{ReadOnly: true})
 	if err != nil {
@@ -497,9 +498,6 @@ var commands = prog.CommandRegistry{
 }
 
 func main() {
-	log.SetPrefix("tzodb: ")
-	log.SetFlags(0)
-
 	prog := prog.MainProg{
 		Name:       "tzodb",
 		Summary:    "tzodb is a tool to run ZODB-related benchmarks",
@@ -507,5 +505,6 @@ func main() {
 		HelpTopics: nil,
 	}
 
+	defer log.Flush()
 	prog.Main()
 }