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

net/http: some test times out? or something fails? or some noise? #2518

Closed
rogpeppe opened this issue Dec 2, 2011 · 15 comments
Closed

net/http: some test times out? or something fails? or some noise? #2518

rogpeppe opened this issue Dec 2, 2011 · 15 comments

Comments

@rogpeppe
Copy link
Contributor

rogpeppe commented Dec 2, 2011

cd $GOROOT/src/pkg/net/http; gotest -timeout 5

6g, ubuntu 11.10, 7551fda5eeef+ tip 
(i tried weekly first)

it seems perfectly reproducible currently.

backtrace attached.

Attachments:

  1. backtrace.txt (32768 bytes)
@rogpeppe
Copy link
Contributor Author

rogpeppe commented Dec 2, 2011

Comment 1:

looks like the "unsolicited response" message has nothing to do with it . 
gotest -run HandlerPanic
hangs with no output.

@rogpeppe
Copy link
Contributor Author

rogpeppe commented Dec 2, 2011

Comment 2:

a more relevant stack trace:
% gotest -v -run HandlerPanic
rm -f _test/net/http.a
rm -f _test/net/http.a
gopack grc _test/net/http.a _gotest_.6 
=== RUN http_test.TestHandlerPanic
unexpected fault address 0x3e800003d81
throw: fault
[signal 0xb code=0x0 addr=0x3e800003d81 pc=0x416e49]
goroutine 1 [chan receive]:
testing.RunTests(0x400c00, 0x73d910, 0x5e0000005e, 0x404601, 0x28, ...)
    /home/rog/go/src/pkg/testing/testing.go:255 +0x6e7
testing.Main(0x400c00, 0x73d910, 0x5e0000005e, 0x72bcf8, 0x100000001, ...)
    /home/rog/go/src/pkg/testing/testing.go:202 +0x62
main.main()
    /home/rog/go/src/pkg/net/http/_testmain.go:124 +0x91
goroutine 2 [chan receive]:
net/http.(*persistConn).roundTrip(0xf840000b40, 0xf84001af30, 0x0, 0x0, 0x0, ...)
    /home/rog/go/src/pkg/net/http/transport.go:647 +0x284
net/http.(*Transport).RoundTrip(0xf840020340, 0xf840039b00, 0x16, 0x0, 0x0, ...)
    /home/rog/go/src/pkg/net/http/transport.go:158 +0x1ef
net/http.send(0xf840039b00, 0xf840002c60, 0xf840020340, 0x0, 0x0, ...)
    /home/rog/go/src/pkg/net/http/client.go:123 +0x1c7
net/http.(*Client).doFollowingRedirects(0x743ff0, 0xf840039b00, 0x0, 0x0, 0x0, ...)
    /home/rog/go/src/pkg/net/http/client.go:209 +0x454
net/http.(*Client).Get(0x743ff0, 0xf840021600, 0xf800000016, 0xf84003c0f0, 0x0, ...)
    /home/rog/go/src/pkg/net/http/client.go:166 +0xb8
net/http.Get(0xf840021600, 0xf800000016, 0xf840002fc0, 0x0, 0x0, ...)
    /home/rog/go/src/pkg/net/http/client.go:148 +0x51
/home/rog/go/src/pkg/net/http/_xtest_.testHandlerPanic(0xf840000300, 0x744100, 0x461982,
0xf840000300)
    /home/rog/go/src/pkg/net/http/serve_test.go:907 +0x1a0
/home/rog/go/src/pkg/net/http/_xtest_.TestHandlerPanic(0xf840000300, 0x25744990)
    /home/rog/go/src/pkg/net/http/serve_test.go:868 +0x2a
testing.tRunner(0xf840000300, 0x73df70, 0x0, 0x0)
    /home/rog/go/src/pkg/testing/testing.go:189 +0x41
created by testing.RunTests
    /home/rog/go/src/pkg/testing/testing.go:254 +0x6c7
goroutine 3 [syscall]:
syscall.Syscall6()
    /home/rog/go/src/pkg/syscall/asm_linux_amd64.s:40 +0x5
syscall.EpollWait(0xf800000006, 0xf840039a60, 0xa0000000a, 0xffffffff, 0xc, ...)
    /home/rog/go/src/pkg/syscall/zsyscall_linux_amd64.go:252 +0xa1
net.(*pollster).WaitFD(0xf840039a50, 0xf8400209c0, 0x0, 0x7700000007, 0x0, ...)
    /home/rog/go/src/pkg/net/fd_linux.go:141 +0xf8
net.(*pollServer).Run(0xf8400209c0, 0x0)
    /home/rog/go/src/pkg/net/fd.go:228 +0xcc
created by net.newPollServer
    /home/rog/go/src/pkg/net/newpollserver.go:35 +0x327
goroutine 4 [chan receive]:
net.(*pollServer).WaitRead(0xf8400209c0, 0xf84002c5a0, 0xf8400024b0, 0xb)
    /home/rog/go/src/pkg/net/fd.go:257 +0x52
