Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

cmd/go: go cmd performance degradation on Plan 9 between Go 1.9 and 1.11 #27744

Closed
driusan opened this issue Sep 19, 2018 · 18 comments
Closed

cmd/go: go cmd performance degradation on Plan 9 between Go 1.9 and 1.11 #27744

driusan opened this issue Sep 19, 2018 · 18 comments
Labels
FrozenDueToAge GoCommand cmd/go help wanted NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. OS-Plan9 ToolSpeed
Milestone

Comments

@driusan
Copy link

driusan commented Sep 19, 2018

What version of Go are you using (go version)?

go 1.11 plan9/amd64

Does this issue reproduce with the latest release?

Yes

What operating system and processor architecture are you using (go env)?

GOARCH='amd64'
GOBIN=''
GOCACHE='/usr/driusan/lib/cache/go-build'
GOEXE=''
GOFLAGS=''
GOHOSTARCH='amd64'
GOHOSTOS='plan9'
GOOS='plan9'
GOPATH='/usr/driusan/go'
GOPROXY=''
GORACE=''
GOROOT='/usr/driusan/go1.11'
GOTMPDIR=''
GOTOOLDIR='/usr/driusan/go1.11/pkg/tool/plan9_amd64'
GCCGO='gccgo'
CC='6c'
CXX='g++'
CGO_ENABLED='0'
GOMOD=''
CGO_CFLAGS='-g -O2'
CGO_CPPFLAGS=''
CGO_CXXFLAGS='-g -O2'
CGO_FFLAGS='-g -O2'
CGO_LDFLAGS='-g -O2'
PKG_CONFIG='pkg-config'
GOGCCFLAGS='-fPIC -m64 -fno-caret-diagnostics -Qunused-arguments -fmessage-length=0 -fdebug-prefix-map=/tmp/go-build647141787=/tmp/go-build -gno-record-gcc-switches'

What did you do?

Ran go fmt ./... on the package github.com/driusan/dgit. Load spikes to 100% and it takes over 2 minutes, while this wasn't the case with previous versions of Go.

term% time $home/go1.9.2/bin/go fmt ./...
0.05u 0.11s 4.32r /usr/driusan/go1.9.2/bin/go fmt ./...
term% time $home/go1.11/bin/go fmt ./...
39.60u 1.11s 129.93r /usr/driusan/go1.11/bin/go fmt ./...

What did you expect to see?

Similar performance to previous releases in go fmt.

What did you see instead?

A 30x performance degradation.

@mirtchovski
Copy link
Contributor

can you run iostats go fmt ./... to see if anything weird is happening?

@driusan
Copy link
Author

driusan commented Sep 19, 2018

I don't know what would be "weird", but:

term% iostats go fmt ./...

read      11812907 bytes, 11863.8 Kb/sec
write     4293 bytes, 178.553 Kb/sec
protocol  14220569 bytes, 16920.9 Kb/sec
rpc       53431 count

Message    Count   Low  High  Time Averg          T       R
version        1     2     2     2     2 ms       19       19 bytes
attach         1     0     0     0     0 ms       26       20 bytes
walk       23171     0   112  5030     0 ms   746210   830957 bytes
open        3465     0   107  1111     0 ms    41580    83160 bytes
create         1     0     0     0     0 ms       35       24 bytes
read        4972     0     8   972     0 ms   114356 11867599 bytes
write        477     0     0    23     0 ms    15264     5247 bytes
clunk      19639     0    22  6386     0 ms   216029   137473 bytes
remove         1     0     0     0     0 ms       11        7 bytes
stat        1703     0     2   179     0 ms    18733   143800 bytes

