Skip to content

os/user: user.Current() too slow on Windows #68312

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

Closed
philwo opened this issue Jul 4, 2024 · 16 comments
Closed

os/user: user.Current() too slow on Windows #68312

philwo opened this issue Jul 4, 2024 · 16 comments
Labels
NeedsFix The path to resolution is known, but the work has not been done. OS-Windows Performance
Milestone

Comments

@philwo
Copy link
Contributor

philwo commented Jul 4, 2024

Go version

go version go1.22.4 windows/amd64

Output of go env in your module/workspace:

set GO111MODULE=on
set GOARCH=amd64
set GOBIN=C:\src\infra\infra\go\bin
set GOCACHE=C:\src\infra\infra\go\golang\gocache
set GOENV=C:\Users\philwo\AppData\Roaming\go\env
set GOEXE=.exe
set GOEXPERIMENT=
set GOFLAGS=
set GOHOSTARCH=amd64
set GOHOSTOS=windows
set GOINSECURE=
set GOMODCACHE=C:\src\infra\infra\go\golang\modcache
set GONOPROXY=*.googlesource.com,*.git.corp.google.com,google.com
set GONOSUMDB=*.googlesource.com,*.git.corp.google.com,google.com
set GOOS=windows
set GOPATH=C:\Users\philwo\go
set GOPRIVATE=*.googlesource.com,*.git.corp.google.com,google.com
set GOPROXY=https://proxy.golang.org,direct
set GOROOT=C:\src\infra\infra\go\golang\go
set GOSUMDB=sum.golang.org
set GOTMPDIR=
set GOTOOLCHAIN=local
set GOTOOLDIR=C:\src\infra\infra\go\golang\go\pkg\tool\windows_amd64
set GOVCS=
set GOVERSION=go1.22.4
set GCCGO=gccgo
set GOAMD64=v1
set AR=ar
set CC=gcc
set CXX=g++
set CGO_ENABLED=0
set GOMOD=C:\src\infra\infra\go\src\infra\go.mod
set GOWORK=
set CGO_CFLAGS=-O2 -g
set CGO_CPPFLAGS=
set CGO_CXXFLAGS=-O2 -g
set CGO_FFLAGS=-O2 -g
set CGO_LDFLAGS=-O2 -g
set PKG_CONFIG=pkg-config
set GOGCCFLAGS=-m64 -fno-caret-diagnostics -Qunused-arguments -Wl,--no-gc-sections -fmessage-length=0 -ffile-prefix-map=C:\src\temp\go-build1415248655=/tmp/go-build -gno-record-gcc-switches

What did you do?

I ran various tools that are part of Chromium's build tooling and are written in Go (reproxy, Siso), which have a mysterious startup overhead on my corporate Windows machine when I'm logged in via SSH, sometimes between 30s - 120s.

I traced it down to all of them depending on glog, which calls user.Current() in its init function. user.Current() on corporate Windows (joined to a domain) makes a network call to figure out the display name of the current user, which is part of the user.User struct returned by the function.

None of the callers that I inspected actually need the display name, they only wanted to know the username and/or the home directory of the user. However, there is no lightweight API available in the Go standard library that would allow callers to only get the username without the display name.

Here's a minimal repro example: https://go.dev/play/p/ODg6zPl1M1p

I found some other reports about this in the past as well:

What did you see happen?

The provided example takes ~500ms in the best case on corporate Windows for me, but between 30s - 120s when anything goes wrong with the network call to Active Directory triggered by user.Current()'s call to TranslateAccountName or NetUserGetInfo, which is unfortunately regularly the case (and currently for yet unknown reasons always when logged in to the machine via SSH instead of Remote Desktop).

Here's an example where I added timing measurements to the calls in the code:

> .\getuser.exe
syscall.NetGetJoinInformation() took 1.161ms
syscall.TranslateAccountName() took 1m5.5853054s
syscall.NetUserGetInfo() took 22.1981487s

In total, user.Current() took 1m27.788102s

What did you expect to see?

user.Current() should returns within single-digit milliseconds, like on macOS and Linux.

