hub pull-request fails with random network errors

[rolfbjarne]

hub pull-request sometimes (maybe 25% of the time) fails with a random network error (sometimes it times out after a long time instead of failing as well).

Example output:

fatal error: unexpected signal during runtime execution
[signal 0xb code=0x1 addr=0xb01dfacedebac1e pc=0xeceb]

runtime stack:
runtime.throw(0x5e0480, 0x2a)
    /home/travis/.gimme/versions/go1.6.3.linux.amd64/src/runtime/panic.go:547 +0x90
runtime.sigpanic()
    /home/travis/.gimme/versions/go1.6.3.linux.amd64/src/runtime/sigpanic_unix.go:12 +0x5a
runtime.unlock(0x7c5920)
    /home/travis/.gimme/versions/go1.6.3.linux.amd64/src/runtime/lock_sema.go:107 +0x14b
runtime.(*mheap).alloc_m(0x7c5920, 0x1, 0x60000000013, 0x906c68)
    /home/travis/.gimme/versions/go1.6.3.linux.amd64/src/runtime/mheap.go:492 +0x314
runtime.(*mheap).alloc.func1()
    /home/travis/.gimme/versions/go1.6.3.linux.amd64/src/runtime/mheap.go:502 +0x41
runtime.systemstack(0xc8200f1e58)
    /home/travis/.gimme/versions/go1.6.3.linux.amd64/src/runtime/asm_amd64.s:307 +0xab
runtime.(*mheap).alloc(0x7c5920, 0x1, 0x10000000013, 0xe98f)
    /home/travis/.gimme/versions/go1.6.3.linux.amd64/src/runtime/mheap.go:503 +0x63
runtime.(*mcentral).grow(0x7c7440, 0x0)
    /home/travis/.gimme/versions/go1.6.3.linux.amd64/src/runtime/mcentral.go:209 +0x93
runtime.(*mcentral).cacheSpan(0x7c7440, 0x906c68)
    /home/travis/.gimme/versions/go1.6.3.linux.amd64/src/runtime/mcentral.go:89 +0x47d
runtime.(*mcache).refill(0x872960, 0x13, 0x906c68)
    /home/travis/.gimme/versions/go1.6.3.linux.amd64/src/runtime/mcache.go:119 +0xcc
runtime.mallocgc.func2()
    /home/travis/.gimme/versions/go1.6.3.linux.amd64/src/runtime/malloc.go:642 +0x2b
runtime.systemstack(0xc82001b500)
    /home/travis/.gimme/versions/go1.6.3.linux.amd64/src/runtime/asm_amd64.s:291 +0x79
runtime.mstart()
    /home/travis/.gimme/versions/go1.6.3.linux.amd64/src/runtime/proc.go:1051

goroutine 17 [running]:
runtime.systemstack_switch()
    /home/travis/.gimme/versions/go1.6.3.linux.amd64/src/runtime/asm_amd64.s:245 fp=0xc8202e8f30 sp=0xc8202e8f28
runtime.mallocgc(0x140, 0x3dfd60, 0x1, 0xc81ffe0263)
    /home/travis/.gimme/versions/go1.6.3.linux.amd64/src/runtime/malloc.go:643 +0x869 fp=0xc8202e9008 sp=0xc8202e8f30
runtime.newarray(0x3dfd60, 0x25, 0x0)
    /home/travis/.gimme/versions/go1.6.3.linux.amd64/src/runtime/malloc.go:798 +0xc9 fp=0xc8202e9048 sp=0xc8202e9008
runtime.makeslice(0x535880, 0x21, 0x25, 0x0, 0x0, 0x0)
    /home/travis/.gimme/versions/go1.6.3.linux.amd64/src/runtime/slice.go:32 +0x165 fp=0xc8202e9098 sp=0xc8202e9048
math/big.nat.make(0x0, 0x0, 0x0, 0x21, 0x0, 0x0, 0x0)
    /home/travis/.gimme/versions/go1.6.3.linux.amd64/src/math/big/nat.go:54 +0x7d fp=0xc8202e90d0 sp=0xc8202e9098