net.(*netFD).accept(0xf84002c5a0, 0x4d0a00, 0x0, 0xf8400024b0, 0xb, ...)
    /home/rog/go/src/pkg/net/fd.go:635 +0x1e5
net.(*TCPListener).AcceptTCP(0xf84001e390, 0xf840020f00, 0x0, 0x0, 0x7fbf79df1fb0, ...)
    /home/rog/go/src/pkg/net/tcpsock_posix.go:268 +0x71
net.(*TCPListener).Accept(0xf84001e390, 0x0, 0x0, 0x0, 0x0, ...)
    /home/rog/go/src/pkg/net/tcpsock_posix.go:278 +0x49
net/http/httptest.(*historyListener).Accept(0xf8400215e0, 0x0, 0x0, 0x0, 0x0, ...)
    /home/rog/go/src/pkg/net/http/httptest/server.go:38 +0x67
net/http.(*Server).Serve(0xf840020a80, 0xf840020ac0, 0xf8400215e0, 0x0, 0x0, ...)
    /home/rog/go/src/pkg/net/http/server.go:983 +0x7a
created by net/http/httptest.(*Server).Start
    /home/rog/go/src/pkg/net/http/httptest/server.go:96 +0x1b7
goroutine 5 [chan receive]:
net.(*pollServer).WaitRead(0xf8400209c0, 0xf84002cf00, 0xf8400024b0, 0xb)
    /home/rog/go/src/pkg/net/fd.go:257 +0x52
net.(*netFD).Read(0xf84002cf00, 0xf840060000, 0x100000001000, 0xffffffff, 0xf8400024b0,
...)
    /home/rog/go/src/pkg/net/fd.go:408 +0x1f2
net.(*TCPConn).Read(0xf84001e360, 0xf840060000, 0x100000001000, 0x0, 0x0, ...)
    /home/rog/go/src/pkg/net/tcpsock_posix.go:74 +0x95
bufio.(*Reader).fill(0xf840020b00, 0x100000000)
    /home/rog/go/src/pkg/bufio/bufio.go:101 +0x101
bufio.(*Reader).Peek(0xf840020b00, 0xf800000001, 0x0, 0x0, 0x0, ...)
    /home/rog/go/src/pkg/bufio/bufio.go:133 +0xbc
net/http.(*persistConn).readLoop(0xf840000b40, 0x0)
    /home/rog/go/src/pkg/net/http/transport.go:521 +0x97
created by net/http.(*Transport).getConn
    /home/rog/go/src/pkg/net/http/transport.go:376 +0x548
goroutine 6 [semacquire]:
sync.(*Cond).Wait(0xf840013060, 0x41534b)
    /home/rog/go/src/pkg/sync/cond.go:68 +0xaa
io.(*pipe).write(0xf840013000, 0xf84001dc00, 0x2fc00000290, 0xf800000000, 0x0, ...)
    /home/rog/go/src/pkg/io/pipe.go:87 +0x1b8
io.(*PipeWriter).Write(0xf84001e330, 0xf84001dc00, 0x2fc00000290, 0x27c, 0x0, ...)
    /home/rog/go/src/pkg/io/pipe.go:154 +0x57
log.(*Logger).Output(0xf840028000, 0x100000002, 0xf84001ca00, 0x2bf0000027c, 0x0, ...)
    /home/rog/go/src/pkg/log/log.go:159 +0x247
log.Print(0x7fbf79df1d28, 0x100000001)
    /home/rog/go/src/pkg/log/log.go:276 +0x5d
net/http._func_002(0x7fbf79df1fb0, 0x7fbf79df1100, 0x7fbf79df1fb8, 0x7fbf79df1dc8)
    /home/rog/go/src/pkg/net/http/server.go:576 +0x22f
----- stack segment boundary -----
/home/rog/go/src/pkg/net/http/_xtest_._func_044(0xf84001e318, 0xf84001e310, 0x426102,
0xf840020e40, 0xf840020e80, ...)
    /home/rog/go/src/pkg/net/http/serve_test.go:904 +0x19f
net/http.HandlerFunc.ServeHTTP(0xf840020980, 0xf840020e40, 0xf840020e80, 0xf840039f20,
0xf840020e80, ...)
    /home/rog/go/src/pkg/net/http/server.go:688 +0x3d
net/http.(*conn).serve(0xf840000a20, 0x0)
    /home/rog/go/src/pkg/net/http/server.go:654 +0x599
created by net/http.(*Server).Serve
    /home/rog/go/src/pkg/net/http/server.go:1001 +0x298
gotest: "./6.out -test.v=true -test.run=HandlerPanic" failed: exit status 2

@rsc
Copy link
Contributor

rsc commented Dec 5, 2011

Comment 3:

Owner changed to @bradfitz.

Status changed to Accepted.

@bradfitz
Copy link
Contributor

