Add histogram/more per frame stats (#46)

* Add histogram/more per frame stats

* tweak buckets

* wip provide json that fortio report can graph

* Add missing fields for fortio report

* Use the QPSLabel and ResponseLabel from fortio/fortio#984

* Working version and readme update

.gitignore

@@ -1,3 +1,4 @@
+*.json
 .history
 .golangci.yml
 .DS_Store

README.md

@@ -49,9 +49,15 @@ Image viewer screenshot:
 
 ![fps image viewer](fps_image_viewer.png)
 
-Additional flags/usage:
+Detailed statistics are saved in a JSON files and can be visualized or compared by running [fortio report](https://github.com/fortio/fortio#installation)
+
+![fps fortio histogram](histogram.png)
+
+### Usage
+
+Additional flags/command help:
 ```
-fps v0.17.0 usage:
+fps v0.18.0 usage:
 	fps [flags] [maxfps] or fps -i imagefiles...
 or 1 of the special arguments
 	fps {help|envhelp|version|buildinfo}
@@ -63,6 +69,8 @@ flags:
   -i	Arguments are now images files to show, no FPS test (hit any key to continue)
   -image string
     	Image file to display in monochrome in the background instead of the default one
+  -n number of frames
+    	Start immediately an FPS test with the specified number of frames (default is interactive)
   -nobox
     	Don't draw the box around the image, make the image full screen instead of 1 pixel less on all sides
   -truecolor

ansipixels/fps/fps.go

@@ -3,14 +3,18 @@ package main
 import (
 	"bytes"
 	_ "embed"
+	"encoding/json"
 	"errors"
 	"flag"
 	"fmt"
 	"os"
 	"strconv"
+	"strings"
 	"time"
 
 	"fortio.org/cli"
+	"fortio.org/fortio/periodic"
+	"fortio.org/fortio/stats"
 	"fortio.org/log"
 	"fortio.org/safecast"
 	"fortio.org/terminal"
@@ -20,8 +24,65 @@ import (
 
 const defaultMonoImageColor = "\033[34m" // ansi blue-ish
 
+func jsonOutput(jsonFileName string, data any) {
+	var j []byte
+	j, err := json.MarshalIndent(data, "", "  ")
+	if err != nil {
+		log.Fatalf("Unable to json serialize result: %v", err)
+	}
+	var f *os.File
+	f, err = os.Create(jsonFileName)
+	if err != nil {
+		log.Fatalf("Unable to create %s: %v", jsonFileName, err)
+	}
+	n, err := f.Write(append(j, '\n'))
+	if err != nil {
+		log.Fatalf("Unable to write json to %s: %v", jsonFileName, err)
+	}
+	err = f.Close()
+	if err != nil {
+		log.Fatalf("Close error for %s: %v", jsonFileName, err)
+	}
+	fmt.Printf("Successfully wrote %d bytes of Json data (visualize with %sfortio report%s):\n%s\n",
+		n, log.ANSIColors.Cyan, log.ANSIColors.Reset, jsonFileName)
+}
+
+var (
+	perfResults = &Results{
+		QPSLabel:      "FPS",
+		ResponseLabel: "Frame duration",
+		RetCodes:      make(map[string]int64),
+	}
+	noJSON = flag.Bool("nojson", false,
+		"Don't output json file with results that otherwise get produced and can be visualized with fortio report")
+)
+
+type Results struct {
+	periodic.RunnerResults
+	RetCodes      map[string]int64
+	Destination   string // shows up in fortio graph title
+	StartTime     time.Time
+	QPSLabel      string
+	ResponseLabel string
+	hist          *stats.Histogram
+}
+
 func main() {
-	os.Exit(Main())
+	ret := Main()
+	if !*noJSON && perfResults.hist != nil && perfResults.hist.Count > 0 {
+		perfResults.DurationHistogram = perfResults.hist.Export().CalcPercentiles([]float64{50, 75, 90, 99, 99.9})
+		perfResults.RetCodes["OK"] = perfResults.hist.Count
+		perfResults.RunType = "FPS"
+		ro := &periodic.RunnerOptions{
+			Labels:  perfResults.Labels,
+			RunType: perfResults.RunType,
+		}
+		ro.GenID()
+		perfResults.ID = ro.ID
+		fname := ro.ID + ".json"
+		jsonOutput(fname, perfResults)
+	}
+	os.Exit(ret)
 }
 
 func isStopKey(ap *ansipixels.AnsiPixels) bool {
@@ -68,13 +129,13 @@ func charAt(ap *ansipixels.AnsiPixels, pos, w, h int, what string) {
 	ap.WriteAtStr(x+ap.Margin, y+ap.Margin, what)
 }
 
-func animate(ap *ansipixels.AnsiPixels, frame uint) {
+func animate(ap *ansipixels.AnsiPixels, frame int64) {
 	w := ap.W
 	h := ap.H
 	w -= 2 * ap.Margin
 	h -= 2 * ap.Margin
 	total := 2*w + 2*h
-	pos := safecast.MustConvert[int](frame % safecast.MustConvert[uint](total))
+	pos := safecast.MustConvert[int](frame % safecast.MustConvert[int64](total))
 	charAt(ap, pos+2, w, h, "\033[31m█") // Red
 	charAt(ap, pos+1, w, h, "\033[32m█") // Green
 	charAt(ap, pos, w, h, "\033[34m█")   // Blue
@@ -197,15 +258,24 @@ func imagesViewer(ap *ansipixels.AnsiPixels, imageFiles []string) int { //nolint
 	}
 }
 
-func Main() int { //nolint:funlen,gocognit,gocyclo // color and mode if/else are a bit long.
+func setLabels(labels ...string) {
+	perfResults.Labels = strings.Join(labels, ", ")
+}
+
+func Main() int { //nolint:funlen,gocognit,gocyclo,maintidx // color and mode if/else are a bit long.
 	defaultTrueColor := false
 	if os.Getenv("COLORTERM") != "" {
 		defaultTrueColor = true
 	}
 	defaultColor := false
-	if os.Getenv("TERM") == "xterm-256color" {
+	tenv := os.Getenv("TERM")
+	switch tenv {
+	case "xterm-256color":
 		defaultColor = true
+	case "":
+		tenv = "TERM not set"
 	}
+	perfResults.Destination = tenv
 	imgFlag := flag.String("image", "", "Image file to display in monochrome in the background instead of the default one")
 	colorFlag := flag.Bool("color", defaultColor,
 		"If your terminal supports color, this will load image in (216) colors instead of monochrome")
@@ -215,6 +285,7 @@ func Main() int { //nolint:funlen,gocognit,gocyclo // color and mode if/else are
 	noboxFlag := flag.Bool("nobox", false,
 		"Don't draw the box around the image, make the image full screen instead of 1 pixel less on all sides")
 	imagesOnlyFlag := flag.Bool("i", false, "Arguments are now images files to show, no FPS test (hit any key to continue)")
+	exactlyFlag := flag.Int64("n", 0, "Start immediately an FPS test with the specified `number of frames` (default is interactive)")
 	cli.MinArgs = 0
 	cli.MaxArgs = -1
 	cli.ArgsHelp = "[maxfps] or fps -i imagefiles..."
@@ -235,7 +306,14 @@ func Main() int { //nolint:funlen,gocognit,gocyclo // color and mode if/else are
 		}
 		fpsStr = fmt.Sprintf("%.1f", fpsLimit)
 		hasFPSLimit = true
+		perfResults.hist = stats.NewHistogram(0, .01/fpsLimit)
+	} else {
+		// with max fps expect values in the tens of usec range with usec precision (at max fps for fast terminals)
+		perfResults.hist = stats.NewHistogram(0, 0.0000001)
 	}
+	perfResults.Exactly = *exactlyFlag
+	perfResults.RequestedQPS = fpsStr
+	perfResults.Version = "fps " + cli.LongVersion
 	ap := ansipixels.NewAnsiPixels(max(25, fpsLimit)) // initial fps for the start screen and/or the image viewer.
 	if err := ap.Open(); err != nil {
 		log.Fatalf("Not a terminal: %v", err)
@@ -300,7 +378,9 @@ func Main() int { //nolint:funlen,gocognit,gocyclo // color and mode if/else are
 	// FPS test
 	fps := 0.0
 	// sleep := 1 * time.Second / time.Duration(fps)
-	err = ap.ReadOrResizeOrSignal()
+	if perfResults.Exactly <= 0 {
+		err = ap.ReadOrResizeOrSignal()
+	}
 	if err != nil {
 		return log.FErrf("Error reading initial key: %v", err)
 	}
@@ -318,20 +398,22 @@ func Main() int { //nolint:funlen,gocognit,gocyclo // color and mode if/else are
 	if err = ap.OnResize(); err != nil {
 		return log.FErrf("Error showing image: %v", err)
 	}
-	frames := uint(0)
+	frames := int64(0)
 	var elapsed time.Duration
 	var entry []byte
 	sendableTickerChan := make(chan time.Time, 1)
 	var tickerChan <-chan time.Time
+	perfResults.StartTime = time.Now()
 	startTime := hrtime.Now()
 	now := startTime
 	if hasFPSLimit {
 		ticker := time.NewTicker(time.Second / time.Duration(fpsLimit))
 		tickerChan = ticker.C
 	} else {
 		tickerChan = sendableTickerChan
-		sendableTickerChan <- time.Now()
+		sendableTickerChan <- perfResults.StartTime
 	}
+	setLabels("fps "+strings.TrimSuffix(fpsStr, ".0"), tenv, fmt.Sprintf("%dx%d", ap.W, ap.H))
 	for {
 		select {
 		case s := <-ap.C:
@@ -345,12 +427,24 @@ func Main() int { //nolint:funlen,gocognit,gocyclo // color and mode if/else are
 			continue // was a resize without error, get back to the fps loop.
 		case v := <-tickerChan:
 			elapsed = hrtime.Since(now)
-			fps = 1. / elapsed.Seconds()
+			sec := elapsed.Seconds()
+			if frames > 0 {
+				perfResults.hist.Record(sec) // record in milliseconds
+			}
+			fps = 1. / sec
 			now = hrtime.Now()
+			perfResults.ActualDuration = (now - startTime)
+			perfResults.ActualQPS = float64(frames) / perfResults.ActualDuration.Seconds()
+			// stats.Record("fps", fps)
 			ap.WriteAt(ap.W/2-20, ap.H/2+2, " Last frame %s%v%s FPS: %s%.0f%s Avg %s%.2f%s ",
 				log.ANSIColors.Green, elapsed.Round(10*time.Microsecond), log.ANSIColors.Reset,
 				log.ANSIColors.BrightRed, fps, log.ANSIColors.Reset,
-				log.ANSIColors.Cyan, float64(frames)/(now-startTime).Seconds(), log.ANSIColors.Reset)
+				log.ANSIColors.Cyan, perfResults.ActualQPS, log.ANSIColors.Reset)
+			ap.WriteAt(ap.W/2-20, ap.H/2+3, " Best %.1f Worst %.1f: %.1f +/- %.1f ",
+				1/perfResults.hist.Min, 1/perfResults.hist.Max, 1/perfResults.hist.Avg(), 1/perfResults.hist.StdDev())
+			if perfResults.Exactly > 0 && frames >= perfResults.Exactly {
+				return 0
+			}
 			animate(ap, frames)
 			// Request cursor position (note that FPS is about the same without it, the Flush seems to be enough)
 			_, _, err = ap.ReadCursorPos()

go.mod

@@ -4,6 +4,7 @@ go 1.22.7
 
 require (
 	fortio.org/cli v1.9.0
+	fortio.org/fortio v1.66.5
 	fortio.org/log v1.16.0
 	fortio.org/safecast v1.0.0
 	fortio.org/term v0.23.0-fortio-6
@@ -15,8 +16,10 @@ require (
 // replace fortio.org/term => ../term
 
 require (
+	fortio.org/sets v1.2.0 // indirect
 	fortio.org/struct2env v0.4.1 // indirect
 	fortio.org/version v1.0.4 // indirect
 	github.com/kortschak/goroutine v1.1.2 // indirect
 	golang.org/x/crypto/x509roots/fallback v0.0.0-20240916204253-42ee18b96377 // indirect
+	golang.org/x/exp v0.0.0-20240904232852-e7e105dedf7e // indirect
 )

go.sum

@@ -1,22 +1,42 @@
+fortio.org/assert v1.2.1 h1:48I39urpeDj65RP1KguF7akCjILNeu6vICiYMEysR7Q=
+fortio.org/assert v1.2.1/go.mod h1:039mG+/iYDPO8Ibx8TrNuJCm2T2SuhwRI3uL9nHTTls=
 fortio.org/cli v1.9.0 h1:cPgNHvrjxznmbmwuXSwPqQLKZ+RMW8i0iAOESLjt1aI=
 fortio.org/cli v1.9.0/go.mod h1:pk/JBE8LcXtNuo5Yj2bLsVbwPaHo8NWdbstSN0cpbFk=
+fortio.org/dflag v1.7.2 h1:lUhXFvDlw4CJj/q7hPv/TC+n/wVoQylzQO6bUg5GQa0=
+fortio.org/dflag v1.7.2/go.mod h1:6yO/NIgrWfQH195WbHJ3Y45SCx11ffivQjfx2C/FS1U=
+fortio.org/fortio v1.66.5 h1:WTJzTGOA12YWZSM5g43602lH+GOsmP3eKHXLnuRW4vs=
+fortio.org/fortio v1.66.5/go.mod h1:gOaugOHVf8PU0R5CjXUPlFTZa81sdcZPErvWfLDI2ug=
 fortio.org/log v1.16.0 h1:GhU8/9NkYZmEIzvTN/DTMedDAStLJraWUUVUA2EbNDc=
 fortio.org/log v1.16.0/go.mod h1:t58Spg9njjymvRioh5F6qKGSupEsnMjXLGWIS1i3khE=
 fortio.org/safecast v1.0.0 h1:dr3131WPX8iS1pTf76+39WeXbTrerDYLvi9s7Oi3wiY=
 fortio.org/safecast v1.0.0/go.mod h1:xZmcPk3vi4kuUFf+tq4SvnlVdwViqf6ZSZl91Jr9Jdg=
+fortio.org/scli v1.15.2 h1:vWXt4QOViXNWy4Gdm7d2FDfptzWD00QiWzYAM/IUF7c=
+fortio.org/scli v1.15.2/go.mod h1:XvY2JglgCeeZOIc5CrfBTtcsxkVV8xmGL5ykAcBjEHI=
+fortio.org/sets v1.2.0 h1:FBfC7R2xrOJtkcioUbY6WqEzdujuBoZRbSdp1fYF4Kk=
+fortio.org/sets v1.2.0/go.mod h1:J2BwIxNOLWsSU7IMZUg541kh3Au4JEKHrghVwXs68tE=
 fortio.org/struct2env v0.4.1 h1:rJludAMO5eBvpWplWEQNqoVDFZr4RWMQX7RUapgZyc0=
 fortio.org/struct2env v0.4.1/go.mod h1:lENUe70UwA1zDUCX+8AsO663QCFqYaprk5lnPhjD410=
 fortio.org/term v0.23.0-fortio-6 h1:pKrUX0tKOxyEhkhLV50oJYucTVx94rzFrXc24lIuLvk=
 fortio.org/term v0.23.0-fortio-6/go.mod h1:7buBfn81wEJUGWiVjFNiUE/vxWs5FdM9c7PyZpZRS30=
 fortio.org/version v1.0.4 h1:FWUMpJ+hVTNc4RhvvOJzb0xesrlRmG/a+D6bjbQ4+5U=
 fortio.org/version v1.0.4/go.mod h1:2JQp9Ax+tm6QKiGuzR5nJY63kFeANcgrZ0osoQFDVm0=
+github.com/fsnotify/fsnotify v1.7.0 h1:8JEhPFa5W2WU7YfeZzPNqzMP6Lwt7L2715Ggo0nosvA=
+github.com/fsnotify/fsnotify v1.7.0/go.mod h1:40Bi/Hjc2AVfZrqy+aj+yEI+/bRxZnMJyTJwOpGvigM=
+github.com/google/uuid v1.6.0 h1:NIvaJDMOsjHA8n1jAhLSgzrAzy1Hgr+hNrb57e+94F0=
+github.com/google/uuid v1.6.0/go.mod h1:TIyPZe4MgqvfeYDBFedMoGGpEw/LqOeaOT+nhxU+yHo=
 github.com/kortschak/goroutine v1.1.2 h1:lhllcCuERxMIK5cYr8yohZZScL1na+JM5JYPRclWjck=
 github.com/kortschak/goroutine v1.1.2/go.mod h1:zKpXs1FWN/6mXasDQzfl7g0LrGFIOiA6cLs9eXKyaMY=
 github.com/loov/hrtime v1.0.3 h1:LiWKU3B9skJwRPUf0Urs9+0+OE3TxdMuiRPOTwR0gcU=
 github.com/loov/hrtime v1.0.3/go.mod h1:yDY3Pwv2izeY4sq7YcPX/dtLwzg5NU1AxWuWxKwd0p0=
 golang.org/x/crypto/x509roots/fallback v0.0.0-20240916204253-42ee18b96377 h1:aDWu69N3Si4isYMY1ppnuoGEFypX/E5l4MWA//GPClw=
 golang.org/x/crypto/x509roots/fallback v0.0.0-20240916204253-42ee18b96377/go.mod h1:kNa9WdvYnzFwC79zRpLRMJbdEFlhyM5RPFBBZp/wWH8=
+golang.org/x/exp v0.0.0-20240904232852-e7e105dedf7e h1:I88y4caeGeuDQxgdoFPUq097j7kNfw6uvuiNxUBfcBk=
+golang.org/x/exp v0.0.0-20240904232852-e7e105dedf7e/go.mod h1:akd2r19cwCdwSwWeIdzYQGa/EZZyqcOdwWiwj5L5eKQ=
 golang.org/x/image v0.20.0 h1:7cVCUjQwfL18gyBJOmYvptfSHS8Fb3YUDtfLIZ7Nbpw=
 golang.org/x/image v0.20.0/go.mod h1:0a88To4CYVBAHp5FXJm8o7QbUl37Vd85ply1vyD8auM=
+golang.org/x/net v0.29.0 h1:5ORfpBpCs4HzDYoodCDBbwHzdR5UrLBZ3sOnUJmFoHo=
+golang.org/x/net v0.29.0/go.mod h1:gLkgy8jTGERgjzMic6DS9+SP0ajcu6Xu3Orq/SpETg0=
 golang.org/x/sys v0.25.0 h1:r+8e+loiHxRqhXVl6ML1nO3l1+oFoWbnlu2Ehimmi34=
 golang.org/x/sys v0.25.0/go.mod h1:/VUhepiaJMQUp4+oa/7Zr1D23ma6VTLIYjOOTFZPUcA=
+golang.org/x/text v0.18.0 h1:XvMDiNzPAl0jr17s6W9lcaIhGUfUORdGCNsuLmPG224=
+golang.org/x/text v0.18.0/go.mod h1:BuEKDfySbSR4drPmRPG/7iBdf8hvFMuRexcpahXilzY=