Investigating slowness of golang/go executable on Windows?

example_output_windows.txt

NOTE: pathext contains 11 extensions
NOTE: path has 50 entries
goos: windows
goarch: amd64
pkg: golang-exec-slow-testbed
BenchmarkBuiltinUnknownCommand
BenchmarkBuiltinUnknownCommand-12                                      	       3	 398999967 ns/op
BenchmarkBuiltinKnownCommand
BenchmarkBuiltinKnownCommand-12                                        	     218	   5467874 ns/op
BenchmarkLocalCopyWithUnknownCommand
BenchmarkLocalCopyWithUnknownCommand-12                                	       3	 403333200 ns/op
BenchmarkLocalCopyWithKnownCommand
BenchmarkLocalCopyWithKnownCommand-12                                  	     222	   5447606 ns/op
BenchmarkFindExecutableWithExistingFileButNoExtensions
BenchmarkFindExecutableWithExistingFileButNoExtensions-12              	  190485	      6300 ns/op
BenchmarkFindExecutableWithExistingFileWithSomeExtensions
BenchmarkFindExecutableWithExistingFileWithSomeExtensions-12           	  184611	      6636 ns/op
BenchmarkFindExecutableWithExistingFileWithRealExtensions
BenchmarkFindExecutableWithExistingFileWithRealExtensions-12           	  193545	      6505 ns/op
BenchmarkFindExecutableWithNonExistingFileButNoExtensions
BenchmarkFindExecutableWithNonExistingFileButNoExtensions-12           	    3242	    371683 ns/op
BenchmarkFindExecutableWithNonExistingFileWithSomeExtensions
BenchmarkFindExecutableWithNonExistingFileWithSomeExtensions-12        	    1071	   1091504 ns/op
BenchmarkFindExecutableWithNonExistingFileWithRealExtensions
BenchmarkFindExecutableWithNonExistingFileWithRealExtensions-12        	     298	   4073811 ns/op
BenchmarkFindExecutableOnExistingFileProportionalToPathLength
BenchmarkFindExecutableOnExistingFileProportionalToPathLength-12       	    3428	    330804 ns/op
BenchmarkFindExecutableOnNonExistingFileProportionalToPathLength
BenchmarkFindExecutableOnNonExistingFileProportionalToPathLength-12    	       5	 204799720 ns/op
BenchmarkStatOnExistingFile
BenchmarkStatOnExistingFile-12                                         	  187501	      6240 ns/op
BenchmarkStatOnNonExistingFile
BenchmarkStatOnNonExistingFile-12                                      	    3242	    376073 ns/op
PASS

Process finished with exit code 0

example_output_wsl.txt

NOTE: pathext contains 0 extensions
NOTE: path has 57 entries
wrote CPU profile to builtin_known.prof
wrote CPU profile to builtin_unknown.prof
goos: linux
goarch: amd64
pkg: golang-exec-slow-testbed
BenchmarkBuiltinUnknownCommand-12                                              4         288830750 ns/op
BenchmarkBuiltinKnownCommand-12                                           248312              5268 ns/op
BenchmarkLocalCopyWithUnknownCommand-12                                        4         291618275 ns/op
BenchmarkLocalCopyWithKnownCommand-12                                     240192              5041 ns/op
BenchmarkFindExecutableWithExistingFileButNoExtensions-12                    573           2075049 ns/op
BenchmarkFindExecutableWithExistingFileWithSomeExtensions-12                 582           2137966 ns/op
BenchmarkFindExecutableWithExistingFileWithRealExtensions-12                 579           2034148 ns/op
BenchmarkFindExecutableWithNonExistingFileButNoExtensions-12                2415            479138 ns/op
BenchmarkFindExecutableWithNonExistingFileWithSomeExtensions-12             2637            476540 ns/op
BenchmarkFindExecutableWithNonExistingFileWithRealExtensions-12             2622            472515 ns/op
BenchmarkFindExecutableOnExistingFileProportionalToPathLength-12               9         115634533 ns/op
BenchmarkFindExecutableOnNonExistingFileProportionalToPathLength-12           45          27054131 ns/op
BenchmarkStatOnExistingFile-12                                               596           2033425 ns/op
BenchmarkStatOnNonExistingFile-12                                           2502            473269 ns/op
PASS
ok      golang-exec-slow-testbed        20.892s

