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/compile/internal/logopt: TestLogOpt/Copy fails with 'Access is denied.' error #38251

Closed
alexbrainman opened this issue Apr 5, 2020 · 6 comments

Comments

@alexbrainman
Copy link
Member

@alexbrainman alexbrainman commented Apr 5, 2020

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

go version devel +fff7509d47 Sat Apr 4 01:01:04 2020 +0000 windows/amd64

Does this issue reproduce with the latest release?

I don't know.

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

go env Output
set GO111MODULE=off
set GOARCH=amd64
set GOBIN=
set GOCACHE=C:\Users\Alex\AppData\Local\go-build
set GOENV=C:\Users\Alex\AppData\Roaming\go\env
set GOEXE=.exe
set GOFLAGS=
set GOHOSTARCH=amd64
set GOHOSTOS=windows
set GOINSECURE=
set GONOPROXY=
set GONOSUMDB=
set GOOS=windows
set GOPATH=c:\users\alex\dev
set GOPRIVATE=
set GOPROXY=https://proxy.golang.org,direct
set GOROOT=c:\users\alex\dev\go
set GOSUMDB=sum.golang.org
set GOTMPDIR=
set GOTOOLDIR=c:\users\alex\dev\go\pkg\tool\windows_amd64
set GCCGO=gccgo
set AR=ar
set CC=gcc
set CXX=g++
set CGO_ENABLED=1
set GOMOD=
set CGO_CFLAGS=-g -O2
set CGO_CPPFLAGS=
set CGO_CXXFLAGS=-g -O2
set CGO_FFLAGS=-g -O2
set CGO_LDFLAGS=-g -O2
set PKG_CONFIG=pkg-config
set GOGCCFLAGS=-m64 -mthreads -fmessage-length=0 -fdebug-prefix-map=C:\Users\Alex\AppData\Local\Temp\go-build775355946=/tmp/go-build -gno-record-gcc-switches

What did you do?

I run

go test -short cmd/compile/internal/logopt

command.

What did you expect to see?

I expected command to succeed.

What did you see instead?

Test fails with:

--- FAIL: TestLogOpt (0.30s)
    --- FAIL: TestLogOpt/Copy (0.16s)
        --- FAIL: TestLogOpt/Copy/arm (0.02s)
            logopt_test.go:199: [c:\users\alex\dev\go\bin\go.exe tool compile -p x -json=0,file://log/opt -o C:\Users\Alex\AppData\Local\Temp\TestLogOpt028005011\copy.o C:\Users\Alex\AppData\Local\Temp\TestLogOpt028005011\copy.go]
            logopt_test.go:204: go: creating work dir: mkdir C:\WINDOWS\go-build191589167: Access is denied.
            logopt_test.go:131: -json=0,file://log/opt should have succeeded
            logopt_test.go:135: -json=0,file://log/opt missing expected log file
            logopt_test.go:138:
            logopt_test.go:37: did not see phrase {"range":{"start":{"line":3,"character":2},"end":{"line":3,"character":2}},"severity":3,"code":"copy","source":"go compiler","message":"128 bytes"} in
            logopt_test.go:37: did not see phrase {"range":{"start":{"line":9,"character":2},"end":{"line":9,"character":2}},"severity":3,"code":"copy","source":"go compiler","message":"128 bytes"} in
            logopt_test.go:43: expected exactly 2 occurences of "code":"copy" in
        --- FAIL: TestLogOpt/Copy/arm64 (0.02s)
            logopt_test.go:199: [c:\users\alex\dev\go\bin\go.exe tool compile -p x -json=0,file://log/opt -o C:\Users\Alex\AppData\Local\Temp\TestLogOpt028005011\copy.o C:\Users\Alex\AppData\Local\Temp\TestLogOpt028005011\copy.go]
            logopt_test.go:204: go: creating work dir: mkdir C:\WINDOWS\go-build401421879: Access is denied.
            logopt_test.go:131: -json=0,file://log/opt should have succeeded
            logopt_test.go:135: -json=0,file://log/opt missing expected log file
            logopt_test.go:138:
            logopt_test.go:37: did not see phrase {"range":{"start":{"line":3,"character":2},"end":{"line":3,"character":2}},"severity":3,"code":"copy","source":"go compiler","message":"128 bytes"} in
            logopt_test.go:37: did not see phrase {"range":{"start":{"line":9,"character":2},"end":{"line":9,"character":2}},"severity":3,"code":"copy","source":"go compiler","message":"128 bytes"} in
            logopt_test.go:43: expected exactly 2 occurences of "code":"copy" in
        --- FAIL: TestLogOpt/Copy/386 (0.02s)
            logopt_test.go:199: [c:\users\alex\dev\go\bin\go.exe tool compile -p x -json=0,file://log/opt -o C:\Users\Alex\AppData\Local\Temp\TestLogOpt028005011\copy.o C:\Users\Alex\AppData\Local\Temp\TestLogOpt028005011\copy.go]
            logopt_test.go:204: go: creating work dir: mkdir C:\WINDOWS\go-build231443483: Access is denied.
            logopt_test.go:131: -json=0,file://log/opt should have succeeded
            logopt_test.go:135: -json=0,file://log/opt missing expected log file
            logopt_test.go:138:
            logopt_test.go:37: did not see phrase {"range":{"start":{"line":3,"character":2},"end":{"line":3,"character":2}},"severity":3,"code":"copy","source":"go compiler","message":"128 bytes"} in
            logopt_test.go:37: did not see phrase {"range":{"start":{"line":9,"character":2},"end":{"line":9,"character":2}},"severity":3,"code":"copy","source":"go compiler","message":"128 bytes"} in
            logopt_test.go:43: expected exactly 2 occurences of "code":"copy" in
        --- FAIL: TestLogOpt/Copy/amd64 (0.02s)
            logopt_test.go:199: [c:\users\alex\dev\go\bin\go.exe tool compile -p x -json=0,file://log/opt -o C:\Users\Alex\AppData\Local\Temp\TestLogOpt028005011\copy.o C:\Users\Alex\AppData\Local\Temp\TestLogOpt028005011\copy.go]
            logopt_test.go:204: go: creating work dir: mkdir C:\WINDOWS\go-build091527347: Access is denied.
            logopt_test.go:131: -json=0,file://log/opt should have succeeded
            logopt_test.go:135: -json=0,file://log/opt missing expected log file
            logopt_test.go:138:
            logopt_test.go:37: did not see phrase {"range":{"start":{"line":3,"character":2},"end":{"line":3,"character":2}},"severity":3,"code":"copy","source":"go compiler","message":"128 bytes"} in
            logopt_test.go:37: did not see phrase {"range":{"start":{"line":9,"character":2},"end":{"line":9,"character":2}},"severity":3,"code":"copy","source":"go compiler","message":"128 bytes"} in
            logopt_test.go:43: expected exactly 2 occurences of "code":"copy" in
        --- FAIL: TestLogOpt/Copy/mips (0.02s)
            logopt_test.go:199: [c:\users\alex\dev\go\bin\go.exe tool compile -p x -json=0,file://log/opt -o C:\Users\Alex\AppData\Local\Temp\TestLogOpt028005011\copy.o C:\Users\Alex\AppData\Local\Temp\TestLogOpt028005011\copy.go]
            logopt_test.go:204: go: creating work dir: mkdir C:\WINDOWS\go-build209411947: Access is denied.
            logopt_test.go:131: -json=0,file://log/opt should have succeeded
            logopt_test.go:135: -json=0,file://log/opt missing expected log file
            logopt_test.go:138:
            logopt_test.go:37: did not see phrase {"range":{"start":{"line":3,"character":2},"end":{"line":3,"character":2}},"severity":3,"code":"copy","source":"go compiler","message":"128 bytes"} in
            logopt_test.go:37: did not see phrase {"range":{"start":{"line":9,"character":2},"end":{"line":9,"character":2}},"severity":3,"code":"copy","source":"go compiler","message":"128 bytes"} in
            logopt_test.go:43: expected exactly 2 occurences of "code":"copy" in
        --- FAIL: TestLogOpt/Copy/mips64 (0.02s)
            logopt_test.go:199: [c:\users\alex\dev\go\bin\go.exe tool compile -p x -json=0,file://log/opt -o C:\Users\Alex\AppData\Local\Temp\TestLogOpt028005011\copy.o C:\Users\Alex\AppData\Local\Temp\TestLogOpt028005011\copy.go]
            logopt_test.go:204: go: creating work dir: mkdir C:\WINDOWS\go-build066462375: Access is denied.
            logopt_test.go:131: -json=0,file://log/opt should have succeeded
            logopt_test.go:135: -json=0,file://log/opt missing expected log file
            logopt_test.go:138:
            logopt_test.go:37: did not see phrase {"range":{"start":{"line":3,"character":2},"end":{"line":3,"character":2}},"severity":3,"code":"copy","source":"go compiler","message":"128 bytes"} in
            logopt_test.go:37: did not see phrase {"range":{"start":{"line":9,"character":2},"end":{"line":9,"character":2}},"severity":3,"code":"copy","source":"go compiler","message":"128 bytes"} in
            logopt_test.go:43: expected exactly 2 occurences of "code":"copy" in
        --- FAIL: TestLogOpt/Copy/ppc64le (0.02s)
            logopt_test.go:199: [c:\users\alex\dev\go\bin\go.exe tool compile -p x -json=0,file://log/opt -o C:\Users\Alex\AppData\Local\Temp\TestLogOpt028005011\copy.o C:\Users\Alex\AppData\Local\Temp\TestLogOpt028005011\copy.go]
            logopt_test.go:204: go: creating work dir: mkdir C:\WINDOWS\go-build464334239: Access is denied.
            logopt_test.go:131: -json=0,file://log/opt should have succeeded
            logopt_test.go:135: -json=0,file://log/opt missing expected log file
            logopt_test.go:138:
            logopt_test.go:37: did not see phrase {"range":{"start":{"line":3,"character":2},"end":{"line":3,"character":2}},"severity":3,"code":"copy","source":"go compiler","message":"128 bytes"} in
            logopt_test.go:37: did not see phrase {"range":{"start":{"line":9,"character":2},"end":{"line":9,"character":2}},"severity":3,"code":"copy","source":"go compiler","message":"128 bytes"} in
            logopt_test.go:43: expected exactly 2 occurences of "code":"copy" in
        --- FAIL: TestLogOpt/Copy/s390x (0.02s)
            logopt_test.go:199: [c:\users\alex\dev\go\bin\go.exe tool compile -p x -json=0,file://log/opt -o C:\Users\Alex\AppData\Local\Temp\TestLogOpt028005011\copy.o C:\Users\Alex\AppData\Local\Temp\TestLogOpt028005011\copy.go]
            logopt_test.go:204: go: creating work dir: mkdir C:\WINDOWS\go-build220467091: Access is denied.
            logopt_test.go:131: -json=0,file://log/opt should have succeeded
            logopt_test.go:135: -json=0,file://log/opt missing expected log file
            logopt_test.go:138:
            logopt_test.go:37: did not see phrase {"range":{"start":{"line":3,"character":2},"end":{"line":3,"character":2}},"severity":3,"code":"copy","source":"go compiler","message":"128 bytes"} in
            logopt_test.go:37: did not see phrase {"range":{"start":{"line":9,"character":2},"end":{"line":9,"character":2}},"severity":3,"code":"copy","source":"go compiler","message":"128 bytes"} in
            logopt_test.go:43: expected exactly 2 occurences of "code":"copy" in
        --- FAIL: TestLogOpt/Copy/wasm (0.02s)
            logopt_test.go:199: [c:\users\alex\dev\go\bin\go.exe tool compile -p x -json=0,file://log/opt -o C:\Users\Alex\AppData\Local\Temp\TestLogOpt028005011\copy.o C:\Users\Alex\AppData\Local\Temp\TestLogOpt028005011\copy.go]
            logopt_test.go:204: go: creating work dir: mkdir C:\WINDOWS\go-build247928563: Access is denied.
            logopt_test.go:131: -json=0,file://log/opt should have succeeded
            logopt_test.go:135: -json=0,file://log/opt missing expected log file
            logopt_test.go:138:
            logopt_test.go:37: did not see phrase {"range":{"start":{"line":3,"character":2},"end":{"line":3,"character":2}},"severity":3,"code":"copy","source":"go compiler","message":"128 bytes"} in
            logopt_test.go:37: did not see phrase {"range":{"start":{"line":9,"character":2},"end":{"line":9,"character":2}},"severity":3,"code":"copy","source":"go compiler","message":"128 bytes"} in
            logopt_test.go:43: expected exactly 2 occurences of "code":"copy" in
FAIL
FAIL    cmd/compile/internal/logopt     0.386s
FAIL

I was able to bisect this failure to

47ade08141b23cfeafed92943e16012d5dc5eb8b is the first bad commit
commit 47ade08141b23cfeafed92943e16012d5dc5eb8b
Author: David Chase <drchase@google.com>
Date:   Sat Nov 2 23:57:11 2019 -0400

    cmd/compile: add logging for large (>= 128 byte) copies

    For 1.15, unless someone really wants it in 1.14.

    A performance-sensitive user thought this would be useful,
    though "large" was not well-defined.  If 128 is large,
    there are 139 static instances of "large" copies in the compiler
    itself.

    Includes test.

    Change-Id: I81f20c62da59d37072429f3a22c1809e6fb2946d
    Reviewed-on: https://go-review.googlesource.com/c/go/+/205066
    Run-TryBot: David Chase <drchase@google.com>
    TryBot-Result: Gobot Gobot <gobot@golang.org>
    Reviewed-by: Cherry Zhang <cherryyz@google.com>

:040000 040000 46c10febf7a9c71e49d1ad7ff4027e3be81453af cb045d689803f00f1f8dd3fb2ab912a5f38df682 M  src

/cc @dr2chase and @cherrymui

Alex

@alexbrainman
Copy link
Member Author

@alexbrainman alexbrainman commented Apr 5, 2020

logopt_test.go:204: go: creating work dir: mkdir C:\WINDOWS\go-build191589167: Access is denied.

Just briefly looking at the error.

It looks like this test is creating directory in my Windows directory (C:\WINDOWS). This is not allowed. I suspect our builders succeed because they, probably, run as Administrator.

Alex

@bcmills
Copy link
Member

@bcmills bcmills commented Apr 6, 2020

I suspect our builders succeed because they, probably, run as Administrator.

#10719 (non-root builder for Linux) is somewhat related.

@gopherbot
Copy link

@gopherbot gopherbot commented Apr 6, 2020

Change https://golang.org/cl/227339 mentions this issue: cmd/compile: make logopt test skip if cannot create scratch directory

@egonelbre
Copy link
Contributor

@egonelbre egonelbre commented Apr 7, 2020

I'm still seeing this failure:

C:\Go.tip\src\cmd\compile\internal\logopt>go version
go version devel +74d6de03fd Mon Apr 6 18:06:41 2020 +0000 windows/amd64
C:\Go.tip\src\cmd\compile\internal\logopt>go test .
--- FAIL: TestLogOpt (0.42s)
    --- FAIL: TestLogOpt/Copy (0.17s)
        --- FAIL: TestLogOpt/Copy/arm (0.02s)
            logopt_test.go:199: [C:\Go.tip\bin\go.exe tool compile -p x -json=0,file://log/opt -o Z:\Temp\TestLogOpt955495483\copy.o Z:\Temp\TestLogOpt955495483\copy.go]
            logopt_test.go:204: go: creating work dir: mkdir C:\WINDOWS\go-build315158903: Access is denied.
            logopt_test.go:131: -json=0,file://log/opt should have succeeded
            logopt_test.go:135: -json=0,file://log/opt missing expected log file
            logopt_test.go:138:
            logopt_test.go:37: did not see phrase {"range":{"start":{"line":3,"character":2},"end":{"line":3,"character":2}},"severity":3,"code":"copy","source":"go compiler","message":"
128 bytes"} in
            logopt_test.go:37: did not see phrase {"range":{"start":{"line":9,"character":2},"end":{"line":9,"character":2}},"severity":3,"code":"copy","source":"go compiler","message":"
128 bytes"} in
            logopt_test.go:43: expected exactly 2 occurences of "code":"copy" in
<... snip ...>

@gopherbot
Copy link

@gopherbot gopherbot commented Apr 7, 2020

Change https://golang.org/cl/227497 mentions this issue: cmd/compile/internal/logopt: preserve env while running command

gopherbot pushed a commit that referenced this issue Apr 7, 2020
The test was not preserving temporary directory flags leading to a
failure on windows with:

    mkdir C:\WINDOWS\go-build315158903: Access is denied.

Fixes #38251

Change-Id: I6ee31b31e84b7f6e75ea6ee0f3b8c094835bf5d2
Reviewed-on: https://go-review.googlesource.com/c/go/+/227497
Reviewed-by: David Chase <drchase@google.com>
@gopherbot
Copy link

@gopherbot gopherbot commented Apr 11, 2020

Change https://golang.org/cl/227802 mentions this issue: Revert "cmd/compile: make logopt test skip if cannot create scratch directory"

gopherbot pushed a commit that referenced this issue Apr 11, 2020
…irectory"

This reverts commit 9853481.

Reason for revert: The change does not really fixes issue #38251. CL 227497 is real fix.

Change-Id: I9f556005baf1de968f059fb8dad89dae05330aa6
Reviewed-on: https://go-review.googlesource.com/c/go/+/227802
Run-TryBot: Alex Brainman <alex.brainman@gmail.com>
TryBot-Result: Gobot Gobot <gobot@golang.org>
Reviewed-by: David Chase <drchase@google.com>
@golang golang locked and limited conversation to collaborators Apr 11, 2021
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Projects
None yet
Development

No branches or pull requests

4 participants