bradfitz commented Dec 5, 2011

Comment 4:

Russ, the unsolicited noise I believe is due to this EINVAL check being removed:
http://code.google.com/p/go/source/diff?spec=svn7c18a8ff01f7c609539faad43d95551c4b5f372a&r=9942702ebc317c9f5626af670ddfcff9e8fec37e&format=side&path=/src/pkg/net/http/transport.go&old_path=/src/pkg/net/http/transport.go&old=fbac675badb483d130ad747ddb322e6bdb%C2%A844b1d1
Do you remember why that was done?
I'll look into why this test is failing, but it seems to work for all of us and our
builders, so I'm confused.

@rsc
Copy link
Contributor

rsc commented Dec 5, 2011

Comment 5:

It was removed because nothing should look for os.EINVAL.
What does that mean?  What is it really trying to catch?
No one knows.
Maybe the EINVAL used to happen because something
would get closed multiple times, or read after close?
Better to identify the situation and avoid it.
Russ

@bradfitz
Copy link
Contributor

bradfitz commented Dec 5, 2011

Comment 6:

The net.Conn Read is now returning a syscall.Errno(0x16) (EINVAL) when the remote side
of the TCP connection closes while we're waiting on a read.
It used to return os.EINVAL.
We shouldn't depend on syscall.Errno(0x16) from the http package.
You also wanted to get rid of transport_windows.go in the http package.
To solve both problems, should we introduce a new error type in the net package that
http can look for?  I'd like a portable way to detect the remote side closing.

@rsc
Copy link
Contributor

rsc commented Dec 5, 2011

Comment 7:

How about io.EOF?

@bradfitz
Copy link
Contributor

bradfitz commented Dec 5, 2011

Comment 8:

That sounds good.  So, I went to do that in the net package, starting with adding a new
test for that case, but it already passes:
// TestReadEOF verifies that we get io.EOF from a blocking read                         
                                                      
// on a TCP connection when the remote side closes.                                     
                                                      
func TestReadEOF(t *testing.T) {
        l := localListener(t)
        defer l.Close()
        closec := make(chan bool, 1)
        go func() {
                c, err := l.Accept()
                if err != nil {
                        t.Fatalf("Accept: %v", err)
                }
                <-closec
                c.Close()
        }()
        c, err := Dial("tcp", l.Addr().String())
        if err != nil {
                t.Fatalf("Dial: %v", err)
        }
        defer c.Close()
        errc := make(chan error, 1)
        go func() {
                var buf [1]byte
                _, err := c.Read(buf[:])
                errc <- err
        }()
        closec <- true
        got := <-errc
        if got != io.EOF {
                t.Errorf("got error %v; want io.EOF", got)
        }
        t.Logf("got error %v", got)
}
... so, I'm confused.
Maybe this error only happens when we get a RST packet?

@rsc
Copy link
Contributor

rsc commented Dec 5, 2011

Comment 9:

Can you get a system call trace of the net/http test when it fails?

@bradfitz
Copy link
Contributor

bradfitz commented Dec 5, 2011

Comment 10:

The http tests don't fail.
This bug is a mess of different issues.  I don't even know what the OP's issue is, so
I'm taking over this bug (at least for now), to address the log spam stuff about
Unsolicited response from server.

@bradfitz
Copy link
Contributor

bradfitz commented Dec 5, 2011

Comment 11:

I think net.Conn.Read should return different error values for a clean close (io.EOF)
and a dirty RST close.

@rsc
Copy link
Contributor

rsc commented Dec 5, 2011

Comment 12:

I guess you could do ErrUnexpectedEOF although I don't
see the difference myself.

@alexbrainman
Copy link
Member

Comment 13:

This is how I see it. And I am often wrong, but ...
There are 2 scenarios here:
1) network read completes successfully and returns 0 bytes read (EOF);
2) network read completes with error (not sure about other OSes, but on Windows you
might get many different error messages depending on situation: who closed connection,
how, where and so on).
The main question here to Brad - do you care if connection is closed because of 1) or
2)? Can you treat them in them similar fashion? If not, then why not? You then have to
decide what you are looking for in these error messages. If you just want to know
whether peer closed connection on you, I say you can't, because network will not provide
this level of details. Is user closed their browser? Is user turned their PC off? Is
user pulled their network cord out? Is ISP router turned off? Why should you care which?
Alex

@bradfitz
Copy link
Contributor

bradfitz commented Dec 8, 2011

Comment 14:

Fixed the noise (per Alex's comment #13), but I can't reproduce rogpeppe's original
crash.
Closing.

Status changed to Invalid.

@rogpeppe
Copy link
Contributor Author

rogpeppe commented Dec 8, 2011

Comment 15:

yeah, when i update to that version again and run all.bash, i don't get the crash.
probably something in my environment.

@golang golang locked and limited conversation to collaborators Jun 24, 2016
This issue was closed.
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

5 participants