Opens    Reads  (bytes)   Writes  (bytes) File
    1        0        0        0        0 stdin
    1        0        0        0        0 stdout
    1        0        0        0        0 stderr
    1      853  3486368        0        0 /bin/go
  156      312    75504        0        0 /dev/sysstat
  156      312    34115        0        0 /dev/swap
    1        0        0        0        0 /proc/500/text
  403        6     3966        0        0 /usr/driusan/go/src/github.com/driusan/dgit
    1        0        0        0        0 /tmp/go-build964208625
    3        8    19083        0        0 /usr/driusan/go/src/github.com/driusan/dgit/main.go
    1        2      842        0        0 /usr/driusan/go/src/github.com/driusan/dgit/.git
    3        6    13497        0        0 /usr/driusan/go/src/github.com/driusan/dgit/cmd
    3        6     9759        0        0 /usr/driusan/go/src/github.com/driusan/dgit/cmd/add.go
    3        7    11715        0        0 /usr/driusan/go/src/github.com/driusan/dgit/cmd/apply.go
    3        6     5082        0        0 /usr/driusan/go/src/github.com/driusan/dgit/cmd/branch.go
    3        6     4629        0        0 /usr/driusan/go/src/github.com/driusan/dgit/cmd/catfile.go
    3        7    14835        0        0 /usr/driusan/go/src/github.com/driusan/dgit/cmd/checkignore.go
    3        7    12168        0        0 /usr/driusan/go/src/github.com/driusan/dgit/cmd/checkout.go
    3        6     6405        0        0 /usr/driusan/go/src/github.com/driusan/dgit/cmd/checkoutindex.go
    3        6     6021        0        0 /usr/driusan/go/src/github.com/driusan/dgit/cmd/clean.go
    3        7    11724        0        0 /usr/driusan/go/src/github.com/driusan/dgit/cmd/clone.go
    3        6     9201        0        0 /usr/driusan/go/src/github.com/driusan/dgit/cmd/commit.go
    3        6     8223        0        0 /usr/driusan/go/src/github.com/driusan/dgit/cmd/committree.go
    3        6     6192        0        0 /usr/driusan/go/src/github.com/driusan/dgit/cmd/commondiff.go
    3        6     7203        0        0 /usr/driusan/go/src/github.com/driusan/dgit/cmd/config.go
    3        5     4035        0        0 /usr/driusan/go/src/github.com/driusan/dgit/cmd/diff.go
    3        5     2154        0        0 /usr/driusan/go/src/github.com/driusan/dgit/cmd/difffiles.go
    3        5     3477        0        0 /usr/driusan/go/src/github.com/driusan/dgit/cmd/diffindex.go
    3        6     5442        0        0 /usr/driusan/go/src/github.com/driusan/dgit/cmd/difftree.go
    3        6     5304        0        0 /usr/driusan/go/src/github.com/driusan/dgit/cmd/fetch.go
    3        6     6510        0        0 /usr/driusan/go/src/github.com/driusan/dgit/cmd/flag.go
    3        6     4650        0        0 /usr/driusan/go/src/github.com/driusan/dgit/cmd/flag_test.go
    3        7    15624        0        0 /usr/driusan/go/src/github.com/driusan/dgit/cmd/grep.go
    3        6     5688        0        0 /usr/driusan/go/src/github.com/driusan/dgit/cmd/hashobject.go
    3        6     9342        0        0 /usr/driusan/go/src/github.com/driusan/dgit/cmd/indexpack.go
    3        5     3711        0        0 /usr/driusan/go/src/github.com/driusan/dgit/cmd/init.go
    3        6     7668        0        0 /usr/driusan/go/src/github.com/driusan/dgit/cmd/log.go
    3        4      828        0        0 /usr/driusan/go/src/github.com/driusan/dgit/cmd/log_test.go
    3        7    12749        0        0 /usr/driusan/go/src/github.com/driusan/dgit/cmd/lsfiles.go
    3        6     8487        0        0 /usr/driusan/go/src/github.com/driusan/dgit/cmd/lstree.go
    3        4      786        0        0 /usr/driusan/go/src/github.com/driusan/dgit/cmd/main_test.go
    3        5     4149        0        0 /usr/driusan/go/src/github.com/driusan/dgit/cmd/merge.go
    3        5     4320        0        0 /usr/driusan/go/src/github.com/driusan/dgit/cmd/mergebase.go
    3        5     4419        0        0 /usr/driusan/go/src/github.com/driusan/dgit/cmd/mergefile.go
    3        5     1674        0        0 /usr/driusan/go/src/github.com/driusan/dgit/cmd/mktag.go
    3        5     4083        0        0 /usr/driusan/go/src/github.com/driusan/dgit/cmd/packobjects.go
    3        6     4668        0        0 /usr/driusan/go/src/github.com/driusan/dgit/cmd/pull.go
    3        7    10800        0        0 /usr/driusan/go/src/github.com/driusan/dgit/cmd/push.go
    3        7    12417        0        0 /usr/driusan/go/src/github.com/driusan/dgit/cmd/readtree.go
    3        5     3663        0        0 /usr/driusan/go/src/github.com/driusan/dgit/cmd/reset.go
    3        5     3963        0        0 /usr/driusan/go/src/github.com/driusan/dgit/cmd/rev-list.go
    3        5     2469        0        0 /usr/driusan/go/src/github.com/driusan/dgit/cmd/rev-list_test.go
    3        4      870        0        0 /usr/driusan/go/src/github.com/driusan/dgit/cmd/rev-parse.go
    3        6     9996        0        0 /usr/driusan/go/src/github.com/driusan/dgit/cmd/revert.go
    3        5     4020        0        0 /usr/driusan/go/src/github.com/driusan/dgit/cmd/rm.go
    3        4     1365        0        0 /usr/driusan/go/src/github.com/driusan/dgit/cmd/send-pack.go
    3        5     2034        0        0 /usr/driusan/go/src/github.com/driusan/dgit/cmd/show.go
    3        5     3711        0        0 /usr/driusan/go/src/github.com/driusan/dgit/cmd/showref.go
    3        6     9519        0        0 /usr/driusan/go/src/github.com/driusan/dgit/cmd/status.go
    3        5     2439        0        0 /usr/driusan/go/src/github.com/driusan/dgit/cmd/submodule.go
    3        5     3945        0        0 /usr/driusan/go/src/github.com/driusan/dgit/cmd/symbolicref.go
    3        5     4140        0        0 /usr/driusan/go/src/github.com/driusan/dgit/cmd/tag.go
    3        5     3225        0        0 /usr/driusan/go/src/github.com/driusan/dgit/cmd/unpackobjects.go
    3        7    15759        0        0 /usr/driusan/go/src/github.com/driusan/dgit/cmd/updateindex.go
    3        5     2901        0        0 /usr/driusan/go/src/github.com/driusan/dgit/cmd/updateindex_test.go
    3        6     6309        0        0 /usr/driusan/go/src/github.com/driusan/dgit/cmd/updateref.go
    3        6     8565        0        0 /usr/driusan/go/src/github.com/driusan/dgit/cmd/var.go
    3        5     2349        0        0 /usr/driusan/go/src/github.com/driusan/dgit/cmd/writetree.go
    3        6    23724        0        0 /usr/driusan/go/src/github.com/driusan/dgit/git
    3        6     8670        0        0 /usr/driusan/go/src/github.com/driusan/dgit/git/add.go
    3        7    12828        0        0 /usr/driusan/go/src/github.com/driusan/dgit/git/apply.go
    3        7    15113        0        0 /usr/driusan/go/src/github.com/driusan/dgit/git/apply_test.go
    3        4      549        0        0 /usr/driusan/go/src/github.com/driusan/dgit/git/auth.go
    3        5     3078        0        0 /usr/driusan/go/src/github.com/driusan/dgit/git/catfile.go
    3        8    15968        0        0 /usr/driusan/go/src/github.com/driusan/dgit/git/checkout.go
    3        7    12753        0        0 /usr/driusan/go/src/github.com/driusan/dgit/git/checkout_test.go
    3        8    17203        0        0 /usr/driusan/go/src/github.com/driusan/dgit/git/checkoutindex.go
    3        6     8664        0        0 /usr/driusan/go/src/github.com/driusan/dgit/git/checkoutindex_test.go
    3        5     3273        0        0 /usr/driusan/go/src/github.com/driusan/dgit/git/clean.go
    3        8    21470        0        0 /usr/driusan/go/src/github.com/driusan/dgit/git/client.go
    3        7    13570        0        0 /usr/driusan/go/src/github.com/driusan/dgit/git/commit.go
    3        8    18033        0        0 /usr/driusan/go/src/github.com/driusan/dgit/git/commit_test.go
    3        5     3219        0        0 /usr/driusan/go/src/github.com/driusan/dgit/git/commitmessage_test.go
    3        6     8172        0        0 /usr/driusan/go/src/github.com/driusan/dgit/git/committree.go
    3        7    12774        0        0 /usr/driusan/go/src/github.com/driusan/dgit/git/committree_test.go
    3        7    15289        0        0 /usr/driusan/go/src/github.com/driusan/dgit/git/config.go
    3        4      531        0        0 /usr/driusan/go/src/github.com/driusan/dgit/git/consts.go
    3        4      558        0        0 /usr/driusan/go/src/github.com/driusan/dgit/git/consts_plan9.go
    3        7    11751        0        0 /usr/driusan/go/src/github.com/driusan/dgit/git/delta.go
    3        5     4062        0        0 /usr/driusan/go/src/github.com/driusan/dgit/git/diff.go
    3        6     8010        0        0 /usr/driusan/go/src/github.com/driusan/dgit/git/difffiles.go
    3        6     6714        0        0 /usr/driusan/go/src/github.com/driusan/dgit/git/diffindex.go
    3        6     7011        0        0 /usr/driusan/go/src/github.com/driusan/dgit/git/difftree.go
    3        4     1371        0        0 /usr/driusan/go/src/github.com/driusan/dgit/git/editor.go
    3        4     1317        0        0 /usr/driusan/go/src/github.com/driusan/dgit/git/editor_plan9.go
    3        5     2946        0        0 /usr/driusan/go/src/github.com/driusan/dgit/git/entrymode.go
    3        4      741        0        0 /usr/driusan/go/src/github.com/driusan/dgit/git/errors.go
    3        6     9201        0        0 /usr/driusan/go/src/github.com/driusan/dgit/git/expandtree.go
    3        5     3957        0        0 /usr/driusan/go/src/github.com/driusan/dgit/git/fetch.go
    3        7    12335        0        0 /usr/driusan/go/src/github.com/driusan/dgit/git/file.go
    3        5     1617        0        0 /usr/driusan/go/src/github.com/driusan/dgit/git/file_ctime_other.go
    3        4      846        0        0 /usr/driusan/go/src/github.com/driusan/dgit/git/file_ctime_unix.go
    3        4      396        0        0 /usr/driusan/go/src/github.com/driusan/dgit/git/file_inode_other.go
    3        4      684        0        0 /usr/driusan/go/src/github.com/driusan/dgit/git/file_inode_unix.go
    3        4      693        0        0 /usr/driusan/go/src/github.com/driusan/dgit/git/file_mtime.go
    3        4     1443        0        0 /usr/driusan/go/src/github.com/driusan/dgit/git/file_mtime_plan9.go
    3        6     6501        0        0 /usr/driusan/go/src/github.com/driusan/dgit/git/grep.go
    3        6     6597        0        0 /usr/driusan/go/src/github.com/driusan/dgit/git/grep_test.go
    3        6     9813        0        0 /usr/driusan/go/src/github.com/driusan/dgit/git/hashdiff.go
    3        5     3006        0        0 /usr/driusan/go/src/github.com/driusan/dgit/git/hashobject.go
    3        7    11928        0        0 /usr/driusan/go/src/github.com/driusan/dgit/git/hashobject_test.go
    3        8    16443        0        0 /usr/driusan/go/src/github.com/driusan/dgit/git/ignore.go
    3        6     8832        0        0 /usr/driusan/go/src/github.com/driusan/dgit/git/ignore_test.go
    3        9    26641        0        0 /usr/driusan/go/src/github.com/driusan/dgit/git/index.go
    3        9    26401        0        0 /usr/driusan/go/src/github.com/driusan/dgit/git/indexpack.go
    3        7    11493        0        0 /usr/driusan/go/src/github.com/driusan/dgit/git/init.go
    3        5     2295        0        0 /usr/driusan/go/src/github.com/driusan/dgit/git/init_test.go
    3        6     8208        0        0 /usr/driusan/go/src/github.com/driusan/dgit/git/interactive.go
    3        6     9621        0        0 /usr/driusan/go/src/github.com/driusan/dgit/git/interactive_test.go
    3        8    18428        0        0 /usr/driusan/go/src/github.com/driusan/dgit/git/lsfiles.go
    3        6     9942        0        0 /usr/driusan/go/src/github.com/driusan/dgit/git/lsfiles_test.go
    3        7    13508        0        0 /usr/driusan/go/src/github.com/driusan/dgit/git/lstree.go
    3        4      786        0        0 /usr/driusan/go/src/github.com/driusan/dgit/git/main_test.go
    3        7    13345        0        0 /usr/driusan/go/src/github.com/driusan/dgit/git/merge.go
    3        6     7905        0        0 /usr/driusan/go/src/github.com/driusan/dgit/git/mergebase.go
    3        6    10248        0        0 /usr/driusan/go/src/github.com/driusan/dgit/git/mergebase_test.go
    3        6     5355        0        0 /usr/driusan/go/src/github.com/driusan/dgit/git/mergefile.go
    3        7    14225        0        0 /usr/driusan/go/src/github.com/driusan/dgit/git/mktag.go
    3        7    15765        0        0 /usr/driusan/go/src/github.com/driusan/dgit/git/objects.go
    3        7    14442        0        0 /usr/driusan/go/src/github.com/driusan/dgit/git/packfile.go
    3        5     2442        0        0 /usr/driusan/go/src/github.com/driusan/dgit/git/packfile_hacks.go
    3        7    13492        0        0 /usr/driusan/go/src/github.com/driusan/dgit/git/packfile_test.go
    3        4      903        0        0 /usr/driusan/go/src/github.com/driusan/dgit/git/password_other.go
    3        4      921        0        0 /usr/driusan/go/src/github.com/driusan/dgit/git/password_plan9.go
    3        5     2244        0        0 /usr/driusan/go/src/github.com/driusan/dgit/git/pktline_test.go
    3        4      579        0        0 /usr/driusan/go/src/github.com/driusan/dgit/git/progressf.go
    3        4      525        0        0 /usr/driusan/go/src/github.com/driusan/dgit/git/progressf_plan9.go
    3        5     1560        0        0 /usr/driusan/go/src/github.com/driusan/dgit/git/pull.go
    3       10    34762        0        0 /usr/driusan/go/src/github.com/driusan/dgit/git/readtree.go
    3        7    15410        0        0 /usr/driusan/go/src/github.com/driusan/dgit/git/readtree_test.go
    3        6     7335        0        0 /usr/driusan/go/src/github.com/driusan/dgit/git/refspec.go
    3        7    13404        0        0 /usr/driusan/go/src/github.com/driusan/dgit/git/reset.go
    3        6     9504        0        0 /usr/driusan/go/src/github.com/driusan/dgit/git/reset_test.go
    3        8    17287        0        0 /usr/driusan/go/src/github.com/driusan/dgit/git/retrieve.go
    3        6     6801        0        0 /usr/driusan/go/src/github.com/driusan/dgit/git/revert.go
    3        6     6156        0        0 /usr/driusan/go/src/github.com/driusan/dgit/git/revert_test.go
    3        6     6678        0        0 /usr/driusan/go/src/github.com/driusan/dgit/git/revlist.go
    3        8    16118        0        0 /usr/driusan/go/src/github.com/driusan/dgit/git/revparse.go
    3        6     5844        0        0 /usr/driusan/go/src/github.com/driusan/dgit/git/rm.go
    3        8    21706        0        0 /usr/driusan/go/src/github.com/driusan/dgit/git/sha1.go
    3        5     2202        0        0 /usr/driusan/go/src/github.com/driusan/dgit/git/sha1_test.go
    3        6     5484        0        0 /usr/driusan/go/src/github.com/driusan/dgit/git/show.go
    3        6     9102        0        0 /usr/driusan/go/src/github.com/driusan/dgit/git/showref.go
    3        8    22635        0        0 /usr/driusan/go/src/github.com/driusan/dgit/git/status.go
    3        8    19524        0        0 /usr/driusan/go/src/github.com/driusan/dgit/git/status_test.go
    3        6     6726        0        0 /usr/driusan/go/src/github.com/driusan/dgit/git/symbolicref.go
    3        5     3642        0        0 /usr/driusan/go/src/github.com/driusan/dgit/git/tag.go
    3        7    11019        0        0 /usr/driusan/go/src/github.com/driusan/dgit/git/unpackobjects.go
    3        7    13505        0        0 /usr/driusan/go/src/github.com/driusan/dgit/git/updateindex.go
    3        7    14701        0        0 /usr/driusan/go/src/github.com/driusan/dgit/git/updateindex_test.go
    3        7    12329        0        0 /usr/driusan/go/src/github.com/driusan/dgit/git/updateref.go
    3        7    13096        0        0 /usr/driusan/go/src/github.com/driusan/dgit/git/writetree.go
    3        8    18721        0        0 /usr/driusan/go/src/github.com/driusan/dgit/git/writetree_test.go
    2        4      390        0        0 /usr/driusan/go/src/github.com/driusan/dgit/issues
    2        4      162        0        0 /usr/driusan/go/src/github.com/driusan/dgit/issues/Status-should-be-refactored
    2        4      162        0        0 /usr/driusan/go/src/github.com/driusan/dgit/issues/need-git-pull-[options]-repo
    2        4      664        0        0 /usr/driusan/go/src/github.com/driusan/dgit/official-git
    2        4      166        0        0 /usr/driusan/go/src/github.com/driusan/dgit/vendor
    1        2       78        0        0 /usr/driusan/go/src/github.com/driusan/dgit/vendor/bitbucket.org
    1        2       77        0        0 /usr/driusan/go/src/github.com/driusan/dgit/vendor/bitbucket.org/mischief
    3        6     1704        0        0 /usr/driusan/go/src/github.com/driusan/dgit/vendor/bitbucket.org/mischief/libauth
    3        6      711        0        0 /usr/driusan/go/src/github.com/driusan/dgit/zlib
    3        7    12534        0        0 /usr/driusan/go/src/github.com/driusan/dgit/zlib/reader.go
    3        7    13662        0        0 /usr/driusan/go/src/github.com/driusan/dgit/zlib/writer.go
    1        2      248        0        0 /usr/driusan/go1.11/src/errors
    1        1      498        0        0 /usr/driusan/go1.11/src/errors/errors.go
    1        1     1270        0        0 /usr/driusan/go1.11/src/errors/errors_test.go
    1        1      691        0        0 /usr/driusan/go1.11/src/errors/example_test.go
    1        2      419        0        0 /usr/driusan/go1.11/src/flag
    1        1     2658        0        0 /usr/driusan/go1.11/src/flag/example_test.go
    1        1      845        0        0 /usr/driusan/go1.11/src/flag/example_value_test.go
    1        1      607        0        0 /usr/driusan/go1.11/src/flag/export_test.go
    1        1     4096        0        0 /usr/driusan/go1.11/src/flag/flag.go
    1        1     4096        0        0 /usr/driusan/go1.11/src/flag/flag_test.go
    1        2      728        0        0 /usr/driusan/go1.11/src/fmt
    1        5    14559        0        0 /usr/driusan/go1.11/src/fmt/doc.go
    1        1      551        0        0 /usr/driusan/go1.11/src/fmt/example_test.go
    1        1      219        0        0 /usr/driusan/go1.11/src/fmt/export_test.go
    1        1     4096        0        0 /usr/driusan/go1.11/src/fmt/fmt_test.go
    1        1     4096        0        0 /usr/driusan/go1.11/src/fmt/format.go
    1        1     4096        0        0 /usr/driusan/go1.11/src/fmt/print.go
    1        1     4096        0        0 /usr/driusan/go1.11/src/fmt/scan.go
    1        1     4096        0        0 /usr/driusan/go1.11/src/fmt/scan_test.go
    1        1     2156        0        0 /usr/driusan/go1.11/src/fmt/stringer_test.go
    1        2      636        0        0 /usr/driusan/go1.11/src/io
    1        1     4096        0        0 /usr/driusan/go1.11/src/io/example_test.go
    1        1     4096        0        0 /usr/driusan/go1.11/src/io/io.go
    1        1     4096        0        0 /usr/driusan/go1.11/src/io/io_test.go
    1        1     2746        0        0 /usr/driusan/go1.11/src/io/multi.go
    1        1     4096        0        0 /usr/driusan/go1.11/src/io/multi_test.go
    1        1     4096        0        0 /usr/driusan/go1.11/src/io/pipe.go
    1        1     4096        0        0 /usr/driusan/go1.11/src/io/pipe_test.go
    1        2     1812        0        0 /usr/driusan/go1.11/src/sync
    1        1     2604        0        0 /usr/driusan/go1.11/src/sync/cond.go
    1        1     4096        0        0 /usr/driusan/go1.11/src/sync/cond_test.go
    1        1     1025        0        0 /usr/driusan/go1.11/src/sync/example_pool_test.go
    1        1     1165        0        0 /usr/driusan/go1.11/src/sync/example_test.go
    1        1      365        0        0 /usr/driusan/go1.11/src/sync/export_test.go
    1        1     4096        0        0 /usr/driusan/go1.11/src/sync/map.go
    1        1     4096        0        0 /usr/driusan/go1.11/src/sync/map_bench_test.go
    1        1     3468        0        0 /usr/driusan/go1.11/src/sync/map_reference_test.go
    1        1     3528        0        0 /usr/driusan/go1.11/src/sync/map_test.go
    1        1     4096        0        0 /usr/driusan/go1.11/src/sync/mutex.go
    1        1     4096        0        0 /usr/driusan/go1.11/src/sync/mutex_test.go
    1        1     1332        0        0 /usr/driusan/go1.11/src/sync/once.go
    1        1     1125        0        0 /usr/driusan/go1.11/src/sync/once_test.go
    1        1     4096        0        0 /usr/driusan/go1.11/src/sync/pool.go
    1        1     3369        0        0 /usr/driusan/go1.11/src/sync/pool_test.go
    1        1     1970        0        0 /usr/driusan/go1.11/src/sync/runtime.go
    1        1     1366        0        0 /usr/driusan/go1.11/src/sync/runtime_sema_test.go
    1        1     4096        0        0 /usr/driusan/go1.11/src/sync/rwmutex.go
    1        1     4096        0        0 /usr/driusan/go1.11/src/sync/rwmutex_test.go
    1        1     4096        0        0 /usr/driusan/go1.11/src/sync/waitgroup.go
    1        1     4096        0        0 /usr/driusan/go1.11/src/sync/waitgroup_test.go
    1        2      232        0        0 /usr/driusan/go1.11/src/internal/race
    1        2      448        0        0 /usr/driusan/go1.11/src/internal/race/doc.go
    1        1      602        0        0 /usr/driusan/go1.11/src/internal/race/norace.go
    1        1      880        0        0 /usr/driusan/go1.11/src/internal/race/race.go
    1        2       79        0        0 /usr/driusan/go1.11/src/unsafe
    1        1     4096        0        0 /usr/driusan/go1.11/src/unsafe/unsafe.go
    1        7    41314        0        0 /usr/driusan/go1.11/src/runtime
    1        1     4096        0        0 /usr/driusan/go1.11/src/runtime/alg.go
    1        1     1352        0        0 /usr/driusan/go1.11/src/runtime/asm.s
    1        1     4096        0        0 /usr/driusan/go1.11/src/runtime/asm_amd64.s
    1        1     4096        0        0 /usr/driusan/go1.11/src/runtime/asm_mips64x.s
    1        1     4096        0        0 /usr/driusan/go1.11/src/runtime/asm_mipsx.s
    1        1     1023        0        0 /usr/driusan/go1.11/src/runtime/asm_ppc64x.h
    1        1     4096        0        0 /usr/driusan/go1.11/src/runtime/asm_ppc64x.s
    1        1      296        0        0 /usr/driusan/go1.11/src/runtime/atomic_mips64x.s
    1        1      258        0        0 /usr/driusan/go1.11/src/runtime/atomic_mipsx.s
    1        1     3218        0        0 /usr/driusan/go1.11/src/runtime/atomic_pointer.go
    1        1      433        0        0 /usr/driusan/go1.11/src/runtime/atomic_ppc64x.s
    1        1      332        0        0 /usr/driusan/go1.11/src/runtime/auxv_none.go
    1        1     1500        0        0 /usr/driusan/go1.11/src/runtime/callers_test.go
    1        1     2055        0        0 /usr/driusan/go1.11/src/runtime/cgo.go
    1        1     2129        0        0 /usr/driusan/go1.11/src/runtime/cgo_mmap.go
    1        2      411        0        0 /usr/driusan/go1.11/src/runtime/cgo_ppc64x.go
    1        1     3130        0        0 /usr/driusan/go1.11/src/runtime/cgo_sigaction.go
    1        2     8192        0        0 /usr/driusan/go1.11/src/runtime/cgocall.go
    1        1      317        0        0 /usr/driusan/go1.11/src/runtime/cgocallback.go
    1        1     4096        0        0 /usr/driusan/go1.11/src/runtime/cgocheck.go
    1        1     4096        0        0 /usr/driusan/go1.11/src/runtime/chan.go
    1        1     4096        0        0 /usr/driusan/go1.11/src/runtime/chan_test.go
    1        1     1434        0        0 /usr/driusan/go1.11/src/runtime/chanbarrier_test.go
    1        1      936        0        0 /usr/driusan/go1.11/src/runtime/closure_test.go
    1        1      413        0        0 /usr/driusan/go1.11/src/runtime/compiler.go
    1        1     1629        0        0 /usr/driusan/go1.11/src/runtime/complex.go
    1        1     1077        0        0 /usr/driusan/go1.11/src/runtime/complex_test.go
    1        1      665        0        0 /usr/driusan/go1.11/src/runtime/cpuflags_amd64.go
    1        1     4096        0        0 /usr/driusan/go1.11/src/runtime/cpuprof.go
    1        1      478        0        0 /usr/driusan/go1.11/src/runtime/cputicks.go
    1        1     4096        0        0 /usr/driusan/go1.11/src/runtime/crash_cgo_test.go
    1        1      390        0        0 /usr/driusan/go1.11/src/runtime/crash_nonunix_test.go
    1        1     4096        0        0 /usr/driusan/go1.11/src/runtime/crash_test.go
    1        1     4096        0        0 /usr/driusan/go1.11/src/runtime/crash_unix_test.go
    1        1     1570        0        0 /usr/driusan/go1.11/src/runtime/debug.go
    1        1     4096        0        0 /usr/driusan/go1.11/src/runtime/debug_test.go
    1        1     2486        0        0 /usr/driusan/go1.11/src/runtime/debugcall.go
    1        1     3075        0        0 /usr/driusan/go1.11/src/runtime/defs_linux_mips64x.go
    1        1     3242        0        0 /usr/driusan/go1.11/src/runtime/defs_linux_mipsx.go
    1        1     1703        0        0 /usr/driusan/go1.11/src/runtime/defs_plan9_amd64.go
    1        1     4096        0        0 /usr/driusan/go1.11/src/runtime/duff_amd64.s
    1        1     3980        0        0 /usr/driusan/go1.11/src/runtime/duff_mips64x.s
    1        1     2442        0        0 /usr/driusan/go1.11/src/runtime/duff_ppc64x.s
    1        1      855        0        0 /usr/driusan/go1.11/src/runtime/env_plan9.go
    1        1     1360        0        0 /usr/driusan/go1.11/src/runtime/env_posix.go
    1        1     1308        0        0 /usr/driusan/go1.11/src/runtime/env_test.go
    1        1     3836        0        0 /usr/driusan/go1.11/src/runtime/error.go
    1        1     1374        0        0 /usr/driusan/go1.11/src/runtime/example_test.go
    1        1     4096        0        0 /usr/driusan/go1.11/src/runtime/export_debug_test.go
    1        1      270        0        0 /usr/driusan/go1.11/src/runtime/export_futex_test.go
    1        1      482        0        0 /usr/driusan/go1.11/src/runtime/export_mmap_test.go
    1        1     4096        0        0 /usr/driusan/go1.11/src/runtime/export_test.go
    1        1      480        0        0 /usr/driusan/go1.11/src/runtime/export_unix_test.go
    1        3    11630        0        0 /usr/driusan/go1.11/src/runtime/extern.go
    1        1     1249        0        0 /usr/driusan/go1.11/src/runtime/fastlog2.go
    1        1      784        0        0 /usr/driusan/go1.11/src/runtime/fastlog2_test.go
    1        1      890        0        0 /usr/driusan/go1.11/src/runtime/fastlog2table.go
    1        1     1382        0        0 /usr/driusan/go1.11/src/runtime/float.go
    1        1     2386        0        0 /usr/driusan/go1.11/src/runtime/funcdata.h
    1        1     2150        0        0 /usr/driusan/go1.11/src/runtime/futex_test.go
    1        1     4096        0        0 /usr/driusan/go1.11/src/runtime/gc_test.go
    1        1     4096        0        0 /usr/driusan/go1.11/src/runtime/gcinfo_test.go
    1        1      453        0        0 /usr/driusan/go1.11/src/runtime/go_tls.h
    1        1     2628        0        0 /usr/driusan/go1.11/src/runtime/hash32.go
    1        1     2750        0        0 /usr/driusan/go1.11/src/runtime/hash64.go
    1        1     4096        0        0 /usr/driusan/go1.11/src/runtime/hash_test.go
    1        1     4096        0        0 /usr/driusan/go1.11/src/runtime/heapdump.go
    1        1     4096        0        0 /usr/driusan/go1.11/src/runtime/iface.go
    1        1     4096        0        0 /usr/driusan/go1.11/src/runtime/iface_test.go
    1        1     1809        0        0 /usr/driusan/go1.11/src/runtime/lfstack.go
    1        1      527        0        0 /usr/driusan/go1.11/src/runtime/lfstack_32bit.go
    1        1     1553        0        0 /usr/driusan/go1.11/src/runtime/lfstack_64bit.go
    1        1     2844        0        0 /usr/driusan/go1.11/src/runtime/lfstack_test.go
    1        1     4096        0        0 /usr/driusan/go1.11/src/runtime/lock_futex.go
    1        1     4096        0        0 /usr/driusan/go1.11/src/runtime/lock_sema.go
    1        2     8192        0        0 /usr/driusan/go1.11/src/runtime/malloc.go
    1        1     4096        0        0 /usr/driusan/go1.11/src/runtime/malloc_test.go
    1        1     4096        0        0 /usr/driusan/go1.11/src/runtime/map.go
    1        1     4096        0        0 /usr/driusan/go1.11/src/runtime/map_benchmark_test.go
    1        1     4096        0        0 /usr/driusan/go1.11/src/runtime/map_fast32.go
    1        1     4096        0        0 /usr/driusan/go1.11/src/runtime/map_fast64.go
    1        1     4096        0        0 /usr/driusan/go1.11/src/runtime/map_faststr.go
    1        1     4096        0        0 /usr/driusan/go1.11/src/runtime/map_test.go
    1        2     8192        0        0 /usr/driusan/go1.11/src/runtime/mbarrier.go
    1        1     4096        0        0 /usr/driusan/go1.11/src/runtime/mbitmap.go
    1        1     4096        0        0 /usr/driusan/go1.11/src/runtime/mcache.go
    1        1     4096        0        0 /usr/driusan/go1.11/src/runtime/mcentral.go
    1        1     1662        0        0 /usr/driusan/go1.11/src/runtime/mem_bsd.go
    1        1     4096        0        0 /usr/driusan/go1.11/src/runtime/mem_plan9.go
    1        1     3736        0        0 /usr/driusan/go1.11/src/runtime/memclr_amd64.s
    1        1      785        0        0 /usr/driusan/go1.11/src/runtime/memclr_mips64x.s
    1        1     1274        0        0 /usr/driusan/go1.11/src/runtime/memclr_mipsx.s
    1        1      433        0        0 /usr/driusan/go1.11/src/runtime/memclr_plan9_amd64.s
    1        1     1675        0        0 /usr/driusan/go1.11/src/runtime/memclr_ppc64x.s
    1        1     4096        0        0 /usr/driusan/go1.11/src/runtime/memmove_amd64.s
    1        1     1801        0        0 /usr/driusan/go1.11/src/runtime/memmove_mips64x.s
    1        1     4096        0        0 /usr/driusan/go1.11/src/runtime/memmove_mipsx.s
    1        1     3051        0        0 /usr/driusan/go1.11/src/runtime/memmove_plan9_amd64.s
    1        1     2782        0        0 /usr/driusan/go1.11/src/runtime/memmove_ppc64x.s
    1        1     4096        0        0 /usr/driusan/go1.11/src/runtime/memmove_test.go
    1        1     4096        0        0 /usr/driusan/go1.11/src/runtime/mfinal.go
    1        1     4096        0        0 /usr/driusan/go1.11/src/runtime/mfinal_test.go
    1        1     2787        0        0 /usr/driusan/go1.11/src/runtime/mfixalloc.go
    1        2     8192        0        0 /usr/driusan/go1.11/src/runtime/mgc.go
    1        1     4096        0        0 /usr/driusan/go1.11/src/runtime/mgclarge.go

