initial version with fortio logger (#2)

* initial version with fortio logger

* adding threads/goroutines

* record GOMAXPROCS

* A bit more verbose log

* the goroutine part can be abstracted/reused

Makefile

@@ -0,0 +1,11 @@
+
+# Small arg for overview testing
+# 150 calls to logger (3 go routines * 10 iterations * (4 invisible + 1 visible)) so with 3*40 of them not logged unless -loglevel debug is passed:
+ARGS:=-n 10 -e 4 -r 3
+
+
+manual-check:
+	@echo "--- Manual eyeball test, should have 10 log entries (out of 50 made) ---"
+	go run . fortio $(ARGS) 2>&1 | jq -c
+	@echo "--- Manual eyeball test, should have all 50 entries - in color and with goroutine just for fun ---"
+	GOMAXPROCS=8 go run -race . fortio $(ARGS) -loglevel debug -logger-force-color=true -logger-goroutine=true

fortio.go

@@ -0,0 +1,27 @@
+package main
+
+import (
+	"fortio.org/log"
+)
+
+func FortioLog1(id string, numLogged int64, numExtraNotLogged int) {
+	// iterate numCalls time
+	for i := int64(1); i <= numLogged; i++ {
+		// Not optimized version - otherwise we can mutate the KeyVals
+		log.S(log.Info, "A visible log entry with 3 attributes",
+			log.Attr("iteration", i),
+			log.Str("id", id),
+			log.Str("logger", "fortio"),
+		)
+		for j := 1; j <= numExtraNotLogged; j++ {
+			// Not optimized version - otherwise we'd check
+			// if log.LogDebug() {...}
+			log.S(log.Debug, "Not visible entry with 4 attributes",
+				log.Str("id", id),
+				log.Attr("iteration", i),
+				log.Attr("sub-iteration", j),
+				log.Str("logger", "fortio"),
+			)
+		}
+	}
+}

main.go

@@ -1,13 +1,28 @@
 package main
 
 import (
+	"flag"
+	"fmt"
+	"runtime"
+	"sync"
+
 	"fortio.org/cli"
 	"fortio.org/log"
 	"fortio.org/scli"
 	"fortio.org/sets"
 )
 
+func userErrorf(format string, args ...interface{}) {
+	// Revert to color mode instead of json as this is a user error.
+	log.Config.ConsoleColor = true
+	log.SetColorMode()
+	cli.ErrUsage(format, args...)
+}
+
 func main() {
+	numCallsFlag := flag.Int64("n", 100, "Number of calls logged (info level), per goroutine `r`")
+	numExtraFlag := flag.Int("e", 9, "Number of extra debug calls (not logged for each `n` iteration), total call will be n*(e+1)")
+	numGoroutineFlag := flag.Int("r", 10, "Number of go routines to use (multiplies the other numbers)")
 	// Force JSON output even on console and disable expensive debug file/line logging
 	// as well as goroutine id logging which most other loggers don't have.
 	cli.BeforeFlagParseHook = func() {
@@ -27,9 +42,40 @@ func main() {
 	scli.ServerMain()
 	vSet := sets.FromSlice(valid)
 	if !vSet.Has(cli.Command) {
-		// Revert to color mode instead of json as this is a user error.
-		log.Config.ConsoleColor = true
-		log.SetColorMode()
-		cli.ErrUsage("Invalid sub-command %q, valid ones are %v", cli.Command, valid)
+		userErrorf("Invalid sub-command %q, valid ones are %v", cli.Command, valid)
+	}
+	numCalls := *numCallsFlag
+	numExtra := *numExtraFlag
+	numThrds := *numGoroutineFlag
+	log.S(log.Info, "Testing",
+		log.Str("logger", cli.Command),
+		log.Attr("num-calls", numCalls),
+		log.Attr("num-extra", numExtra),
+		log.Attr("num-goroutines", numThrds),
+		log.Attr("gomaxprocs", runtime.GOMAXPROCS(0)),
+	)
+	switch cli.Command {
+	case "fortio":
+		Drive(FortioLog1, numThrds, numCalls, numExtra)
+	case "zap":
+		userErrorf("Zap test/bench not implemented yet")
+		// ZapLog()
+	case "slog":
+		// SLog()
+		userErrorf("slog test/bench not implemented yet")
+	}
+}
+
+// Drive the given (iteration logging) function from multiple goroutines.
+func Drive(fn func(string, int64, int), numGoroutines int, numLogged int64, numExtraNotLogged int) {
+	// wait group
+	wg := sync.WaitGroup{}
+	wg.Add(numGoroutines)
+	for i := 1; i <= numGoroutines; i++ {
+		go func(c int) {
+			fn(fmt.Sprintf("R%d", c), numLogged, numExtraNotLogged)
+			wg.Done()
+		}(i)
 	}
+	wg.Wait()
 }