math/big.nat.setBytes(0x0, 0x0, 0x0, 0xc8203fc18f, 0x101, 0x2a6, 0x0, 0x0, 0x0)
    /home/travis/.gimme/versions/go1.6.3.linux.amd64/src/math/big/nat.go:1263 +0x70 fp=0xc8202e9110 sp=0xc8202e90d0
math/big.(*Int).SetBytes(0xc8203fb380, 0xc8203fc18f, 0x101, 0x2a6, 0x5)
    /home/travis/.gimme/versions/go1.6.3.linux.amd64/src/math/big/int.go:388 +0x69 fp=0xc8202e9178 sp=0xc8202e9110
encoding/asn1.parseBigInt(0xc8203fc18f, 0x101, 0x2a6, 0x538d60, 0x0, 0x0)
    /home/travis/.gimme/versions/go1.6.3.linux.amd64/src/encoding/asn1/asn1.go:148 +0x2a3 fp=0xc8202e9230 sp=0xc8202e9178
encoding/asn1.parseField(0x538d60, 0xc8203f9a10, 0x196, 0xc8203fc18b, 0x10a, 0x2aa, 0x0, 0x0, 0x0, 0x0, ...)
    /home/travis/.gimme/versions/go1.6.3.linux.amd64/src/encoding/asn1/asn1.go:805 +0x1f1c fp=0xc8202e99b8 sp=0xc8202e9230
encoding/asn1.parseField(0x4b18c0, 0xc8203f9a10, 0x199, 0xc8203fc187, 0x10e, 0x2ae, 0x0, 0x0, 0x0, 0x0, ...)
    /home/travis/.gimme/versions/go1.6.3.linux.amd64/src/encoding/asn1/asn1.go:851 +0x31d2 fp=0xc8202ea140 sp=0xc8202e99b8
encoding/asn1.UnmarshalWithParams(0xc8203fc187, 0x10e, 0x2ae, 0x3bc180, 0xc8203f9a10, 0x0, 0x0, 0x0, 0x0, 0x0, ...)
    /home/travis/.gimme/versions/go1.6.3.linux.amd64/src/encoding/asn1/asn1.go:990 +0x16e fp=0xc8202ea228 sp=0xc8202ea140
encoding/asn1.Unmarshal(0xc8203fc187, 0x10e, 0x2ae, 0x3bc180, 0xc8203f9a10, 0x0, 0x0, 0x0, 0x0, 0x0)
    /home/travis/.gimme/versions/go1.6.3.linux.amd64/src/encoding/asn1/asn1.go:983 +0x8f fp=0xc8202ea290 sp=0xc8202ea228
crypto/x509.parsePublicKey(0x1, 0xc8203f6a60, 0x0, 0x0, 0x0, 0x0)
    /home/travis/.gimme/versions/go1.6.3.linux.amd64/src/crypto/x509/x509.go:789 +0x10b fp=0xc8202ea538 sp=0xc8202ea290
crypto/x509.parseCertificate(0xc8203f6900, 0x435, 0x0, 0x0)
    /home/travis/.gimme/versions/go1.6.3.linux.amd64/src/crypto/x509/x509.go:939 +0x306 fp=0xc8202eae78 sp=0xc8202ea538
crypto/x509.ParseCertificate(0xc8203fc000, 0x435, 0x435, 0xb, 0x0, 0x0)
    /home/travis/.gimme/versions/go1.6.3.linux.amd64/src/crypto/x509/x509.go:1195 +0x19e fp=0xc8202eaf20 sp=0xc8202eae78
crypto/x509.(*CertPool).AppendCertsFromPEM(0xc8200f4090, 0xc82026b49e, 0x26ae7, 0x64962, 0xc8200f4001)
    /home/travis/.gimme/versions/go1.6.3.linux.amd64/src/crypto/x509/cert_pool.go:96 +0x11d fp=0xc8202eaf88 sp=0xc8202eaf20
