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

os/exec: O_APPEND *os.File as Cmd.Stdout results in "write error: Bad file descriptor" on Windows #27638

Closed
mvdan opened this issue Sep 12, 2018 · 13 comments
Labels
FrozenDueToAge NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. OS-Windows
Milestone

Comments

@mvdan
Copy link
Member

mvdan commented Sep 12, 2018

Beware that I haven't used Windows in more than seven years, and I have never developed on it. So I might have missed something obvious, or this may be a duplicate - apologies if so.

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

go version go1.11 windows/amd64

Does this issue reproduce with the latest release?

Yes.

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

set GOARCH=amd64
set GOBIN=
set GOCACHE=C:\Users\appveyor\AppData\Local\go-build
set GOEXE=.exe
set GOFLAGS=
set GOHOSTARCH=amd64
set GOHOSTOS=windows
set GOOS=windows
set GOPATH=c:\gopath
set GOPROXY=
set GORACE=
set GOROOT=C:\go
set GOTMPDIR=
set GOTOOLDIR=C:\go\pkg\tool\windows_amd64
set GCCGO=gccgo
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 -fno-caret-diagnostics -Qunused-arguments -fmessage-length=0 -fdebug-prefix-map=C:\Users\appveyor\AppData\Local\Temp\1\go-build205334498=/tmp/go-build -gno-record-gcc-switches

What did you do?

Try to feed a write-append os.File as Cmd.Stdout:

https://play.golang.org/p/VsK_0Er5WiR

What did you expect to see?

What I see on go version devel +b2fcfc1a50 Wed Sep 12 07:50:10 2018 +0000 linux/amd64:

$ go run reproduce_bug.go
$ cat f
foobarbaz

What did you see instead?

go run reproduce_bug.go
echo: write error: Bad file descriptor
panic: exit status 1
goroutine 1 [running]:
main.main()
	C:/gopath/src/mvdan.cc/sh/reproduce_bug.go:35 +0x32a
exit status 2

I'm reproducing this via AppVeyor CI, since I don't have a Windows machine at hand: https://ci.appveyor.com/project/mvdan/sh/build/312

This is a minimized case after a Windows user reported a bug in a project of mine: mvdan/sh#289

I carefully read both the os and os/exec godoc pages, and I couldn't find anything that seemed to imply this wouldn't work. I do see ExtraFiles is not supported on Windows., but I'm not using that myself. And a non-append file works, as far as I can tell.

In the original issue, the user shows how manually setting up the file for appending via f.Seek(0, 2) instead of O_APPEND does the trick. So it seems to me like what I'm doing should be somehow possible.

/cc @alexbrainman @antylama

@mvdan mvdan added OS-Windows NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. labels Sep 12, 2018
@mvdan
Copy link
Member Author

mvdan commented Sep 12, 2018

Possible factors that don't affect the outcome of the error:

  • Whether the file exists or not previous to the Cmd.Run
  • What the file permissions on the file are (since this is on Windows)
  • Whether the file is opened with O_RDWR or O_WRONLY
  • Whether we feed the file directly into exec.Cmd, or write into it ourselves first

@ianlancetaylor ianlancetaylor added this to the Unplanned milestone Sep 12, 2018
@ianlancetaylor
Copy link
Contributor

What is the echo program you are running? Is it written in Go or does it come with Windows? Or is it part of cygwin?

I think the error "Bad file descriptor" must be coming from Windows somewhere; I don't see it in the Go standard library.

@mvdan
Copy link
Member Author

mvdan commented Sep 12, 2018

Yes, it does come from the called program. The original issue does mention that this only happens with some kinds of programs one can call on Windows.

I'll try to reproduce the issue with a stand-alone Go binary too. Hopefully that should help narrow down and debug the issue.

@mvdan
Copy link
Member Author

mvdan commented Sep 12, 2018

Is there a way to see what kind of executable one is using on Windows? That is - static or dynamic, 32 or 64-bit, if it's part of cygwin or not, etc.