@mirtchovski
Copy link
Contributor

I meant to compare it with the 1.9 go fmt running under iostats. my suspicion was that you are generating a lot more 9p reads for whatever reason, which can be costly given no 'true vfs caching' in Plan 9.

@dmitshur dmitshur added OS-Plan9 ToolSpeed NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. labels Sep 19, 2018
@dmitshur dmitshur added this to the Go1.12 milestone Sep 19, 2018
@dmitshur dmitshur changed the title go fmt performance on Plan 9 cmd/gofmt: performance degradation on Plan 9 Sep 19, 2018
@mvdan
Copy link
Member

mvdan commented Sep 19, 2018

cc @griesemer @ianthehat

@driusan
Copy link
Author

driusan commented Sep 19, 2018

@mirtchovski ah, my mistake.. the summary from the go 1.9 one is:

read      9636886 bytes, 13499.2 Kb/sec
write     276 bytes, 642.835 Kb/sec
protocol  10978362 bytes, 3326.42 Kb/sec
rpc       28151 count

Message    Count   Low  High  Time Averg          T       R
version        1     0     0     0     0 ms       19       19 bytes
attach         1     0     0     0     0 ms       26       20 bytes
walk        8709     0     8  1555     0 ms   323218   362820 bytes
open        5813     0     0   709     0 ms    69756   139512 bytes
create         3     0     0     0     0 ms      100       72 bytes
read        3730     0    12   697     0 ms    85790  9677916 bytes
write         23     0     0     0     0 ms      805      253 bytes
clunk       8060     0     0   129     0 ms    88660    56420 bytes
remove         4     0     0     0     0 ms       44       68 bytes
stat        1807     0     0   130     0 ms    19877   152967 bytes