crypto/x509.execSecurityRoots(0xd7ec5, 0x0, 0x0)
    /home/travis/.gimme/versions/go1.6.3.linux.amd64/src/crypto/x509/root_darwin.go:23 +0x23e fp=0xc8202eb060 sp=0xc8202eaf88
crypto/x509.initSystemRoots()
    /home/travis/.gimme/versions/go1.6.3.linux.amd64/src/crypto/x509/root_nocgo_darwin.go:10 +0x18 fp=0xc8202eb080 sp=0xc8202eb060
sync.(*Once).Do(0x7dd748, 0x620768)
    /home/travis/.gimme/versions/go1.6.3.linux.amd64/src/sync/once.go:44 +0xe4 fp=0xc8202eb0a8 sp=0xc8202eb080
crypto/x509.systemRootsPool(0x0)
    /home/travis/.gimme/versions/go1.6.3.linux.amd64/src/crypto/x509/root.go:15 +0x2f fp=0xc8202eb0c0 sp=0xc8202eb0a8
crypto/x509.(*Certificate).Verify(0xc8201a4000, 0xc8201291a0, 0xe, 0xc82017ae40, 0x0, 0xed047c795, 0x14a1f325, 0x7c03e0, 0x0, 0x0, ...)
    /home/travis/.gimme/versions/go1.6.3.linux.amd64/src/crypto/x509/verify.go:241 +0x1de fp=0xc8202eb318 sp=0xc8202eb0c0
crypto/tls.(*clientHandshakeState).doFullHandshake(0xc8202ebe38, 0x0, 0x0)
    /home/travis/.gimme/versions/go1.6.3.linux.amd64/src/crypto/tls/handshake_client.go:278 +0x6e9 fp=0xc8202eb9d0 sp=0xc8202eb318
crypto/tls.(*Conn).clientHandshake(0xc820196000, 0x0, 0x0)
    /home/travis/.gimme/versions/go1.6.3.linux.amd64/src/crypto/tls/handshake_client.go:213 +0x1737 fp=0xc8202ebee8 sp=0xc8202eb9d0
crypto/tls.(*Conn).Handshake(0xc820196000, 0x0, 0x0)
    /home/travis/.gimme/versions/go1.6.3.linux.amd64/src/crypto/tls/conn.go:1033 +0xec fp=0xc8202ebf28 sp=0xc8202ebee8
net/http.(*Transport).dialConn.func3(0xc820196000, 0xc8201840c0, 0xc8201920c0)
    /home/travis/.gimme/versions/go1.6.3.linux.amd64/src/net/http/transport.go:831 +0x21 fp=0xc8202ebf68 sp=0xc8202ebf28
runtime.goexit()
    /home/travis/.gimme/versions/go1.6.3.linux.amd64/src/runtime/asm_amd64.s:1998 +0x1 fp=0xc8202ebf70 sp=0xc8202ebf68
created by net/http.(*Transport).dialConn
    /home/travis/.gimme/versions/go1.6.3.linux.amd64/src/net/http/transport.go:836 +0x986

goroutine 1 [select]:
net/http.(*Transport).getConn(0xc8200ce480, 0xc8200d2700, 0x0, 0xc8200136c0, 0x5, 0xc8201291a0, 0x12, 0x0, 0x0, 0x0)
    /home/travis/.gimme/versions/go1.6.3.linux.amd64/src/net/http/transport.go:714 +0x4ef
net/http.(*Transport).RoundTrip(0xc8200ce480, 0xc8200d2700, 0xc8200618b8, 0x0, 0x0)
    /home/travis/.gimme/versions/go1.6.3.linux.amd64/src/net/http/transport.go:314 +0x7e9
github.com/github/hub/github.(*verboseTransport).RoundTrip(0xc8200fb290, 0xc8200d2700, 0xc8200fb290, 0x0, 0x0)
    /tmp/go/src/github.com/github/hub/github/http.go:50 +0x265