lookpath_linux.go

// +build linux

// THIS IS COPIED FROM GO STD LIBRARY

package main

import (
	"errors"
	"os"
	"path/filepath"
	"strings"
	"os/exec"
)


var ErrNotFound = errors.New("executable file not found in $PATH")

// bodged to have same signature as the Windows implementation for test purposes
func findExecutable(file string, exts []string) (string, error) {
	_ = exts

	d, err := os.Stat(file)
	if err != nil {
		return "", err
	}
	if m := d.Mode(); !m.IsDir() && m&0111 != 0 {
		return "", nil
	}
	return "", os.ErrPermission
}

func LookPath(file string) (string, error) {
	if strings.Contains(file, "/") {
		_, err := findExecutable(file, nil)
		if err == nil {
			return file, nil
		}
		return "", &exec.Error{file, err}
	}
	path := os.Getenv("PATH")
	for _, dir := range filepath.SplitList(path) {
		if dir == "" {
			// Unix shell semantics: path element "" means "."
			dir = "."
		}
		path := filepath.Join(dir, file)
		if _, err := findExecutable(path, nil); err == nil {
			return path, nil
		}
	}
	return "", &exec.Error{file, ErrNotFound}
}

lookpath_test.go

package main

import (
	"fmt"
	"os"
	"os/exec"
	"path/filepath"
	"runtime"
	"runtime/pprof"
	"testing"
)

var (
	pathExt      = os.Getenv("PATHEXT")
	realExtList  = filepath.SplitList(pathExt)
	shortExtList []string

	rawPath   = os.Getenv("PATH")
	splitPath = filepath.SplitList(rawPath)

	pathLength = len(splitPath)

	profiledRepetitions = 1

	knownCommand string
	unknownCommand = "made-up-command"

	existingFile = "lookpath_test.go"
	nonExistingFile = "doesnt-exist"
)

func init() {
	fmt.Printf("NOTE: pathext contains %v extensions\n", len(realExtList))
	fmt.Printf("NOTE: path has %v entries\n", pathLength)

	if len(realExtList) > 3 {
		shortExtList = realExtList[:3]
	}

	if runtime.GOOS == "windows" {
		knownCommand = "cmd"
	} else {
		knownCommand = "ls"
	}
}

func BenchmarkBuiltinUnknownCommand(b *testing.B) {
	for i := 0; i < b.N; i++ {
		_, _ = exec.LookPath(unknownCommand)
	}
}

func BenchmarkBuiltinKnownCommand(b *testing.B) {
	for i := 0; i < b.N; i++ {
		_, _ = exec.LookPath(knownCommand)
	}
}

func TestProfileBuiltin(b *testing.T) {
	profiled("builtin_known.prof", func() {
		for i := 0; i < profiledRepetitions; i++ {
			_, _ = exec.LookPath(knownCommand)
		}
	})
	profiled("builtin_unknown.prof", func() {
		for i := 0; i < profiledRepetitions; i++ {
			_, _ = exec.LookPath(unknownCommand)
		}
	})
}

func BenchmarkLocalCopyWithUnknownCommand(b *testing.B) {
	for i := 0; i < b.N; i++ {
		_, _ = LookPath(unknownCommand)
	}
}

func BenchmarkLocalCopyWithKnownCommand(b *testing.B) {
	for i := 0; i < b.N; i++ {
		_, _ = LookPath(knownCommand)
	}
}

func BenchmarkFindExecutableWithExistingFileButNoExtensions(b *testing.B) {
	for i := 0; i < b.N; i++ {
		_, _ = findExecutable(existingFile, nil)
	}
}

func BenchmarkFindExecutableWithExistingFileWithSomeExtensions(b *testing.B) {
	for i := 0; i < b.N; i++ {
		_, _ = findExecutable(existingFile, shortExtList)
	}
}