I tried to reproduce this with a "hello world" program in Go, and it doesn't seem to happen there. So this seems in line with @antylama's investigation - see mvdan/sh#289 (comment).

This is what I tried as a standalone reproducer:

$ cat caller.go
// +build ignore

package main

import (
        "bytes"
        "io/ioutil"
        "os"
        "os/exec"
)

func main() {
        // create the file and add some bytes
        if err := ioutil.WriteFile("f", []byte("foo"), 0644); err != nil {
                panic(err)
        }

        // append some extra bytes
        f, err := os.OpenFile("f", os.O_WRONLY|os.O_APPEND, 0644)
        if err != nil {
                panic(err)
        }

        // writing normally works
        if _, err := f.WriteString("bar"); err != nil {
                panic(err)
        }

        cmd := exec.Command("./called")
        cmd.Stdout = f
        var buf bytes.Buffer
        cmd.Stderr = &buf
        if err := cmd.Run(); err != nil {
                println(buf.String())
                panic(err)
        }
}
$ cat called.go
// +build ignore

package main

import "os"

func main() {
        os.Stdout.WriteString("baz\n")
}
$ go build called.go
$ go run caller.go
$ cat f
foobarbaz

Here's windows succeeding on that: https://ci.appveyor.com/project/mvdan/sh/build/315

I even tried compiling a binary for 32-bit, in case that was it, but it doesn't seem to matter. Or perhaps I didn't set or export the environment variable properly. Not experienced on Windows, I'm afraid. Pointers welcome.

@antylama
Copy link

Look's like binaries from https://git-scm.com/download/win, installed in:
C:\Program Files\Git\usr\bin\ don't working.

c:\>git --version
git version 2.18.0.windows.1

@alexbrainman
Copy link
Member

@mvdan what Ian said. You have some echo.exe program in your PATH, that does not like what you are doing to it.

I tried your program here, and I get different output:

C:\>C:\test

panic: exec: "echo": executable file not found in %PATH%

goroutine 1 [running]:
main.main()
        /home/alex/src/issues/go/27638/reproduce_bug.go:35 +0x32a

C:\>

because I do not have echo.exe in my PATH. Windows does not come with echo.exe program. cmd.exe (command line interpreter / windows shell) has echo command that you can use in windows batch file (shell scripts) or while talking to cmd.exe. For example, I adjusted your program to https://play.golang.org/p/arRrmZ2IyR8 and get what your expect here:

C:\>C:\test

C:\>type f
foobarbaz

C:\>

I do not know why your echo.exe does not work in your setup. Sorry.

Alex

@mvdan
Copy link
Member Author

mvdan commented Sep 13, 2018

Investigated a bit further. Turns out that the echo program is coming from Git for Windows, as you can see on https://ci.appveyor.com/project/mvdan/sh/build/322:

$ git version
git version 2.17.1.windows.2
$ where echo
C:\Program Files\Git\usr\bin\echo.exe
$ go run caller.go
echo: write error: Bad file descriptor
panic: exit status 1
goroutine 1 [running]:
main.main()
	C:/gopath/src/mvdan.cc/sh/caller.go:30 +0x2f1
exit status 2

Alex, could you please try reproducing this with one of the unix-like binaries installed with Git? I believe you can get an installer from http://git-scm.com/download/win. Running any other program, such as go or git, works fine.

I tried my best to install Git on AppVeyor to fully reproduce this from scratch, but running the installer exe directly just hung the CI build for ten minutes.