net/http.send(0xc8200d2700, 0x8c6bc8, 0xc8200fb290, 0x0, 0x0, 0x0, 0xc820013700, 0x0, 0x0)
    /home/travis/.gimme/versions/go1.6.3.linux.amd64/src/net/http/client.go:260 +0x6b7
net/http.(*Client).send(0xc8200fb2c0, 0xc8200d2700, 0x0, 0x0, 0x0, 0xc820129100, 0x0, 0x0)
    /home/travis/.gimme/versions/go1.6.3.linux.amd64/src/net/http/client.go:155 +0x185
net/http.(*Client).doFollowingRedirects(0xc8200fb2c0, 0xc8200d2700, 0x620e78, 0x0, 0x0, 0x0)
    /home/travis/.gimme/versions/go1.6.3.linux.amd64/src/net/http/client.go:475 +0x8a4
net/http.(*Client).Do(0xc8200fb2c0, 0xc8200d2700, 0x0, 0x0, 0x0)
    /home/travis/.gimme/versions/go1.6.3.linux.amd64/src/net/http/client.go:188 +0xff
github.com/github/hub/vendor/github.com/octokit/go-octokit/vendor/github.com/jingweno/go-sawyer.(*Request).Do(0xc8201290e0, 0x53ffe8, 0x3, 0x0)
    /tmp/go/src/github.com/github/hub/vendor/github.com/octokit/go-octokit/vendor/github.com/jingweno/go-sawyer/request.go:36 +0xbb
github.com/github/hub/vendor/github.com/octokit/go-octokit/vendor/github.com/jingweno/go-sawyer.(*Request).Get(0xc8201290e0, 0x0)
    /tmp/go/src/github.com/github/hub/vendor/github.com/octokit/go-octokit/vendor/github.com/jingweno/go-sawyer/request.go:58 +0x36
github.com/github/hub/vendor/github.com/octokit/go-octokit/octokit.(*Request).Get(0xc82010eb20, 0x3b5d00, 0xc8200321d0, 0xc82010eb20, 0x0, 0x0)
    /tmp/go/src/github.com/github/hub/vendor/github.com/octokit/go-octokit/octokit/request.go:29 +0x30
github.com/github/hub/vendor/github.com/octokit/go-octokit/octokit.(*Client).get.func1(0xc82010eb20, 0xc820129000, 0x0, 0x0)
    /tmp/go/src/github.com/github/hub/vendor/github.com/octokit/go-octokit/octokit/client.go:62 +0x4c
github.com/github/hub/vendor/github.com/octokit/go-octokit/octokit.sendRequest(0xc8200fb350, 0xc82007c900, 0xc82010d6d0, 0x8)
    /tmp/go/src/github.com/github/hub/vendor/github.com/octokit/go-octokit/octokit/client.go:137 +0xa4
github.com/github/hub/vendor/github.com/octokit/go-octokit/octokit.(*Client).get(0xc8200fb350, 0xc82007c900, 0x3b5d00, 0xc8200321d0, 0xc8200fac30)
    /tmp/go/src/github.com/github/hub/vendor/github.com/octokit/go-octokit/octokit/client.go:63 +0x62
github.com/github/hub/vendor/github.com/octokit/go-octokit/octokit.(*RepositoriesService).One(0xc82010d780, 0x0, 0xc82007c900)
    /tmp/go/src/github.com/github/hub/vendor/github.com/octokit/go-octokit/octokit/repositories.go:29 +0x6b
github.com/github/hub/github.(*Client).Repository(0xc82010d8e8, 0xc820013580, 0x0, 0x0, 0x0)
    /tmp/go/src/github.com/github/hub/github/client.go:191 +0x29c
github.com/github/hub/commands.pullRequest(0x7bc600, 0xc8200ca420)
    /tmp/go/src/github.com/github/hub/commands/pull_request.go:183 +0x554