There's a lot more walking and clunking. The most significant difference in the individual file stats (I can post the whole thing on request) is that the .git directory appears in go1.11 but not go 1.9.2. I don't know if that's enough to cause the difference, but I suspect it's walking the whole .git directory now unnecessarily.

@dmitshur The problem is in go fmt, not gofmt. gofmt is fine when invoked directly.

@dmitshur dmitshur changed the title cmd/gofmt: performance degradation on Plan 9 cmd/go: fmt performance degradation on Plan 9 Sep 19, 2018
@bcmills bcmills changed the title cmd/go: fmt performance degradation on Plan 9 cmd/go: fmt performance degradation on Plan 9 between Go 1.9 and 1.11 Jan 17, 2019
@bcmills bcmills modified the milestones: Go1.12, Unplanned Jan 17, 2019
@bcmills
Copy link
Contributor

bcmills commented Jan 17, 2019

CC @0intro

@0intro
Copy link
Member

0intro commented Mar 11, 2019

Yes, I confirm there is a performance regression between Go 1.9 and Go 1.10.

cpu% go version
go version go1.9.7 plan9/386
cpu% iostats go fmt ./...

read      8855348 bytes, 75172.28 Kb/sec
write     99 bytes, 1211.798 Kb/sec
protocol  10204502 bytes, 4524.94 Kb/sec
rpc       30409 count