My best guess (also following @antylama's investigation) is that cygwin or something like it is to blame. As you can see on https://github.com/git-for-windows/git/wiki/FAQ, Git for Windows seems to use http://www.msys2.org/.

So it seems like one must run an executable on Windows through MSYS2 and cygwin to reproduce this bug.

@mvdan
Copy link
Member Author

mvdan commented Sep 13, 2018

To clarify - this may mean that this is a bug in cygwin, MSYS2, Git for Windows, or elsewhere - I really don't know. I can't really debug stuff on Windows, so unfortunately I cannot dig further.

@mvdan
Copy link
Member Author

mvdan commented Sep 14, 2018

Here's the very same issue, encountered in 2016, courtesy of @Dirbaio: msteveb/jimtcl#59

Their "fix" was to seek to the end of the file instead of opening in O_APPEND mode, which is the same workaround that @antylama suggested. Unfortunately, they didn't seem to find an actual fix. They still got to the same conclusion, though - this is somehow related to mingw/msys2.

@alexbrainman
Copy link
Member

Alex, could you please try reproducing this with one of the unix-like binaries installed with Git?

Sure, I have Git installed on my computer. And, if I adjust my path to include "c:\Program Files\Git\usr\bin", I can reproduce your problem here.

My best guess (also following @antylama's investigation) is that cygwin or something like it is to blame.

I would not know. If someone wants to investigate this properly, they would need to find source of echo.exe and add debugging to it to see what is happening. I do not have time to do that. Sorry.

Here's the very same issue, encountered in 2016, courtesy of @Dirbaio: msteveb/jimtcl#59

It does sounds similar to what we see here.

Their "fix" was to seek to the end of the file instead of opening in O_APPEND mode

I do not like the fix. They split single "open file" operation into 2 - "open file" and "seek". So there is a race here. They might not care about the race, but our code is used by many many people. FILE_APPEND_DATA does exactly what is required here, so without understanding the problem with the echo.exe, I would not like to change anything.

Alex

@mvdan
Copy link
Member Author

mvdan commented Sep 15, 2018

I can reproduce your problem here.

OK - so at least I'm not going mad :)

I do not have time to do that. Sorry.

I never intended to hand this bug to you. I pinged you since you're generally involved in Windows support, and I know little about the platform.

FILE_APPEND_DATA does exactly what is required here

This is why I put "fix" in quotes. It's a workaround, and like you say, not one that Go itself should take. I could potentially adopt the workaround in my project, but that's a much less invasive change.

Over at the original issue, @antylama and myself have tried to reproduce the same bug with other languages to try and see if this is a bug in Go or not. We've only been able to get programs that either append data correctly, or seem to ignore O_APPEND entirely. We haven't been able to find a way to reproduce the crash without Go so far.

I'd like to keep the two issues open for a few weeks, to see if anyone makes a breakthrough. Debugging on Windows is painfully slow for me since I don't have a machine with it, so I think my investigation of the bug will stop for now.

@alexbrainman
Copy link
Member

I pinged you since you're generally involved in Windows support, and I know little about the platform.

I am not really a Windows expert. It just not many others want to fix Windows things. And I do use Windows. Anyway, I am happy to help, if I can.

We've only been able to get programs that either append data correctly, or seem to ignore O_APPEND entirely. We haven't been able to find a way to reproduce the crash without Go so far.

If echo.exe was written in Go. I would download the source and build it, and add debugging fmt.Printf to see what the problem is, and then decide what to do. But, I suspect, echo.exe is written in C and compiled with gcc, so it won't be as easy to do it on WIndows - Windows does not come with gcc or make or other tools. Maybe, if you can find the source, you could cross compile from Linux. I am not sure. That is why I use Go, instead of C on WIndows.

Alex

@mvdan
Copy link
Member Author

mvdan commented Dec 2, 2018

The original issue over in my repository stalled, mainly because I don't have a Windows machine to debug this on.

It seems clear that it's the binaries being called which are doing something unusual. I'm no longer sure that this is a bug in Go itself.

I don't think keeping this issue open for longer makes sense, since noone seems to be willing to investigate further. Thanks again @ianlancetaylor and @alexbrainman for your time. Hopefully the next developer to run into the error will find this issue with a quick internet search, anyway.

@mvdan mvdan closed this as completed Dec 2, 2018
@golang golang locked and limited conversation to collaborators Dec 2, 2019
Sign up for free to subscribe to this conversation on GitHub. Already have an account? Sign in.
Labels
FrozenDueToAge NeedsInvestigation Someone must examine and confirm this is a valid issue and not a duplicate of an existing one. OS-Windows
Projects
None yet
Development

No branches or pull requests

5 participants