@seankhliao seankhliao added OS-Windows NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. labels Jul 4, 2024
@seankhliao
Copy link
Member

cc @golang/windows

@ianlancetaylor
Copy link
Member

I think we will need a proposal for an alternate API. See https://go.dev/s/proposal.

@alexbrainman
Copy link
Member

I traced it down to all of them depending on glog, which calls user.Current() in its init function.

Is it possible to adjust glog code to use something different from user.Current() that will provide the same functionality?

Alex

@mauri870
Copy link
Member

mauri870 commented Jul 8, 2024

It seems that the problem relies on the fact that user.Current() tries to make network calls to deal with active directory and domain lookup. I think a new alternate api would be a "local only" version of user.Current that does not use the network.

I traced it down to all of them depending on glog, which calls user.Current() in its init function.

Is it possible to adjust glog code to use something different from user.Current() that will provide the same functionality?

Alex

Looks like kubernetes/klog (a fork of golang/glog) already applies a hack to bypass this https://github.com/kubernetes/klog/pull/123/files#diff-d01d6fd256d313607b4da3fdc0147234f5c8c4326b18044201af6da8a69ae36aR63-R84.

@gopherbot
Copy link
Contributor

Change https://go.dev/cl/597255 mentions this issue: os/user: speed up Current on Windows

@qmuntal
Copy link
Member

qmuntal commented Jul 9, 2024

I've taken a stab at this in https://go-review.googlesource.com/c/go/+/597255. It replaces the offending slow API calls with GetUserNameExW, which should be faster for the current user.

@philwo could you give it a try? You can test test it compiling the Go toolchain at that CL by following these steps:

  1. go install golang.org/dl/gotip@latest
  2. gotip download 597255
  3. gotip build .

(Replace step 3 arguments with whatever build args you are using to build your app).

@philwo
Copy link
Contributor Author

philwo commented Jul 11, 2024

Hi @qmuntal,

Wow, thank you so much for quickly finding & implementing this fix. I've tested it on the corporate Windows machine that showed the performance issues. Your CL is a huge improvement for me in all cases.

First, I compared that the output of user.Current() is the same before and after the change. They match exactly. ✅

Then I compared the performance:

# Before change, "best case" (working connection to Active Directory)
> hyperfine .\getuser.exe
Benchmark 1: .\getuser.exe
  Time (mean ± σ):     528.5 ms ±   1.7 ms    [User: 0.0 ms, System: 1.6 ms]
  Range (min … max):   526.2 ms … 531.7 ms    10 runs

# After change, "best case" shows a ~50x speed-up
> hyperfine .\getuser_fixed.exe
Benchmark 1: .\getuser_fixed.exe
  Time (mean ± σ):      10.0 ms ±   0.6 ms    [User: 0.3 ms, System: 0.3 ms]
  Range (min … max):     8.6 ms …  13.4 ms    154 runs

# Before change, "worst case" (connection to Active Directory disrupted)
> hyperfine --runs=1 .\getuser.exe
Benchmark 1: .\getuser.exe
  Time (abs ≡):        22.529 s               [User: 0.000 s, System: 0.000 s]

# After change, "worst case" shows a >200x speed-up
> hyperfine .\getuser_fixed.exe
Benchmark 1: .\getuser_fixed.exe
  Time (mean ± σ):       9.5 ms ±   0.6 ms    [User: 0.2 ms, System: 0.1 ms]
  Range (min … max):     8.4 ms …  13.2 ms    154 runs

So impressive! 🚀

For comparison, I also benchmarked the problematic workaround that some people use, which is to rely on the %USERNAME% environment variable on Windows. The performance as measured by the above benchmark is the same, so I can't think of a good reason to keep using %USERNAME%.

I think this will not only result in an ecosystem-wide startup time improvement of Go tools running on Windows that were affected by this, but if we can get folks to revert their workarounds that depend on %USERNAME%, it will improve security as well, because...

> .\getuser_from_envvar.exe
Result: philwo
> set USERNAME=mallory
> .\getuser_from_envvar.exe
Result: mallory