Message    Count   Low  High  Time Averg          T       R
version        1     0     0     0     0 ms       19       19 bytes
attach         1     0     0     0     0 ms       22       20 bytes
walk        9452     0   112   863     0 ms   310328   339554 bytes
open        6110     0   112   769     0 ms    73320   146640 bytes
create         2     0     7     7     3 ms       62       48 bytes
read        3654     0     0   115     0 ms    84042  8895542 bytes
write         11     0     0     0     0 ms      352      121 bytes
clunk       9003     0     0   180     0 ms    99033    63021 bytes
remove         3     0     0     0     0 ms       33       14 bytes
stat        2172     0     0   265     0 ms    23892   168121 bytes
cpu% go version
go version go1.10.8 plan9/386
cpu% iostats go fmt ./...

read      8898944 bytes, 66728.22 Kb/sec
write     3321 bytes, 1158.178 Kb/sec
protocol  12502604 bytes, 4797.149 Kb/sec
rpc       92246 count

Message    Count   Low  High  Time Averg          T       R
version        1     0     0     0     0 ms       19       19 bytes
attach         1     0     0     0     0 ms       22       20 bytes
walk       39563     0   112   895     0 ms  1099595  1196763 bytes
open        7317     0   112   899     0 ms    87804   175608 bytes
create         1     0     0     0     0 ms       35       24 bytes
read        4490     0     0   130     0 ms   103270  8948334 bytes
write        369     0     0     2     0 ms    11808     4059 bytes
clunk      38427     0     1   370     0 ms   422697   268989 bytes
remove         1     0     0     0     0 ms       11        7 bytes
stat        2076     0     2   246     0 ms    22836   160549 bytes