func BenchmarkFindExecutableWithExistingFileWithRealExtensions(b *testing.B) {
	for i := 0; i < b.N; i++ {
		_, _ = findExecutable(existingFile, realExtList)
	}
}

func BenchmarkFindExecutableWithNonExistingFileButNoExtensions(b *testing.B) {
	for i := 0; i < b.N; i++ {
		_, _ = findExecutable(nonExistingFile, nil)
	}
}

func BenchmarkFindExecutableWithNonExistingFileWithSomeExtensions(b *testing.B) {
	for i := 0; i < b.N; i++ {
		_, _ = findExecutable(nonExistingFile, shortExtList)
	}
}

func BenchmarkFindExecutableWithNonExistingFileWithRealExtensions(b *testing.B) {
	for i := 0; i < b.N; i++ {
		_, _ = findExecutable(nonExistingFile, realExtList)
	}
}

func BenchmarkFindExecutableOnExistingFileProportionalToPathLength(b *testing.B) {
	for i := 0; i < b.N; i++ {
		for i := 0; i < pathLength; i++ {
			_, _ = findExecutable(existingFile, realExtList)
		}
	}
}

func BenchmarkFindExecutableOnNonExistingFileProportionalToPathLength(b *testing.B) {
	for i := 0; i < b.N; i++ {
		for i := 0; i < pathLength; i++ {
			_, _ = findExecutable(nonExistingFile, realExtList)
		}
	}
}

func BenchmarkStatOnExistingFile(b *testing.B) {
	for i := 0; i < b.N; i++ {
		_, _ = os.Stat(existingFile)
	}
}

func BenchmarkStatOnNonExistingFile(b *testing.B) {
	for i := 0; i < b.N; i++ {
		_, _ = os.Stat(nonExistingFile)
	}
}

func profiled(path string, f func()) {
	file, err := os.Create(path)
	if err != nil {
		panic(fmt.Sprintf("failed to create CPU profile file: %v", err))
	}

	if err := pprof.StartCPUProfile(file); err != nil {
		panic(fmt.Sprintf("failed to start CPU profile: %v", err))
	}

	defer pprof.StopCPUProfile()

	f()

	fmt.Printf("wrote CPU profile to %s\n", path)
}

lookpath_windows.go

// +build windows

// THIS IS COPIED FROM GO STD LIBRARY

package main

import (
	"errors"
	"os"
	"os/exec"
	"path/filepath"
	"strings"
)

func LookPath(file string) (string, error) {
	var exts []string
	x := os.Getenv(`PATHEXT`)
	if x != "" {
		for _, e := range strings.Split(strings.ToLower(x), `;`) {
			if e == "" {
				continue
			}
			if e[0] != '.' {
				e = "." + e
			}
			exts = append(exts, e)
		}
	} else {
		exts = []string{".com", ".exe", ".bat", ".cmd"}
	}

	if strings.ContainsAny(file, `:\/`) {
		if f, err := findExecutable(file, exts); err == nil {
			return f, nil
		} else {
			return "", &exec.Error{Name: file, Err: err}
		}
	}
	if f, err := findExecutable(filepath.Join(".", file), exts); err == nil {
		return f, nil
	}
	path := os.Getenv("path")
	for _, dir := range filepath.SplitList(path) {
		if f, err := findExecutable(filepath.Join(dir, file), exts); err == nil {
			return f, nil
		}
	}
	return "", &exec.Error{Name: file, Err: ErrNotFound}
}

func findExecutable(file string, exts []string) (string, error) {
	if len(exts) == 0 {
		return file, chkStat(file)
	}
	if hasExt(file) {
		if chkStat(file) == nil {
			return file, nil
		}
	}
	for _, e := range exts {
		if f := file + e; chkStat(f) == nil {
			return f, nil
		}
	}
	return "", os.ErrNotExist
}

func chkStat(file string) error {
	d, err := os.Stat(file)
	if err != nil {
		return err
	}
	if d.IsDir() {
		return os.ErrPermission
	}
	return nil
}