😅

Thanks,
Philipp

@qmuntal
Copy link
Member

qmuntal commented Jul 11, 2024

Wow, thank you so much for quickly finding & implementing this fix.

Glad that it helped 😸, thanks for testing it. I'm afraid it is too late to merge the fix into go1.23 release branch, unless the @golang/release team thinks it worth the risk.

@gopherbot
Copy link
Contributor

Change https://go.dev/cl/604395 mentions this issue: os/user: document Current improvements

@dmitshur dmitshur added Performance NeedsFix The path to resolution is known, but the work has not been done. and removed NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. labels Aug 9, 2024
@dmitshur dmitshur added this to the Go1.24 milestone Aug 9, 2024
gopherbot pushed a commit that referenced this issue Aug 10, 2024
This reverts CL 597255.

Reason for revert: Broke windows/arm64

Fixes #68822.
Updates #68312.

Change-Id: I43efabad43c74045888bb62bd27522aeaba0a64c
Reviewed-on: https://go-review.googlesource.com/c/go/+/604555
Reviewed-by: Ian Lance Taylor <iant@google.com>
Reviewed-by: Dmitri Shuralyov <dmitshur@google.com>
LUCI-TryBot-Result: Go LUCI <golang-scoped@luci-project-accounts.iam.gserviceaccount.com>
@qmuntal
Copy link
Member

qmuntal commented Aug 10, 2024

Reopen due to CL 604555. I'll prepare a CL with another attempt soon.

@qmuntal qmuntal reopened this Aug 10, 2024
@gopherbot
Copy link
Contributor

Change https://go.dev/cl/604555 mentions this issue: Revert "os/user: speed up Current on Windows"

@gopherbot
Copy link
Contributor

Change https://go.dev/cl/605135 mentions this issue: os/user: speed up Current on Windows

gopherbot pushed a commit that referenced this issue Aug 21, 2024
Update #21867.
Update #68312.
Update #68647.

Change-Id: Ic41d6747c5a54ba28c1292258aa4d318ccb9fe40
Reviewed-on: https://go-review.googlesource.com/c/go/+/604395
Reviewed-by: Cherry Mui <cherryyz@google.com>
Reviewed-by: Dmitri Shuralyov <dmitshur@google.com>
LUCI-TryBot-Result: Go LUCI <golang-scoped@luci-project-accounts.iam.gserviceaccount.com>
Reviewed-by: Alex Brainman <alex.brainman@gmail.com>
@neolit123
Copy link
Contributor

neolit123 commented Aug 22, 2024

a96e736

func GetUserName(format uint32) (string, error) {
	n := uint32(50)

@qmuntal
instead of 50, should that have been UNLEN + 1, which is 256 + 1?

A pointer to the buffer to receive the user's logon name. If this buffer is not large enough to contain the entire user name, the function fails. A buffer size of (UNLEN + 1) characters will hold the maximum length user name including the terminating null character. UNLEN is defined in Lmcons.h.

https://learn.microsoft.com/en-us/windows/win32/api/winbase/nf-winbase-getusernamea#parameters

@alexbrainman
Copy link
Member

@neolit123

instead of 50, should that have been UNLEN + 1, which is 256 + 1?

Why 257?

257 is too large for an average user name. We start with 50 and grow only if 50 is not large enough.

Alex

@neolit123
Copy link
Contributor

@neolit123

instead of 50, should that have been UNLEN + 1, which is 256 + 1?

Why 257?

257 is too large for an average user name. We start with 50 and grow only if 50 is not large enough.

Alex

i missed this part of the function docs, that n will receive the req size.

If lpNameBuffer is too small, the function fails and GetLastError returns ERROR_MORE_DATA. This parameter receives the required buffer size, in Unicode characters (whether or not Unicode is being used), including the terminating null character.

https://learn.microsoft.com/en-us/windows/win32/api/secext/nf-secext-getusernameexa#parameters

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
NeedsFix The path to resolution is known, but the work has not been done. OS-Windows Performance
Projects
None yet
Development

No branches or pull requests

10 participants