Detailed comparison: https://www.diffchecker.com/5Dj8GNPJ

@0intro
Copy link
Member

0intro commented Mar 11, 2019

Contrary to Go 1.9, Go 1.10 also scan the .git directory, but it doesn't explain the performance regression (the .git directory only contains a single file in my case).

@0intro 0intro self-assigned this Mar 11, 2019
@ghost
Copy link

ghost commented May 26, 2019

I'd like to point out that all the go tools are affected by this regression, not just go fmt.

; time go version
go version go1.10.3 plan9/amd64
0.00u 0.01s 0.01r 	 go version
; time go12 version
go version go1.12 plan9/amd64
1.95u 0.03s 1.97r 	 go12 version

It would probably be beneficial to start a fresh issue for this, perhaps with a title reflecting the true extent and magnitude of the problem.

cmd/go: Local Man Discovers a Horrible Performance Degradation in Go, You Wouldn't Believe What Didn't Happen Next

@griesemer
Copy link
Contributor

As mentioned earlier, the issue is with the go tool, not gofmt per se. Changing the title accordingly.

@griesemer griesemer changed the title cmd/go: fmt performance degradation on Plan 9 between Go 1.9 and 1.11 cmd/go: go cmd performance degradation on Plan 9 between Go 1.9 and 1.11 May 26, 2019
@dmitshur dmitshur added the GoCommand cmd/go label May 27, 2019
@majiru
Copy link

