Add logging for analysis process

Signed-off-by: Ondrej Fabry <[email protected]>
ondrajz · ondrajz · Jan 1, 2025 · Mar 29, 2024 · Mar 29, 2024 · Dec 30, 2024
commit e7f3b3a5e7d68f33809702ecb260c152a71aac70
diff --git a/Makefile b/Makefile
@@ -38,7  38,7 @@ help:
 	@grep -E '^[a-zA-Z_-] :.*?## .*$$' $(MAKEFILE_LIST) | awk 'BEGIN {FS = ":.*?## "}; {printf "\033[36m%-30s\033[0m %s\n", $$1, $$2}'
 
 build:  ## Build go-callvis
-	go build -tags $(GO_BUILD_TAGS) -ldflags "$(GO_LDFLAGS)" $(GO_BUILD_ARGS)
 	go build -v -tags $(GO_BUILD_TAGS) -ldflags "$(GO_LDFLAGS)" $(GO_BUILD_ARGS)
 
 test:  ## Run unit tests
 	go test -tags $(GO_BUILD_TAGS) -ldflags "$(GO_LDFLAGS)" $(GO_BUILD_ARGS) -short -race ./...

diff --git a/analysis.go b/analysis.go
@@ -11,6  11,7 @@ import (
 	"os"
 	"path/filepath"
 	"strings"
 	"time"
 
 	"golang.org/x/tools/go/callgraph"
 	"golang.org/x/tools/go/callgraph/cha"
@@ -96,27  97,35 @@ func (a *analysis) DoAnalysis(
 	tests bool,
 	args []string,
 ) error {
 	logf("begin analysis")
 	defer logf("analysis done")
 
 	cfg := &packages.Config{
 		Mode:       packages.LoadAllSyntax,
 		Tests:      tests,
 		Dir:        dir,
 		BuildFlags: getBuildFlags(),
 	}
 
 	logf("loading packages")
 
 	initial, err := packages.Load(cfg, args...)
 	if err != nil {
 		return err
 	}
-
 	if packages.PrintErrors(initial) > 0 {
 		return fmt.Errorf("packages contain errors")
 	}
 
 	logf("loaded %d initial packages, building program", len(initial))
 
 	// Create and build SSA-form program representation.
 	mode := ssa.InstantiateGenerics
 	prog, pkgs := ssautil.AllPackages(initial, mode)
 	prog.Build()
 
 	logf("build done, computing callgraph (algo: %v)", algo)
 
 	var graph *callgraph.Graph
 	var mainPkg *ssa.Package
 
@@ -149,7  158,7 @@ func (a *analysis) DoAnalysis(
 		return fmt.Errorf("invalid call graph type: %s", a.opts.algo)
 	}
 
-	//cg.DeleteSyntheticNodes()
 	logf("callgraph resolved with %d nodes", len(graph.Nodes))
 
 	a.prog = prog
 	a.pkgs = pkgs
@@ -257,6  266,9 @@ func (a *analysis) Render() ([]byte, error) {
 		focusPkg *types.Package
 	)
 
 	start := time.Now()
 	logf("begin rendering")
 
 	if a.opts.focus != "" {
 		if ssaPkg = a.prog.ImportedPackage(a.opts.focus); ssaPkg == nil {
 			if strings.Contains(a.opts.focus, "/") {
@@ -283,7  295,7 @@ func (a *analysis) Render() ([]byte, error) {
 			}
 		}
 		focusPkg = ssaPkg.Pkg
-		logf("focusing: %v", focusPkg.Path())
 		logf("focusing package: %v (path: %v)", focusPkg.Name(), focusPkg.Path())
 	}
 
 	dot, err := printOutput(
@@ -302,6  314,8 @@ func (a *analysis) Render() ([]byte, error) {
 		return nil, fmt.Errorf("processing failed: %v", err)
 	}
 
 	logf("rendering done (took %v sec)", time.Since(start).Round(time.Millisecond).Seconds())
 
 	return dot, nil
 }
 

diff --git a/dot_cgo.go b/dot_cgo.go
@@ -20,9  20,11 @@ func runDotToImage(outfname string, format string, dot []byte) (string, error) {
     }
     defer func() {
         if err := graph.Close(); err != nil {
-            log.Fatal(err)
             log.Printf("error closing graph: %v", err)
         }
         if err := g.Close(); err != nil {
             log.Printf("error closing graphviz: %v", err)
         }
-        g.Close()
     }()
     var img string
     if outfname == "" {

diff --git a/handler.go b/handler.go
@@ -25,7  25,7 @@ func handler(w http.ResponseWriter, r *http.Request) {
 
 	var img string
 	if img = Analysis.FindCachedImg(); img != "" {
-		log.Println("serving file:", img)
 		log.Println("serving cached file:", img)
 		http.ServeFile(w, r, img)
 		return
 	}
@@ -38,17  38,17 @@ func handler(w http.ResponseWriter, r *http.Request) {
 
 	output, err := Analysis.Render()
 	if err != nil {
-		http.Error(w, err.Error(), http.StatusInternalServerError)
 		http.Error(w, fmt.Sprintf("rendering failed: %v", err.Error()), http.StatusInternalServerError)
 		return
 	}
 
 	if r.Form.Get("format") == "dot" {
-		log.Println("writing dot output..")
 		log.Println("writing dot output")
 		fmt.Fprint(w, string(output))
 		return
 	}
 
-	log.Printf("converting dot to %s..\n", *outputFormat)
 	log.Printf("converting dot to %s\n", *outputFormat)
 
 	img, err = dotToImage("", *outputFormat, output)
 	if err != nil {

diff --git a/main.go b/main.go
@@ -5,7  5,6 @@ import (
 	"flag"
 	"fmt"
 	"go/build"
-	"io/ioutil"
 	"log"
 	"net"
 	"net/http"
@@ -102,14  101,14 @@ func outputDot(fname string, outputFormat string) {
 		log.Fatalf("%v\n", err)
 	}
 
-	log.Println("writing dot output..")
 	log.Println("writing dot output")
 
-	writeErr := ioutil.WriteFile(fmt.Sprintf("%s.gv", fname), output, 0755)
 	writeErr := os.WriteFile(fmt.Sprintf("%s.gv", fname), output, 0755)
 	if writeErr != nil {
 		log.Fatalf("%v\n", writeErr)
 	}
 
-	log.Printf("converting dot to %s..\n", outputFormat)
 	log.Printf("converting dot to %s\n", outputFormat)
 
 	_, err = dotToImage(fname, outputFormat, output)
 	if err != nil {

diff --git a/output.go b/output.go
@@ -433,6  433,7 @@ func printOutput(
 		edges = append(edges, e)
 	}
 
 	logf("%d/%d nodes", len(nodeMap), len(cg.Nodes))
 	logf("%d/%d edges", len(edges), count)
 
 	title := ""