func hasExt(file string) bool {
	i := strings.LastIndex(file, ".")
	if i < 0 {
		return false
	}
	return strings.LastIndexAny(file, `:\/`) < i
}

var ErrNotFound = errors.New("executable file not found in %PATH%")

Here's my output:

-------------------- builtin function --------------------
test builtin (unknown command)  took 424.8237ms (took 3 iterations)
test builtin (known command)    took 70.49508ms (took 15 iterations)
-------------------- profiling builtin function --------------------
wrote CPU profile to builtin_known.prof
wrote CPU profile to builtin_unknown.prof
-------------------- local copy - should be same as builtin, just a copy --------------------
test local (unknown command)    took 361.116233ms       (took 3 iterations)
test local (known command)      took 71.714985ms        (took 14 iterations)
-------------------- local copy: findExecutable (existing file, various extension counts) --------------------
NOTE: pathext contains 12 extensions
test findExecutable (existing file, no exts)    took 762.946µs  (took 1312 iterations)
test findExecutable (existing file, some exts)  took 781.074µs  (took 1281 iterations)
test findExecutable (existing file, many exts)  took 800.306µs  (took 1250 iterations)
-------------------- local copy: findExecutable (non-existing file, various extension counts) --------------------
test findExecutable (non-existing file, no exts)        took 1.150444ms (took 871 iterations)
test findExecutable (non-existing file, some exts)      took 3.246784ms (took 308 iterations)
test findExecutable (non-existing file, many exts)      took 13.084706ms        (took 77 iterations)
-------------------- local copy: findExecutable (repeated dumbly) --------------------
NOTE: path has 23 entries
test findExecutable (existing file)     took 16.72877ms (took 60 iterations)
test findExecutable (non-existing file) took 286.9654ms (took 4 iterations)
-------------------- os.Stat --------------------
test stat (existing file)       took 733.236µs  (took 1364 iterations)
test stat (non-existing file)   took 1.024477ms (took 978 iterations)

NOTE: pathext contains 0 extensions
NOTE: path has 14 entries
wrote CPU profile to builtin_known.prof
wrote CPU profile to builtin_unknown.prof
goos: linux
goarch: amd64
BenchmarkBuiltinUnknownCommand-24                                      	   53644	     22541 ns/op
BenchmarkBuiltinKnownCommand-24                                        	  148549	      7621 ns/op
BenchmarkLocalCopyWithUnknownCommand-24                                	   55334	     21462 ns/op
BenchmarkLocalCopyWithKnownCommand-24                                  	  156183	      8003 ns/op
BenchmarkFindExecutableWithExistingFileButNoExtensions-24              	 1000000	      1054 ns/op
BenchmarkFindExecutableWithExistingFileWithSomeExtensions-24           	 1000000	      1054 ns/op
BenchmarkFindExecutableWithExistingFileWithRealExtensions-24           	 1000000	      1018 ns/op
BenchmarkFindExecutableWithNonExistingFileButNoExtensions-24           	 1479615	       841 ns/op
BenchmarkFindExecutableWithNonExistingFileWithSomeExtensions-24        	 1435975	       840 ns/op
BenchmarkFindExecutableWithNonExistingFileWithRealExtensions-24        	 1445222	       820 ns/op
BenchmarkFindExecutableOnExistingFileProportionalToPathLength-24       	   83017	     14673 ns/op
BenchmarkFindExecutableOnNonExistingFileProportionalToPathLength-24    	  103734	     11680 ns/op
BenchmarkStatOnExistingFile-24                                         	 1000000	      1038 ns/op
BenchmarkStatOnNonExistingFile-24                                      	 1444682	       825 ns/op
PASS
ok  	_/home/ricky26/Projects/OSS/temp/8313096dd475659d63297889cff1818c-00532cebdad0e3bf7ea8438777bfc1fe1a1037e3	20.887s

This turned out to be an antivirus-like piece of software called Trusteer Endpoint Security (sometimes called Rapport) by IBM.

This turned out to be an antivirus-like piece of software called Trusteer Endpoint Security (sometimes called Rapport) by IBM.

Yep I've got that installed. How did you figure it out?