majiru commented Aug 11, 2019

I've been testing the runtime a bit between versions and it seems like the issue with this is regarding the garbage collector. The specific major release that causes this bug to hit is go1.11, go1.10 seems to work just fine. The actual code that is causing the slow down at the start of the runtime initialization is in mccommoninit. For plan9 mp.notesig & mp.errstr are allocated on the garbage collector and the first pass through mpreinit is what is causing the delay.

For reference this slow down is also seen on go1.12. Here are traces of syscalls made by go1.10.8 and go1.11.1 through the use of plan9's ratrace(1), both outputs are from running the command go version. The slowdown is seen after the first series of Brk syscalls in 1.11 and seems like the delay is entirely within userspace.

@bcmills
Copy link
Contributor

bcmills commented Sep 18, 2019

At this point Go 1.11 is no longer even supported, so the regression in performance is de facto the new performance baseline for the go command on Plan 9.

I have no objection if someone wants to contribute fixes for the general problem of Go getting slower on Plan 9, but I don't think we need to keep an open issue against cmd/go to track it.

@bcmills bcmills closed this as completed Sep 18, 2019
@BurnZeZ
Copy link

BurnZeZ commented Sep 19, 2019

At this point Go 1.11 is no longer even supported, so the regression in performance is de facto the new performance baseline for the go command on Plan 9.