github.com/github/hub/commands.(*Command).Call(0x7bc600, 0xc8200ca420, 0x0, 0x0)
    /tmp/go/src/github.com/github/hub/commands/commands.go:45 +0x188
github.com/github/hub/commands.(*Runner).Call(0xc820011610, 0x7bc600, 0xc8200ca420, 0x0, 0x0, 0x0, 0x0)
    /tmp/go/src/github.com/github/hub/commands/runner.go:109 +0x5e
github.com/github/hub/commands.(*Runner).Execute(0xc820011610, 0x0, 0x0, 0x0, 0x0)
    /tmp/go/src/github.com/github/hub/commands/runner.go:94 +0x21f
main.main()
    /home/travis/gopath/src/github.com/github/hub/main.go:14 +0x50

goroutine 5 [syscall]:
os/signal.signal_recv(0x0)
    /home/travis/.gimme/versions/go1.6.3.linux.amd64/src/runtime/sigqueue.go:116 +0x132
os/signal.loop()
    /home/travis/.gimme/versions/go1.6.3.linux.amd64/src/os/signal/signal_unix.go:22 +0x18
created by os/signal.init.1
    /home/travis/.gimme/versions/go1.6.3.linux.amd64/src/os/signal/signal_unix.go:28 +0x37

goroutine 11 [chan receive]:
net/http.(*Transport).dialConn(0xc8200ce480, 0x0, 0xc8200136c0, 0x5, 0xc8201291a0, 0x12, 0x0, 0x0, 0x0)
    /home/travis/.gimme/versions/go1.6.3.linux.amd64/src/net/http/transport.go:837 +0x9c2
net/http.(*Transport).getConn.func4(0xc8200ce480, 0x0, 0xc8200136c0, 0x5, 0xc8201291a0, 0x12, 0xc82000b8c0)
    /home/travis/.gimme/versions/go1.6.3.linux.amd64/src/net/http/transport.go:709 +0x66
created by net/http.(*Transport).getConn
    /home/travis/.gimme/versions/go1.6.3.linux.amd64/src/net/http/transport.go:711 +0x262

$ hub --version
git version 2.10.0
hub version 2.3.0-pre9
$ uname -a
Darwin RolfsMacPro.local 16.4.0 Darwin Kernel Version 16.4.0: Thu Dec 22 22:53:21 PST 2016; root:xnu-3789.41.3~3/RELEASE_X86_64 x86_64

Is there any other output I can gather that would help track this down?

[rolfbjarne]

This is another variation:

Error creating pull request: Post https://api.github.com/repos/xamarin/xamarin-macios/pulls: x509: certificate has expired or is not yet valid

[pudge]

bump

This has been a problem for awhile now. Any progress being made ... ?

[mislav]

I personally haven't experienced this. If this is caused by network inconsistencies, I'm guessing there's little we could change in hub to make this work. I'm personally confused as to why the error message looks like a crash rather than being caught by error handlers at runtime.

Could this be a problem with the prebuilt binary that you might have downloaded? Can you try compiling hub yourself for your system and see if the problem goes away, or changes symptoms?

[rolfbjarne]

I've never seen network inconsistencies in any other app on my machine, so I don't think it's a network issue on my machine. My guess would be an invalid memory access in Go, which most of the time doesn't have any negative consequences.

I'm now using 2.3.0-pre9, but this happened in the previous release to (2.3.0-pre8). Before that I wasn't using hub much, so I don't know if the problem is older or not.

[rolfbjarne]

I'll try building hub myself and see what happens.

[mislav]

The master version of hub now requires Go 1.8. Does anyone still experience crashes even when built with a relatively newer version of Go?

[rolfbjarne]

I haven't seen this issue in a while.

[mislav]

Okay, going to close for now and assume newer Go handles this better. Please reopen if there is new evidence

[pudge]

I still have errors with the latest released binary of hub.

[pudge]

Just built from master with pre10 and Go 1.8.3. Will report if problems occur.