That test runs these commands from the misc/cgo/testcshared directory:

GOPATH=`pwd` go build -buildmode=c-shared -installsuffix testcshared -o libgo2.so libgo2
gcc -o testp2 main2.c -Wl,--no-as-needed libgo2.so
LD_LIBRARY_PATH=. ./testp2

(Running those commands will leave the files libgo2.so and testp2 behind, you'll want to clean them up.)

Can you confirm that running those commands by themselves demonstrates the same failure.

It's possible that the test will run the wrong version of go; which go command is first on your PATH?

@ianlancetaylor,

It's possible that the test will run the wrong version of go; which go command is first on your PATH?

$ which go
/usr/lib/go-1.9/bin/go
$ go version
go version go1.9.4 linux/amd64

This version is taken from ppa:gophers/archive.

Can you confirm that running those commands by themselves demonstrates the same failure.

Yes, it gives:

$ LD_LIBRARY_PATH=. ./testp2
BUG: failed to read any data from pipe

See also strace output.

Thanks for the strace output. That was going to be my next question. But what we need is actually the output from strace -f. Can you show that? Thanks.

@ianlancetaylor, oh, you're right, here it is: strace -f -v -s 100 output.

Thanks. That is strange. I see this:

[pid 18664] pipe([3, 4])                = 0
[pid 18664] dup2(3, 100 <unfinished ...>

and then the call to dup2 never completes, despite many calls to nanosleep for 1000000 nanoseconds. The next PID 18664 shows up is at the very end of the trace when all the processes are exiting.

[pid 18664] <... dup2 resumed>)         = ?
[pid 18664] +++ exited with 2 +++

What could possibly cause dup2 to hang like that? Are you using a FUSE file system of any sort?

@ianlancetaylor,

No, there are no FUSE file systems mounted inside my home directory (mount).

I've also noticed that increasing the number of iterations in misc/cgo/testcshared/main2.c from 1000 to 10000 helps to PASS the test, i.e. dup2 resumes in the libgo2 thread after more iterations.

Do you have an unusually slow system? 1000 iterations of a sleep for 1000000 nanoseconds is a full second. How could it possibly take a full second for dup2 to complete? It's not like the program is doing anything, it's mostly sleeping. Can you show strace -ftt output?

@ianlancetaylor,

Do you have an unusually slow system?

I have 32×2.2GHz CPU cores with small load average: 0.82, 1.25, 1.12.

Can you show strace -ftt output?

I'm confused because now I can't reproduce the bug even with 1000 iterations. However, I reproduced it with 300 iterations, here is the strace -ftt output.

@ianlancetaylor,

Well, I have reproduced it with 1000 iterations again after 340 more runs of ./testp2, see strace -ftt.

Thanks. That output does clearly show that dup2 did not complete for more than one second, even though the program spent most of its time doing a loop of nothing but

[pid 12133] 00:48:36.838609 nanosleep({tv_sec=0, tv_nsec=1000000}, NULL) = 0
[pid 12133] 00:48:36.839734 read(100, 0x7fff18a156e0, 20) = -1 EBADF (Bad file descriptor)

By comparison, on my laptop, I see

[pid 238401] 14:01:39.650477 dup2(3, 100 <unfinished ...>
...
[pid 238401] 14:01:39.705113 <... dup2 resumed> ) = 100

so the dup2 call completes in much less than 1/10 second.

I'm grasping at straws, but can you try adding

    sched_yield();

before the call to nanosleep in misc/cgo/testcshared/main2.c?

@ianlancetaylor,

Since it's very difficult to reproduce the bug now (for unknown reasons), I've collected some statistics instead on how much iterations it takes for different versions of code to finish with PASS (sorted raw data).

Here is the histogram for n = 5000 runs, the X-axis (tail stripped) denotes the number of iterations to finish, the Y-axis denotes the number of runs.

.

See also five extremal values:

• without sched_yield: 9, 10, 11, 11, 12, ..., 258, 263, 274, 281, 392.
• with sched_yield: 11, 11, 12, 12, 12, ..., 256, 259, 272, 334, 340.

So, according to the above mentioned, I don't see any significant difference at all.

Change https://golang.org/cl/93895 mentions this issue: misc/cgo/testcshared: increase sleep in TestUnexportedSymbols

Well, I don't know what's going on, but it sounds like an approach like https;//golang.org/cl/93895 will at least make it more likely to pass.

@ianlancetaylor,

Yep, seems like a reasonable approach.

This is still failing:

$ greplogs -dashboard -e 'TestUnexportedSymbols' -md -l
2018-03-29T06:09:52-ac7c0ee/linux-386
2018-04-11T16:06:01-e1040d7/linux-386-clang
2018-04-17T14:39:08-58b18cf/linux-amd64
2018-04-17T23:46:11-7ba12c1/linux-386-387

Trybot failures that just happened:
https://storage.googleapis.com/go-build-log/1247948c/linux-amd64_75439f19.log
https://storage.googleapis.com/go-build-log/7c12bc2a/linux-amd64-race_9f0c9a0a.log

The test currently uses file descriptor 100, which requires the process's fdtable to be expanded. Somehow that seems to take a long time. The other threads running (the main thread written in C and the sysmon thread) are somehow blocking that. I don't have enough kernel-fu to understand how. On my system the dup2 call does block for about 0.03 seconds, while the other threads are busy sleeping in loops. I guess that somehow, sometimes, the call blocks for over 2 seconds.

I'll try a different workaround, which is to only dup to file descriptor 30. That is less than the Linux kernel's default fdtable size of 32 or 64, so the dup2 call now completes immediately without blocking at all.

Change https://golang.org/cl/108537 mentions this issue: misc/cgo/testcshared: use file descriptor 30 for TestUnexportedSymbols

@ianlancetaylor this breaks the trybots on the 1.10 release branch as well, and is probably (?) also an issue on 1.9, can you look into backporting the fix?

https://go-review.googlesource.com/c/go/+/111715#message-c7b7c5f6de1d1ad25c8c7db15599e99e29a392a7

@gopherbot please open a backport issue for 1.10 and 1.9.

Backport issue(s) opened: #25277 (for 1.10), #25278 (for 1.9).

Remember to create the cherry-pick CL(s) as soon as the patch is submitted to master, according to https://golang.org/wiki/MinorReleases.

Change https://golang.org/cl/111995 mentions this issue: [release-branch.go1.10] misc/cgo/testcshared: use file descriptor 30 for TestUnexportedSymbols

Change https://golang.org/cl/111996 mentions this issue: [release-branch.go1.9] misc/cgo/testcshared: use file descriptor 30 for TestUnexportedSymbols

Hi everyone! I've just downloaded the go code and ran the all.bash script to compile without any changes and got the following error (that resembles the original message):

##### ../misc/cgo/testcshared
--- FAIL: TestUnexportedSymbols (0.64s)
    cshared_test.go:353: run: [go build -buildmode=c-shared -installsuffix testcshared -o libgo2.so libgo2]
    cshared_test.go:367: run: [gcc -fPIC -m64 -pthread -fmessage-length=0 -fdebug-prefix-map=/tmp/go-build783986620=/tmp/go-build -gno-record-gcc-switches -I pkg/linux_amd64_shared -o testp2 main2.c -Wl,--no-as-needed libgo2.so]
    cshared_test.go:373: run: [./testp2]
    cshared_test.go:376: # NAN ChangeLog
**
FAIL
2018/07/31 23:09:06 Failed: exit status 1

I've tried two other times and the message on the last line (after "cshared_test.go:376") changed all times, suggesting some random values were being read from the fd 30. I've recompiled the binaries to use fd 100 like it was originally and I got the tests to pass.

go env:

$ go env
GOARCH="amd64"
GOBIN=""
GOCACHE="/home/danielapetruzalek/.cache/go-build"
GOEXE=""
GOHOSTARCH="amd64"
GOHOSTOS="linux"
GOOS="linux"
GOPATH="/home/danielapetruzalek/go"
GORACE=""
GOROOT="/usr/local/go"
GOTMPDIR=""
GOTOOLDIR="/usr/local/go/pkg/tool/linux_amd64"
GCCGO="gccgo"
CC="gcc"
CXX="g++"
CGO_ENABLED="1"
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 -pthread -fmessage-length=0 -fdebug-prefix-map=/tmp/go-build074359831=/tmp/go-build -gno-record-gcc-switches"

I'm testing Go on the new Google Pixelbook.

I wonder if instead of choosing an arbitrary number we could have a more safe way to select the fd? Or use another technique to run this test?

@danicat This issue is closed. Please open a new issue for that problem. Thanks.

Sure @ianlancetaylor. Done!