I am unable to make sense of this statement no matter how I interpret it.

I have no objection if someone wants to contribute fixes for the general problem of Go getting slower on Plan 9, but I don't think we need to keep an open issue against cmd/go to track it.

It’s not a problem of it getting slower; it’s a problem of something bad happening in the runtime.

Testing on several machines shows an average of around 0.5 seconds passing before main() is even reached, so calling it the “new performance baseline” and closing the issue seems a bit absurd in the face of evidence that the runtime may no longer be behaving sanely.

I found the commit that appears to mark when this problem began, but I don’t use or write go, so somebody else will have to investigate if they want to find out what is really going on.
c2cdfbd

@majiru
Copy link

majiru commented Sep 20, 2019

Reverting the sysFree function change in the commit BurnZeZ pointed out seems to take care of the delay.

; time go version
go version go1.13 plan9/amd64
0.01u 0.04s 0.08r 	 go version

@0intro
Copy link
Member

0intro commented Sep 20, 2019

CC @millerresearch

@millerresearch
Copy link
Contributor

I found the commit that appears to mark when this problem began, but I don’t use or write go, so somebody else will have to investigate if they want to find out what is really going on.
c2cdfbd

OK, that was mine, sorry. It seems to be only an amd64 problem: plan9 on arm and 386 are unaffected.
I can see what's gone wrong, so I'll try to sort it out.

@gopherbot
Copy link

Change https://golang.org/cl/207917 mentions this issue: runtime: on plan9 don't return substitute address for sysReserve

@4ad
Copy link
Member

4ad commented Nov 23, 2019

As this is actively worked on, I am going to reopen this.

@4ad 4ad reopened this Nov 23, 2019
@golang golang locked and limited conversation to collaborators Nov 27, 2020
@rsc rsc unassigned 0intro Jun 23, 2022
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
FrozenDueToAge GoCommand cmd/go help wanted NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. OS-Plan9 ToolSpeed
Projects
None yet
Development

No branches or pull requests