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

Geth nodes crashes, memory leak #3002

Closed
Phistr90 opened this Issue Sep 18, 2016 · 28 comments

Comments

Projects
None yet
@Phistr90

Phistr90 commented Sep 18, 2016

System information

Geth version: 1.4.10-stable-5f55d95a
OS & Version: Arch

Expected behaviour

Actual behaviour

Geth nodes crashes after a few minutes.

Steps to reproduce the behaviour

Start geth node, try to sync

Log:

http://pastebin.com/kVjhA2vU

I guess the problem is the VM codehash da002555

@bobfeldbauer

This comment has been minimized.

Show comment
Hide comment
@bobfeldbauer

bobfeldbauer Sep 18, 2016

I can confirm seeing the same issue with geth version 1.4.11-stable-fed692f6 on Debian. The problematic block is block #2283416. Possibly the payload in this transaction: https://etherchain.org/tx/0x5c19695f50a30abbadfeef201d695d9c95c254534019e2f6a7a590e9ef246e82

bobfeldbauer commented Sep 18, 2016

I can confirm seeing the same issue with geth version 1.4.11-stable-fed692f6 on Debian. The problematic block is block #2283416. Possibly the payload in this transaction: https://etherchain.org/tx/0x5c19695f50a30abbadfeef201d695d9c95c254534019e2f6a7a590e9ef246e82

@chrisfranko

This comment has been minimized.

Show comment
Hide comment
@chrisfranko

chrisfranko commented Sep 18, 2016

yikes

@HelixiR

This comment has been minimized.

Show comment
Hide comment
@HelixiR

HelixiR commented Sep 18, 2016

@MicahZoltu

This comment has been minimized.

Show comment
Hide comment
@MicahZoltu

MicahZoltu Sep 18, 2016

Contributor

Be careful what you read on the internet everyone. Not everyone posting comments here is a geth developer. Safest to assume they aren't and they are trying to pump/dump unless you have evidence to the contrary.

Contributor

MicahZoltu commented Sep 18, 2016

Be careful what you read on the internet everyone. Not everyone posting comments here is a geth developer. Safest to assume they aren't and they are trying to pump/dump unless you have evidence to the contrary.

@Gustav-Simonsson

This comment has been minimized.

Show comment
Hide comment
@Gustav-Simonsson

Gustav-Simonsson Sep 18, 2016

Member

Please wait for official security alert to be published at https://blog.ethereum.org/ - until then be careful what people claim.

So far we can confirm a memory leak in go-ethereum master branch (and probably earlier releases). More info soon.

Member

Gustav-Simonsson commented Sep 18, 2016

Please wait for official security alert to be published at https://blog.ethereum.org/ - until then be careful what people claim.

So far we can confirm a memory leak in go-ethereum master branch (and probably earlier releases). More info soon.

@devktor

This comment has been minimized.

Show comment
Hide comment
@devktor

devktor Sep 18, 2016

Here are some GDB crash logs :


Thread 4 "geth" received signal SIGPIPE, Broken pipe.

[Switching to Thread 0x7ffff64e5700 (LWP 6055)]

syscall.Syscall () at /usr/lib/go-1.6/src/syscall/asm_linux_amd64.s:27

27      CMPQ    AX, $0xfffffffffffff001

(gdb) bt

#0  syscall.Syscall () at /usr/lib/go-1.6/src/syscall/asm_linux_amd64.s:27

#1  0x000000000063812f in syscall.write (fd=492, p=..., n=119, err=...) at /usr/lib/go-1.6/src/syscall/zsyscall_linux_amd64.go:1064

#2  0x000000000063649d in syscall.Write (fd=492, p=..., n=32, err=...) at /usr/lib/go-1.6/src/syscall/syscall_unix.go:180

#3  0x00000000009f51a7 in net.(*netFD).Write (fd=0xc82d318ee0, p=..., nn=0, err=...) at /usr/lib/go-1.6/src/net/fd_unix.go:328

#4  0x0000000000a09284 in net.(*conn).Write (c=0xc82d7f8048, b=..., ~r1=0, ~r2=...) at /usr/lib/go-1.6/src/net/net.go:184

#5  0x00000000008fd1b3 in github.com/ethereum/go-ethereum/p2p.(*rlpxFrameRW).WriteMsg (rw=0xc8267ec900, msg=..., ~r1=...)
    at /opt/go-ethereum/build/_workspace/src/github.com/ethereum/go-ethereum/p2p/rlpx.go:598

#6  0x00000000008f667a in github.com/ethereum/go-ethereum/p2p.(*rlpx).WriteMsg (t=0xc82c9d0e70, msg=..., ~r1=...)
    at /opt/go-ethereum/build/_workspace/src/github.com/ethereum/go-ethereum/p2p/rlpx.go:96

#7  0x000000000090878b in github.com/ethereum/go-ethereum/p2p.(*conn).WriteMsg (this=0xc82abaa500, anon0=..., ~r1=...) at <autogenerated>:14

#8  0x00000000008f14e1 in github.com/ethereum/go-ethereum/p2p.Send (w=..., msgcode=2, data=..., ~r3=...)
    at /opt/go-ethereum/build/_workspace/src/github.com/ethereum/go-ethereum/p2p/message.go:97

#9  0x00000000008f15b7 in github.com/ethereum/go-ethereum/p2p.SendItems (w=..., msgcode=2, elems=..., ~r3=...)
    at /opt/go-ethereum/build/_workspace/src/github.com/ethereum/go-ethereum/p2p/message.go:110

#10 0x00000000008f2e9f in github.com/ethereum/go-ethereum/p2p.(*Peer).pingLoop (p=0xc82eb1bac0)
    at /opt/go-ethereum/build/_workspace/src/github.com/ethereum/go-ethereum/p2p/peer.go:201

#11 0x0000000000479491 in runtime.goexit () at /usr/lib/go-1.6/src/runtime/asm_amd64.s:1998

#12 0x000000c82eb1bac0 in ?? ()

#13 0x0000000000000000 in ?? ()

devktor commented Sep 18, 2016

Here are some GDB crash logs :


Thread 4 "geth" received signal SIGPIPE, Broken pipe.

[Switching to Thread 0x7ffff64e5700 (LWP 6055)]

syscall.Syscall () at /usr/lib/go-1.6/src/syscall/asm_linux_amd64.s:27

27      CMPQ    AX, $0xfffffffffffff001

(gdb) bt

#0  syscall.Syscall () at /usr/lib/go-1.6/src/syscall/asm_linux_amd64.s:27

#1  0x000000000063812f in syscall.write (fd=492, p=..., n=119, err=...) at /usr/lib/go-1.6/src/syscall/zsyscall_linux_amd64.go:1064

#2  0x000000000063649d in syscall.Write (fd=492, p=..., n=32, err=...) at /usr/lib/go-1.6/src/syscall/syscall_unix.go:180

#3  0x00000000009f51a7 in net.(*netFD).Write (fd=0xc82d318ee0, p=..., nn=0, err=...) at /usr/lib/go-1.6/src/net/fd_unix.go:328

#4  0x0000000000a09284 in net.(*conn).Write (c=0xc82d7f8048, b=..., ~r1=0, ~r2=...) at /usr/lib/go-1.6/src/net/net.go:184

#5  0x00000000008fd1b3 in github.com/ethereum/go-ethereum/p2p.(*rlpxFrameRW).WriteMsg (rw=0xc8267ec900, msg=..., ~r1=...)
    at /opt/go-ethereum/build/_workspace/src/github.com/ethereum/go-ethereum/p2p/rlpx.go:598

#6  0x00000000008f667a in github.com/ethereum/go-ethereum/p2p.(*rlpx).WriteMsg (t=0xc82c9d0e70, msg=..., ~r1=...)
    at /opt/go-ethereum/build/_workspace/src/github.com/ethereum/go-ethereum/p2p/rlpx.go:96

#7  0x000000000090878b in github.com/ethereum/go-ethereum/p2p.(*conn).WriteMsg (this=0xc82abaa500, anon0=..., ~r1=...) at <autogenerated>:14

#8  0x00000000008f14e1 in github.com/ethereum/go-ethereum/p2p.Send (w=..., msgcode=2, data=..., ~r3=...)
    at /opt/go-ethereum/build/_workspace/src/github.com/ethereum/go-ethereum/p2p/message.go:97

#9  0x00000000008f15b7 in github.com/ethereum/go-ethereum/p2p.SendItems (w=..., msgcode=2, elems=..., ~r3=...)
    at /opt/go-ethereum/build/_workspace/src/github.com/ethereum/go-ethereum/p2p/message.go:110

#10 0x00000000008f2e9f in github.com/ethereum/go-ethereum/p2p.(*Peer).pingLoop (p=0xc82eb1bac0)
    at /opt/go-ethereum/build/_workspace/src/github.com/ethereum/go-ethereum/p2p/peer.go:201

#11 0x0000000000479491 in runtime.goexit () at /usr/lib/go-1.6/src/runtime/asm_amd64.s:1998

#12 0x000000c82eb1bac0 in ?? ()

#13 0x0000000000000000 in ?? ()
@Atrides

This comment has been minimized.

Show comment
Hide comment
@Atrides

Atrides Sep 18, 2016

I confirm the problem with geth 1.4.11

Atrides commented Sep 18, 2016

I confirm the problem with geth 1.4.11

@bobfeldbauer

This comment has been minimized.

Show comment
Hide comment
@bobfeldbauer

bobfeldbauer Sep 18, 2016

Seems to be the same on develop branch HEAD too.

bobfeldbauer commented Sep 18, 2016

Seems to be the same on develop branch HEAD too.

@colm

This comment has been minimized.

Show comment
Hide comment
@colm

colm Sep 18, 2016

@devktor It seems to be an invalid msg at message.go:110 which fails to send at peer.go:201. Could you log the msg that fails and share?

EDIT : Im wrong here. Plz ignore. Its at pingMsg in pingLoop that causes the crash. This just keeps the peers connected. There is not data from any TX sent here. I have an intuation the bug is in the code that tries to seperate ETC and ETH networks.

@devktor can you give us max verbosity logs?

colm commented Sep 18, 2016

@devktor It seems to be an invalid msg at message.go:110 which fails to send at peer.go:201. Could you log the msg that fails and share?

EDIT : Im wrong here. Plz ignore. Its at pingMsg in pingLoop that causes the crash. This just keeps the peers connected. There is not data from any TX sent here. I have an intuation the bug is in the code that tries to seperate ETC and ETH networks.

@devktor can you give us max verbosity logs?

@sandakersmann

This comment has been minimized.

Show comment
Hide comment
@sandakersmann

sandakersmann Sep 18, 2016

Contributor

I have an intuation the bug is in the code that tries to seperate ETC and ETH networks.

I think you are on to something here.

Contributor

sandakersmann commented Sep 18, 2016

I have an intuation the bug is in the code that tries to seperate ETC and ETH networks.

I think you are on to something here.

@colm

This comment has been minimized.

Show comment
Hide comment
@colm

colm Sep 18, 2016

@sandakersmann we can confirm this by seeing if geth 1.4.9 cashes as it was before the HF and does not have this. Do you ahve a synced chain to test this?

colm commented Sep 18, 2016

@sandakersmann we can confirm this by seeing if geth 1.4.9 cashes as it was before the HF and does not have this. Do you ahve a synced chain to test this?

@trapp

This comment has been minimized.

Show comment
Hide comment
@trapp

trapp Sep 18, 2016

@colm, 1.4.9 would not sync the ETH chain. It would sync the ETC chain where the transaction in question does not exist.

trapp commented Sep 18, 2016

@colm, 1.4.9 would not sync the ETH chain. It would sync the ETC chain where the transaction in question does not exist.

@colm

This comment has been minimized.

Show comment
Hide comment
@colm

colm Sep 18, 2016

@trapp haha yeah my mistake.

colm commented Sep 18, 2016

@trapp haha yeah my mistake.

@devktor

This comment has been minimized.

Show comment
Hide comment
@devktor

devktor Sep 18, 2016

here are full logs with GDB:

#0  syscall.Syscall () at /usr/lib/go-1.6/src/syscall/asm_linux_amd64.s:27
No locals.
#1  0x000000000063812f in syscall.write (fd=800, p=..., n=119, err=...) at /usr/lib/go-1.6/src/syscall/zsyscall_linux_amd64.go:1064
No locals.
#2  0x000000000063649d in syscall.Write (fd=800, p=..., n=32, err=...) at /usr/lib/go-1.6/src/syscall/syscall_unix.go:180
No locals.
#3  0x00000000009f51a7 in net.(*netFD).Write (fd=0xc8354c5f10, p=..., nn=0, err=...) at /usr/lib/go-1.6/src/net/fd_unix.go:328
        n = 859774696608
        ~r0 = {tab = 0x0, data = 0x20}
        syscall·2 = 0xc82e90bca0 ""
        err·3 = {tab = 0x20, data = 0xc822830a80}
        err = {tab = 0x0, data = 0x0}
        err = {tab = 0x0, data = 0x0}
#4  0x0000000000a09284 in net.(*conn).Write (c=0xc836e83398, b=..., ~r1=0, ~r2=...) at /usr/lib/go-1.6/src/net/net.go:184
        n = 32
        err = {tab = 0x10, data = 0x10}
#5  0x00000000008fd1b3 in github.com/ethereum/go-ethereum/p2p.(*rlpxFrameRW).WriteMsg (rw=0xc838543800, msg=..., ~r1=...)
    at /opt/go-ethereum/build/_workspace/src/github.com/ethereum/go-ethereum/p2p/rlpx.go:598
        fsize = 3
        ~r0 = {tab = 0xc82194fa48, data = 0xeb2da0}
        text·2 = 0x7ffff7f480a8 "\340\267\373\000\000\000\000\000\000\323\376", '\000' <repeats 21 times>, "@L^\000\000\000\000\000\060\212^\000\000\000\000\000\340J^\000\000\000\000\000\340T^\000\000\000\000\000\060\214^\000\000\000\000\000@\213^\000\000\000\000\000 V^\000\000\000\000\000\240Y^\000\000\000\000\000PL^\000\000\000\000\000\240Z^\000\000\000\000\000\300[^\000\000\000\000\000\340\\^\000\000\000\000\000\340\210^\000\000\000\000\000\360]^\000\000\000\000\000\200U^\000\000\000\000\000P_^\000\000\000\000\000`L^\000\000\000\000\000p`^\000\000\000\000\000\020Q^\000\000\000\000\000\060S^\000\000\000\000\000\220T^\000\000\000\000\000"...
        err = {tab = 0x0, data = 0x0}
        err = {tab = 0x0, data = 0x4}
        err = {tab = 0x8, data = 0x0}
        err = {tab = 0x0, data = 0x9}
        ptype = {array = 0xc83478cd98 "\001", len = 1, cap = 1}
        mac = {array = 0xc800000000 <error: Cannot access memory at address 0xc800000000>, len = 4364455, cap = 860003851584}
        headbuf = {
          array = 0xc82e90bc20 "q\371`\336\347 e\247^\360s\b\323\300\237\001qf\017)\267q\027Pݍj\030\as\337\001h})\f\360\237{\260\350\\\240\361'\226\062\064۴\017MD\215\307T\235\304^T\313\034\202\316h})\f\360\237{\260\350\\\240\361'\226\062\064۴\017MD\215\307T\235\304^T\313\034\202\316qf\017)\267q\027Pݍj\030\as\337\001<H\360\030\\kr2\321\332l\033z'\331jqf\017)\267q\027Pݍj\030\as\337\001<H\360\030\\kr2\321\332l\033z'\331j\204\202#", <incomplete sequence \310>, len = 32, cap = 32}
        fmacseed = {array = 0x0, len = 0, cap = 860003851584}
        b = {
          array = 0xc82e90bc20 "q\371`\336\347 e\247^\360s\b\323\300\237\001qf\017)\267q\027Pݍj\030\as\337\001h})\f\360\237{\260\350\\\240\361'\226\062\064۴\017MD\215\307T\235\304^T\313\034\202\316h})\f\360\237{\260\350\\\240\361'\226\062\064۴\017MD\215\307T\235\304^T\313\034\202\316qf\017)\267q\027Pݍj\030\as\337\001<H\360\030\\kr2\321\332l\033z'\331jqf\017)\267q\027Pݍj\030\as\337\001<H\360\030\\kr2\321\332l\033z'\331j\204\202#", <incomplete sequence \310>, len = 32, cap = 32}
        tee = {S = {tab = 0xf1ac20, data = 0xc83c395d40}, W = {tab = 0xc82e90bc00, data = 0x0}, Err = {tab = 0x0, data = 0x2}}
#6  0x00000000008f14e1 in github.com/ethereum/go-ethereum/p2p.Send (w=..., msgcode=1, data=..., ~r3=...)
    at /opt/go-ethereum/build/_workspace/src/github.com/ethereum/go-ethereum/p2p/message.go:97
        r = {tab = 0x7ffff7e038e8, data = 0xc83c395d40}
        err = {tab = 0x0, data = 0x0}
#7  0x00000000008f15b7 in github.com/ethereum/go-ethereum/p2p.SendItems (w=..., msgcode=1, elems=..., ~r3=...)
    at /opt/go-ethereum/build/_workspace/src/github.com/ethereum/go-ethereum/p2p/message.go:110
No locals.
#8  0x00000000008f69fb in github.com/ethereum/go-ethereum/p2p.(*rlpx).close (t=0xc82fcbe930, err=...)
    at /opt/go-ethereum/build/_workspace/src/github.com/ethereum/go-ethereum/p2p/rlpx.go:106
        r = 4
        ~r0 = {sec = 63609829155, nsec = 375050915, loc = 0x1a08fe0 <time.localLoc>}
        t·2 = {sec = 63609829155, nsec = 375050915, loc = 0x1a08fe0 <time.localLoc>}
#9  0x0000000000903e3e in github.com/ethereum/go-ethereum/p2p.(*Server).setupConn (srv=0xc820059680, fd=..., flags=4, dialDest=0x0)
    at /opt/go-ethereum/build/_workspace/src/github.com/ethereum/go-ethereum/p2p/server.go:636
        running = true
        phs = 0xc836cab5c0
        c = 0xc834dc4a00
        err = {tab = 0x7ffff4469d98, data = 0xc83478cd60}
        err = {tab = 0x7ffff7e038e8, data = 0xc836cab5c0}
        err = {tab = 0x0, data = 0x0}
#10 0x00000000009072e7 in github.com/ethereum/go-ethereum/p2p.(*Server).listenLoop.func1 (srv=0xc820059680, fd=..., slots=0xc82147cfc0)
    at /opt/go-ethereum/build/_workspace/src/github.com/ethereum/go-ethereum/p2p/server.go:595
No locals.
#11 0x0000000000479491 in runtime.goexit () at /usr/lib/go-1.6/src/runtime/asm_amd64.s:1998
No locals.
---Type <return> to continue, or q <return> to quit---
#12 0x000000c820059680 in ?? ()
No symbol table info available.
#13 0x00007ffff4469188 in ?? ()
No symbol table info available.
#14 0x000000c836e83398 in ?? ()
No symbol table info available.
#15 0x000000c82147cfc0 in ?? ()
No symbol table info available.
#16 0x0000000000000062 in ?? ()
No symbol table info available.
#17 0x0000000000000000 in ?? ()
No symbol table info available.

devktor commented Sep 18, 2016

here are full logs with GDB:

#0  syscall.Syscall () at /usr/lib/go-1.6/src/syscall/asm_linux_amd64.s:27
No locals.
#1  0x000000000063812f in syscall.write (fd=800, p=..., n=119, err=...) at /usr/lib/go-1.6/src/syscall/zsyscall_linux_amd64.go:1064
No locals.
#2  0x000000000063649d in syscall.Write (fd=800, p=..., n=32, err=...) at /usr/lib/go-1.6/src/syscall/syscall_unix.go:180
No locals.
#3  0x00000000009f51a7 in net.(*netFD).Write (fd=0xc8354c5f10, p=..., nn=0, err=...) at /usr/lib/go-1.6/src/net/fd_unix.go:328
        n = 859774696608
        ~r0 = {tab = 0x0, data = 0x20}
        syscall·2 = 0xc82e90bca0 ""
        err·3 = {tab = 0x20, data = 0xc822830a80}
        err = {tab = 0x0, data = 0x0}
        err = {tab = 0x0, data = 0x0}
#4  0x0000000000a09284 in net.(*conn).Write (c=0xc836e83398, b=..., ~r1=0, ~r2=...) at /usr/lib/go-1.6/src/net/net.go:184
        n = 32
        err = {tab = 0x10, data = 0x10}
#5  0x00000000008fd1b3 in github.com/ethereum/go-ethereum/p2p.(*rlpxFrameRW).WriteMsg (rw=0xc838543800, msg=..., ~r1=...)
    at /opt/go-ethereum/build/_workspace/src/github.com/ethereum/go-ethereum/p2p/rlpx.go:598
        fsize = 3
        ~r0 = {tab = 0xc82194fa48, data = 0xeb2da0}
        text·2 = 0x7ffff7f480a8 "\340\267\373\000\000\000\000\000\000\323\376", '\000' <repeats 21 times>, "@L^\000\000\000\000\000\060\212^\000\000\000\000\000\340J^\000\000\000\000\000\340T^\000\000\000\000\000\060\214^\000\000\000\000\000@\213^\000\000\000\000\000 V^\000\000\000\000\000\240Y^\000\000\000\000\000PL^\000\000\000\000\000\240Z^\000\000\000\000\000\300[^\000\000\000\000\000\340\\^\000\000\000\000\000\340\210^\000\000\000\000\000\360]^\000\000\000\000\000\200U^\000\000\000\000\000P_^\000\000\000\000\000`L^\000\000\000\000\000p`^\000\000\000\000\000\020Q^\000\000\000\000\000\060S^\000\000\000\000\000\220T^\000\000\000\000\000"...
        err = {tab = 0x0, data = 0x0}
        err = {tab = 0x0, data = 0x4}
        err = {tab = 0x8, data = 0x0}
        err = {tab = 0x0, data = 0x9}
        ptype = {array = 0xc83478cd98 "\001", len = 1, cap = 1}
        mac = {array = 0xc800000000 <error: Cannot access memory at address 0xc800000000>, len = 4364455, cap = 860003851584}
        headbuf = {
          array = 0xc82e90bc20 "q\371`\336\347 e\247^\360s\b\323\300\237\001qf\017)\267q\027Pݍj\030\as\337\001h})\f\360\237{\260\350\\\240\361'\226\062\064۴\017MD\215\307T\235\304^T\313\034\202\316h})\f\360\237{\260\350\\\240\361'\226\062\064۴\017MD\215\307T\235\304^T\313\034\202\316qf\017)\267q\027Pݍj\030\as\337\001<H\360\030\\kr2\321\332l\033z'\331jqf\017)\267q\027Pݍj\030\as\337\001<H\360\030\\kr2\321\332l\033z'\331j\204\202#", <incomplete sequence \310>, len = 32, cap = 32}
        fmacseed = {array = 0x0, len = 0, cap = 860003851584}
        b = {
          array = 0xc82e90bc20 "q\371`\336\347 e\247^\360s\b\323\300\237\001qf\017)\267q\027Pݍj\030\as\337\001h})\f\360\237{\260\350\\\240\361'\226\062\064۴\017MD\215\307T\235\304^T\313\034\202\316h})\f\360\237{\260\350\\\240\361'\226\062\064۴\017MD\215\307T\235\304^T\313\034\202\316qf\017)\267q\027Pݍj\030\as\337\001<H\360\030\\kr2\321\332l\033z'\331jqf\017)\267q\027Pݍj\030\as\337\001<H\360\030\\kr2\321\332l\033z'\331j\204\202#", <incomplete sequence \310>, len = 32, cap = 32}
        tee = {S = {tab = 0xf1ac20, data = 0xc83c395d40}, W = {tab = 0xc82e90bc00, data = 0x0}, Err = {tab = 0x0, data = 0x2}}
#6  0x00000000008f14e1 in github.com/ethereum/go-ethereum/p2p.Send (w=..., msgcode=1, data=..., ~r3=...)
    at /opt/go-ethereum/build/_workspace/src/github.com/ethereum/go-ethereum/p2p/message.go:97
        r = {tab = 0x7ffff7e038e8, data = 0xc83c395d40}
        err = {tab = 0x0, data = 0x0}
#7  0x00000000008f15b7 in github.com/ethereum/go-ethereum/p2p.SendItems (w=..., msgcode=1, elems=..., ~r3=...)
    at /opt/go-ethereum/build/_workspace/src/github.com/ethereum/go-ethereum/p2p/message.go:110
No locals.
#8  0x00000000008f69fb in github.com/ethereum/go-ethereum/p2p.(*rlpx).close (t=0xc82fcbe930, err=...)
    at /opt/go-ethereum/build/_workspace/src/github.com/ethereum/go-ethereum/p2p/rlpx.go:106
        r = 4
        ~r0 = {sec = 63609829155, nsec = 375050915, loc = 0x1a08fe0 <time.localLoc>}
        t·2 = {sec = 63609829155, nsec = 375050915, loc = 0x1a08fe0 <time.localLoc>}
#9  0x0000000000903e3e in github.com/ethereum/go-ethereum/p2p.(*Server).setupConn (srv=0xc820059680, fd=..., flags=4, dialDest=0x0)
    at /opt/go-ethereum/build/_workspace/src/github.com/ethereum/go-ethereum/p2p/server.go:636
        running = true
        phs = 0xc836cab5c0
        c = 0xc834dc4a00
        err = {tab = 0x7ffff4469d98, data = 0xc83478cd60}
        err = {tab = 0x7ffff7e038e8, data = 0xc836cab5c0}
        err = {tab = 0x0, data = 0x0}
#10 0x00000000009072e7 in github.com/ethereum/go-ethereum/p2p.(*Server).listenLoop.func1 (srv=0xc820059680, fd=..., slots=0xc82147cfc0)
    at /opt/go-ethereum/build/_workspace/src/github.com/ethereum/go-ethereum/p2p/server.go:595
No locals.
#11 0x0000000000479491 in runtime.goexit () at /usr/lib/go-1.6/src/runtime/asm_amd64.s:1998
No locals.
---Type <return> to continue, or q <return> to quit---
#12 0x000000c820059680 in ?? ()
No symbol table info available.
#13 0x00007ffff4469188 in ?? ()
No symbol table info available.
#14 0x000000c836e83398 in ?? ()
No symbol table info available.
#15 0x000000c82147cfc0 in ?? ()
No symbol table info available.
#16 0x0000000000000062 in ?? ()
No symbol table info available.
#17 0x0000000000000000 in ?? ()
No symbol table info available.

@colm

This comment has been minimized.

Show comment
Hide comment
@colm

colm Sep 18, 2016

@devktor Do you have a lot of running byte VM da002555 in your logs? A few others have this which suggests the bug is in the EVM.

colm commented Sep 18, 2016

@devktor Do you have a lot of running byte VM da002555 in your logs? A few others have this which suggests the bug is in the EVM.

@devktor

This comment has been minimized.

Show comment
Hide comment
@devktor

devktor Sep 18, 2016

@colm yes, I have bunch of them.

devktor commented Sep 18, 2016

@colm yes, I have bunch of them.

@devktor

This comment has been minimized.

Show comment
Hide comment
@devktor

devktor Sep 18, 2016

@colm here are some geth logs right before crash:

I0918 23:43:13.555177 eth/downloader/downloader.go:258] Registering peer c5df2a08731a7ab8
I0918 23:43:13.555504 eth/peer.go:261] Peer c5df2a08731a7ab8 [eth/63] fetching 1 headers from #1920000, skipping 0 (reverse = false)
I0918 23:43:13.621269 eth/downloader/downloader.go:284] Attempting synchronisation: ea4f678cc9c81721, head [5a558bd2…], TD 62397707944161850896
I0918 23:43:13.621308 eth/downloader/downloader.go:292] Synchronisation already in progress
I0918 23:43:13.745288 eth/handler.go:531] Peer c5df2a08731a7ab8 [eth/63]: verified to be on the other side of the DAO fork, dropping
I0918 23:43:13.745307 eth/handler.go:302] Peer c5df2a08731a7ab8 [eth/63]: message handling failed: DAO pro-fork bad block extra-data: 0xe4b883e5bda9e7a59ee4bb99e9b1bc
I0918 23:43:13.745321 eth/handler.go:200] Removing peer c5df2a08731a7ab8
I0918 23:43:13.745330 eth/downloader/downloader.go:272] Unregistering peer c5df2a08731a7ab8
I0918 23:43:13.745345 p2p/peer.go:308] Peer c5df2a08731a7ab8 74.193.82.57:39005: Protocol eth/63 error: DAO pro-fork bad block extra-data: 0xe4b883e5bda9e7a59ee4bb99e9b1bc
I0918 23:43:13.745369 p2p/peer.go:180] Peer c5df2a08731a7ab8 74.193.82.57:39005: locally requested disconnect: Useless peer
I0918 23:43:13.745468 p2p/server.go:690] Removed Peer c5df2a08731a7ab8 74.193.82.57:39005 (Useless peer)
I0918 23:43:13.745492 p2p/server.go:501] <-delpeer: Peer c5df2a08731a7ab8 74.193.82.57:39005
I0918 23:43:14.423584 eth/handler.go:295] Peer 4915707cfc0779b9 [eth/62]: timed out DAO fork-check, dropping
I0918 23:43:14.539331 p2p/discover/udp.go:453] >>> 176.9.61.40:30303 discover.pong
I0918 23:43:14.539419 p2p/discover/udp.go:521] <<< 176.9.61.40:30303 *discover.ping: ok
I0918 23:43:14.539528 p2p/discover/table.go:473] Bonding 75557b83220ecac6: known=true, fails=4 age=121h37m1.539523956s
I0918 23:43:14.539730 p2p/discover/udp.go:453] >>> 176.9.61.40:30303 discover.ping
I0918 23:43:14.572761 p2p/discover/udp.go:521] <<< 176.9.61.40:30303 *discover.pong: ok
I0918 23:43:14.573085 p2p/discover/udp.go:453] >>> 104.167.103.231:30303 discover.ping
I0918 23:43:14.809448 p2p/discover/udp.go:521] <<< 104.167.103.231:30303 *discover.pong: ok
I0918 23:43:15.128638 p2p/dial.go:266] dial tcp 84.226.168.104:30303: i/o timeout
I0918 23:43:15.128672 p2p/server.go:469] <-taskdone: dyn dial 2b018a733b0161bf 84.226.168.104:30303
I0918 23:43:15.128712 p2p/server.go:430] new task: dyn dial bd524245c024d480 52.210.99.87:30303
I0918 23:43:15.128747 p2p/dial.go:263] dial tcp 52.210.99.87:30303 (bd524245c024)
I0918 23:43:15.241964 p2p/server.go:479] <-posthandshake: dyn dial conn bd524245c024d480 52.210.99.87:30303
I0918 23:43:15.242121 p2p/server.go:485] <-addpeer: dyn dial conn bd524245c024d480 52.210.99.87:30303
I0918 23:43:15.242148 p2p/server.go:469] <-taskdone: dyn dial bd524245c024d480 52.210.99.87:30303
I0918 23:43:15.242175 p2p/server.go:674] Added Peer bd524245c024d480 52.210.99.87:30303
I0918 23:43:15.242244 p2p/peer.go:301] Peer bd524245c024d480 52.210.99.87:30303: Starting protocol eth/63
I0918 23:43:15.242293 eth/handler.go:258] Peer bd524245c024d480 [eth/63]: peer connected [Parity/v1.4.0-unstable-59f18ab-20160903/x86_64-linux-gnu/rustc1.11.0]
I0918 23:43:15.242375 eth/downloader/downloader.go:284] Attempting synchronisation: ea4f678cc9c81721, head [5a558bd2…], TD 62397707944161850896
I0918 23:43:15.242405 eth/downloader/downloader.go:292] Synchronisation already in progress
I0918 23:43:15.410989 p2p/server.go:590] Accepted conn 83.81.125.74:47498
I0918 23:43:15.413455 p2p/server.go:479] <-posthandshake: inbound conn 5108e144422a0615 83.81.125.74:47498
I0918 23:43:15.445159 eth/handler.go:270] Peer bd524245c024d480 [eth/63]: adding peer
I0918 23:43:15.445205 eth/downloader/downloader.go:258] Registering peer bd524245c024d480
I0918 23:43:15.445409 eth/peer.go:261] Peer bd524245c024d480 [eth/63] fetching 1 headers from #1920000, skipping 0 (reverse = false)
I0918 23:43:15.457394 p2p/server.go:485] <-addpeer: inbound conn 5108e144422a0615 83.81.125.74:47498
I0918 23:43:15.457470 p2p/server.go:674] Added Peer 5108e144422a0615 83.81.125.74:47498
I0918 23:43:15.457540 p2p/peer.go:301] Peer 5108e144422a0615 83.81.125.74:47498: Starting protocol eth/63
I0918 23:43:15.457589 eth/handler.go:258] Peer 5108e144422a0615 [eth/63]: peer connected [Parity/v1.4.0-unstable-f8f39c4-20160916/x86_64-linux-gnu/rustc1.11.0]
I0918 23:43:15.457664 eth/downloader/downloader.go:284] Attempting synchronisation: ea4f678cc9c81721, head [5a558bd2…], TD 62397707944161850896
I0918 23:43:15.457691 eth/downloader/downloader.go:292] Synchronisation already in progress
I0918 23:43:15.502671 eth/handler.go:263] Peer 5108e144422a0615 [eth/63]: handshake failed: Protocol version mismatch - 64 (!= 63)
I0918 23:43:15.502694 p2p/peer.go:308] Peer 5108e144422a0615 83.81.125.74:47498: Protocol eth/63 error: Protocol version mismatch - 64 (!= 63)
I0918 23:43:15.502715 p2p/peer.go:177] Peer 5108e144422a0615 83.81.125.74:47498: protocol error: Protocol version mismatch - 64 (!= 63) (Subprotocol error)
I0918 23:43:15.502849 p2p/server.go:690] Removed Peer 5108e144422a0615 83.81.125.74:47498 (Subprotocol error)
I0918 23:43:15.502875 p2p/server.go:501] <-delpeer: Peer 5108e144422a0615 83.81.125.74:47498
I0918 23:43:15.512614 p2p/discover/udp.go:453] >>> 176.9.61.40:30303 discover.neighbors
I0918 23:43:15.512896 p2p/discover/udp.go:453] >>> 176.9.61.40:30303 discover.neighbors
I0918 23:43:15.512917 p2p/discover/udp.go:521] <<< 176.9.61.40:30303 *discover.findnode: ok
I0918 23:43:16.118131 p2p/server.go:590] Accepted conn 18.111.86.24:50954
I0918 23:43:16.120754 p2p/server.go:479] <-posthandshake: inbound conn 4cac3b3c8b6ae089 18.111.86.24:50954
I0918 23:43:16.250254 p2p/server.go:635] inbound conn 4cac3b3c8b6ae089 18.111.86.24:50954 failed proto handshake: read tcp 192.168.0.103:30303->18.111.86.24:50954: read: connection reset by peer
I0918 23:43:17.871205 p2p/dial.go:266] dial tcp 104.131.3.131:30303: i/o timeout
I0918 23:43:17.871249 p2p/server.go:469] <-taskdone: dyn dial e4fb2ea83db2434a 104.131.3.131:30303
I0918 23:43:17.871292 p2p/server.go:430] new task: dyn dial 27171dd06c679b24 139.59.29.80:30303
I0918 23:43:17.871329 p2p/dial.go:263] dial tcp 139.59.29.80:30303 (27171dd06c67)
I0918 23:43:18.032376 p2p/dial.go:266] dial tcp 95.54.70.84:30303: i/o timeout
I0918 23:43:18.032407 p2p/server.go:469] <-taskdone: dyn dial 21887534e19156ce 95.54.70.84:30303
I0918 23:43:18.032442 p2p/server.go:430] new task: dyn dial 93b1bb96effc8541 52.28.247.236:30303
I0918 23:43:18.032482 p2p/dial.go:263] dial tcp 52.28.247.236:30303 (93b1bb96effc)
I0918 23:43:18.113890 p2p/server.go:479] <-posthandshake: dyn dial conn 93b1bb96effc8541 52.28.247.236:30303
I0918 23:43:18.114592 p2p/server.go:485] <-addpeer: dyn dial conn 93b1bb96effc8541 52.28.247.236:30303
I0918 23:43:18.114648 p2p/server.go:469] <-taskdone: dyn dial 93b1bb96effc8541 52.28.247.236:30303
I0918 23:43:18.114649 p2p/server.go:674] Added Peer 93b1bb96effc8541 52.28.247.236:30303
I0918 23:43:18.114745 p2p/peer.go:301] Peer 93b1bb96effc8541 52.28.247.236:30303: Starting protocol eth/63
I0918 23:43:18.114785 eth/handler.go:258] Peer 93b1bb96effc8541 [eth/63]: peer connected [Parity/v1.3.0-beta/x86_64-linux-gnu/rustc1.10.0]
I0918 23:43:18.114854 eth/downloader/downloader.go:284] Attempting synchronisation: ea4f678cc9c81721, head [5a558bd2…], TD 62397707944161850896
I0918 23:43:18.114882 eth/downloader/downloader.go:292] Synchronisation already in progress
I0918 23:43:18.157286 eth/handler.go:270] Peer 93b1bb96effc8541 [eth/63]: adding peer
I0918 23:43:18.157334 eth/downloader/downloader.go:258] Registering peer 93b1bb96effc8541
I0918 23:43:18.157604 eth/peer.go:261] Peer 93b1bb96effc8541 [eth/63] fetching 1 headers from #1920000, skipping 0 (reverse = false)
I0918 23:43:18.198232 eth/handler.go:534] Peer 93b1bb96effc8541 [eth/63]: verified to be on the same side of the DAO fork
I0918 23:43:18.198255 eth/fetcher/fetcher.go:258] [eth/62] filtering 1 headers
I0918 23:43:18.235398 eth/handler.go:534] Peer bd524245c024d480 [eth/63]: verified to be on the same side of the DAO fork
I0918 23:43:18.235420 eth/fetcher/fetcher.go:258] [eth/62] filtering 1 headers
I0918 23:43:18.302138 p2p/server.go:479] <-posthandshake: dyn dial conn 27171dd06c679b24 139.59.29.80:30303
I0918 23:43:18.302681 eth/fetcher/fetcher.go:368] [eth/62] Peer f2e3cdbe8c866435: discarded announcement #2284000 [753eb180…], distance 585
I0918 23:43:18.304759 p2p/server.go:485] <-addpeer: dyn dial conn 27171dd06c679b24 139.59.29.80:30303
I0918 23:43:18.304838 p2p/server.go:469] <-taskdone: dyn dial 27171dd06c679b24 139.59.29.80:30303
I0918 23:43:18.304871 p2p/server.go:674] Added Peer 27171dd06c679b24 139.59.29.80:30303
I0918 23:43:18.304940 p2p/peer.go:301] Peer 27171dd06c679b24 139.59.29.80:30303: Starting protocol eth/63
I0918 23:43:18.304976 eth/handler.go:258] Peer 27171dd06c679b24 [eth/63]: peer connected [Parity/v1.3.1-beta-2a82fa0-20160911/x86_64-linux-gnu/rustc1.11.0]
I0918 23:43:18.305040 eth/downloader/downloader.go:284] Attempting synchronisation: ea4f678cc9c81721, head [5a558bd2…], TD 62397707944161850896
I0918 23:43:18.305061 eth/downloader/downloader.go:292] Synchronisation already in progress
I0918 23:43:18.506008 eth/handler.go:270] Peer 27171dd06c679b24 [eth/63]: adding peer
I0918 23:43:18.506034 eth/downloader/downloader.go:258] Registering peer 27171dd06c679b24
I0918 23:43:18.506210 eth/peer.go:261] Peer 27171dd06c679b24 [eth/63] fetching 1 headers from #1920000, skipping 0 (reverse = false)
I0918 23:43:18.746462 eth/fetcher/fetcher.go:368] [eth/62] Peer d897b67c2f6151c1: discarded announcement #2284000 [753eb180…], distance 585
I0918 23:43:18.750795 eth/handler.go:534] Peer 27171dd06c679b24 [eth/63]: verified to be on the same side of the DAO fork
I0918 23:43:18.750815 eth/fetcher/fetcher.go:258] [eth/62] filtering 1 headers
I0918 23:43:19.341873 p2p/server.go:590] Accepted conn 74.193.82.57:39138
I0918 23:43:19.345010 p2p/server.go:479] <-posthandshake: inbound conn c5df2a08731a7ab8 74.193.82.57:39138
I0918 23:43:19.542086 p2p/server.go:485] <-addpeer: inbound conn c5df2a08731a7ab8 74.193.82.57:39138
I0918 23:43:19.542155 p2p/server.go:674] Added Peer c5df2a08731a7ab8 74.193.82.57:39138
I0918 23:43:19.542246 p2p/peer.go:301] Peer c5df2a08731a7ab8 74.193.82.57:39138: Starting protocol eth/63
I0918 23:43:19.542284 eth/handler.go:258] Peer c5df2a08731a7ab8 [eth/63]: peer connected [Parity/v1.3.0-beta/x86_64-linux-gnu/rustc1.10.0]
I0918 23:43:19.542335 eth/downloader/downloader.go:284] Attempting synchronisation: ea4f678cc9c81721, head [5a558bd2…], TD 62397707944161850896
I0918 23:43:19.542371 eth/downloader/downloader.go:292] Synchronisation already in progress

Thread 7 "geth" received signal SIGPIPE, Broken pipe.

here are GDB logs:

Thread 7 "geth" received signal SIGPIPE, Broken pipe.
[Switching to Thread 0x7fffeffff700 (LWP 4623)]
syscall.Syscall () at /usr/lib/go-1.6/src/syscall/asm_linux_amd64.s:27
27      CMPQ    AX, $0xfffffffffffff001
(gdb) bt full
#0  syscall.Syscall () at /usr/lib/go-1.6/src/syscall/asm_linux_amd64.s:27
No locals.
#1  0x000000000063812f in syscall.write (fd=910, p=..., n=119, err=...) at /usr/lib/go-1.6/src/syscall/zsyscall_linux_amd64.go:1064
No locals.
#2  0x000000000063649d in syscall.Write (fd=910, p=..., n=32, err=...) at /usr/lib/go-1.6/src/syscall/syscall_unix.go:180
No locals.
#3  0x00000000009f51a7 in net.(*netFD).Write (fd=0xc8269aa540, p=..., nn=0, err=...) at /usr/lib/go-1.6/src/net/fd_unix.go:328
        n = 859718394112
        ~r0 = {tab = 0x0, data = 0x20}
        syscall·2 = 0xc82b35a100 ""
        err·3 = {tab = 0x20, data = 0xc82dd561c0}
        err = {tab = 0x0, data = 0x0}
        err = {tab = 0x0, data = 0x0}
#4  0x0000000000a09284 in net.(*conn).Write (c=0xc8263103f8, b=..., ~r1=0, ~r2=...) at /usr/lib/go-1.6/src/net/net.go:184
        n = 32
        err = {tab = 0x10, data = 0x10}
#5  0x00000000008fd1b3 in github.com/ethereum/go-ethereum/p2p.(*rlpxFrameRW).WriteMsg (rw=0xc82694a780, msg=..., ~r1=...)
    at /opt/go-ethereum/build/_workspace/src/github.com/ethereum/go-ethereum/p2p/rlpx.go:598
        fsize = 2
        ~r0 = {tab = 0x0, data = 0x7fff00000001}
        text·2 = 0x16 <error: Cannot access memory at address 0x16>
        err = {tab = 0x1666d682c9, data = 0x4281e2 <runtime.notewakeup+194>}
        err = {tab = 0x7ffff7e03140, data = 0xc800000001}
        err = {tab = 0x0, data = 0x80}
        err = {tab = 0x464399 <runtime.addtimerLocked+137>, data = 0x5a}
        ptype = {array = 0xc82af80070 "\002", len = 1, cap = 1}
        mac = {array = 0x442701 <net.runtime_pollSetDeadline+449> "\017\204 \001", len = 140737352052944, cap = 0}
        headbuf = {array = 0xc82b35a080 "\026y\377QA\033\071\247iT@\325&Lo0\374\022҇\341\341FD\r\241K9\273g\214\234|\273T\277\341\353g\331fi\361xK\266\236%\017", 
          len = 32, cap = 32}
        fmacseed = {array = 0xc8269aa540 "\f", len = 140737352052736, cap = 10430701}
        b = {array = 0xc82b35a080 "\026y\377QA\033\071\247iT@\325&Lo0\374\022҇\341\341FD\r\241K9\273g\214\234|\273T\277\341\353g\331fi\361xK\266\236%\017", len = 32, 
          cap = 32}
        tee = {S = {tab = 0xa09d43 <net.(*conn).SetWriteDeadline+211>, data = 0xc8269aa540}, W = {tab = 0xecf71018b, data = 0x1a308573}, Err = {
            tab = 0x1a08fe0 <time.localLoc>, data = 0x0}}
#6  0x00000000008f667a in github.com/ethereum/go-ethereum/p2p.(*rlpx).WriteMsg (t=0xc822303f80, msg=..., ~r1=...)
    at /opt/go-ethereum/build/_workspace/src/github.com/ethereum/go-ethereum/p2p/rlpx.go:96
        ~r0 = {sec = 63609831819, nsec = 439387507, loc = 0x1a08fe0 <time.localLoc>}
        t·2 = {sec = 63609831819, nsec = 439387507, loc = 0x1a08fe0 <time.localLoc>}
#7  0x000000000090878b in github.com/ethereum/go-ethereum/p2p.(*conn).WriteMsg (this=0xc822b97220, anon0=..., ~r1=...) at <autogenerated>:14
No locals.
#8  0x00000000008f14e1 in github.com/ethereum/go-ethereum/p2p.Send (w=..., msgcode=2, data=..., ~r3=...)
    at /opt/go-ethereum/build/_workspace/src/github.com/ethereum/go-ethereum/p2p/message.go:97
        r = {tab = 0x7ffff7f48cc8, data = 0xc83183e120}
        err = {tab = 0x0, data = 0x0}
#9  0x00000000008f15b7 in github.com/ethereum/go-ethereum/p2p.SendItems (w=..., msgcode=2, elems=..., ~r3=...)
    at /opt/go-ethereum/build/_workspace/src/github.com/ethereum/go-ethereum/p2p/message.go:110
No locals.
#10 0x00000000008f2e9f in github.com/ethereum/go-ethereum/p2p.(*Peer).pingLoop (p=0xc8267a7540)
    at /opt/go-ethereum/build/_workspace/src/github.com/ethereum/go-ethereum/p2p/peer.go:201
        ping = 0xc8267a7780
        err = {tab = 0x0, data = 0x0}
#11 0x0000000000479491 in runtime.goexit () at /usr/lib/go-1.6/src/runtime/asm_amd64.s:1998
No locals.
#12 0x000000c8267a7540 in ?? ()
No symbol table info available.
#13 0x0000000000000000 in ?? ()
No symbol table info available.

devktor commented Sep 18, 2016

@colm here are some geth logs right before crash:

I0918 23:43:13.555177 eth/downloader/downloader.go:258] Registering peer c5df2a08731a7ab8
I0918 23:43:13.555504 eth/peer.go:261] Peer c5df2a08731a7ab8 [eth/63] fetching 1 headers from #1920000, skipping 0 (reverse = false)
I0918 23:43:13.621269 eth/downloader/downloader.go:284] Attempting synchronisation: ea4f678cc9c81721, head [5a558bd2…], TD 62397707944161850896
I0918 23:43:13.621308 eth/downloader/downloader.go:292] Synchronisation already in progress
I0918 23:43:13.745288 eth/handler.go:531] Peer c5df2a08731a7ab8 [eth/63]: verified to be on the other side of the DAO fork, dropping
I0918 23:43:13.745307 eth/handler.go:302] Peer c5df2a08731a7ab8 [eth/63]: message handling failed: DAO pro-fork bad block extra-data: 0xe4b883e5bda9e7a59ee4bb99e9b1bc
I0918 23:43:13.745321 eth/handler.go:200] Removing peer c5df2a08731a7ab8
I0918 23:43:13.745330 eth/downloader/downloader.go:272] Unregistering peer c5df2a08731a7ab8
I0918 23:43:13.745345 p2p/peer.go:308] Peer c5df2a08731a7ab8 74.193.82.57:39005: Protocol eth/63 error: DAO pro-fork bad block extra-data: 0xe4b883e5bda9e7a59ee4bb99e9b1bc
I0918 23:43:13.745369 p2p/peer.go:180] Peer c5df2a08731a7ab8 74.193.82.57:39005: locally requested disconnect: Useless peer
I0918 23:43:13.745468 p2p/server.go:690] Removed Peer c5df2a08731a7ab8 74.193.82.57:39005 (Useless peer)
I0918 23:43:13.745492 p2p/server.go:501] <-delpeer: Peer c5df2a08731a7ab8 74.193.82.57:39005
I0918 23:43:14.423584 eth/handler.go:295] Peer 4915707cfc0779b9 [eth/62]: timed out DAO fork-check, dropping
I0918 23:43:14.539331 p2p/discover/udp.go:453] >>> 176.9.61.40:30303 discover.pong
I0918 23:43:14.539419 p2p/discover/udp.go:521] <<< 176.9.61.40:30303 *discover.ping: ok
I0918 23:43:14.539528 p2p/discover/table.go:473] Bonding 75557b83220ecac6: known=true, fails=4 age=121h37m1.539523956s
I0918 23:43:14.539730 p2p/discover/udp.go:453] >>> 176.9.61.40:30303 discover.ping
I0918 23:43:14.572761 p2p/discover/udp.go:521] <<< 176.9.61.40:30303 *discover.pong: ok
I0918 23:43:14.573085 p2p/discover/udp.go:453] >>> 104.167.103.231:30303 discover.ping
I0918 23:43:14.809448 p2p/discover/udp.go:521] <<< 104.167.103.231:30303 *discover.pong: ok
I0918 23:43:15.128638 p2p/dial.go:266] dial tcp 84.226.168.104:30303: i/o timeout
I0918 23:43:15.128672 p2p/server.go:469] <-taskdone: dyn dial 2b018a733b0161bf 84.226.168.104:30303
I0918 23:43:15.128712 p2p/server.go:430] new task: dyn dial bd524245c024d480 52.210.99.87:30303
I0918 23:43:15.128747 p2p/dial.go:263] dial tcp 52.210.99.87:30303 (bd524245c024)
I0918 23:43:15.241964 p2p/server.go:479] <-posthandshake: dyn dial conn bd524245c024d480 52.210.99.87:30303
I0918 23:43:15.242121 p2p/server.go:485] <-addpeer: dyn dial conn bd524245c024d480 52.210.99.87:30303
I0918 23:43:15.242148 p2p/server.go:469] <-taskdone: dyn dial bd524245c024d480 52.210.99.87:30303
I0918 23:43:15.242175 p2p/server.go:674] Added Peer bd524245c024d480 52.210.99.87:30303
I0918 23:43:15.242244 p2p/peer.go:301] Peer bd524245c024d480 52.210.99.87:30303: Starting protocol eth/63
I0918 23:43:15.242293 eth/handler.go:258] Peer bd524245c024d480 [eth/63]: peer connected [Parity/v1.4.0-unstable-59f18ab-20160903/x86_64-linux-gnu/rustc1.11.0]
I0918 23:43:15.242375 eth/downloader/downloader.go:284] Attempting synchronisation: ea4f678cc9c81721, head [5a558bd2…], TD 62397707944161850896
I0918 23:43:15.242405 eth/downloader/downloader.go:292] Synchronisation already in progress
I0918 23:43:15.410989 p2p/server.go:590] Accepted conn 83.81.125.74:47498
I0918 23:43:15.413455 p2p/server.go:479] <-posthandshake: inbound conn 5108e144422a0615 83.81.125.74:47498
I0918 23:43:15.445159 eth/handler.go:270] Peer bd524245c024d480 [eth/63]: adding peer
I0918 23:43:15.445205 eth/downloader/downloader.go:258] Registering peer bd524245c024d480
I0918 23:43:15.445409 eth/peer.go:261] Peer bd524245c024d480 [eth/63] fetching 1 headers from #1920000, skipping 0 (reverse = false)
I0918 23:43:15.457394 p2p/server.go:485] <-addpeer: inbound conn 5108e144422a0615 83.81.125.74:47498
I0918 23:43:15.457470 p2p/server.go:674] Added Peer 5108e144422a0615 83.81.125.74:47498
I0918 23:43:15.457540 p2p/peer.go:301] Peer 5108e144422a0615 83.81.125.74:47498: Starting protocol eth/63
I0918 23:43:15.457589 eth/handler.go:258] Peer 5108e144422a0615 [eth/63]: peer connected [Parity/v1.4.0-unstable-f8f39c4-20160916/x86_64-linux-gnu/rustc1.11.0]
I0918 23:43:15.457664 eth/downloader/downloader.go:284] Attempting synchronisation: ea4f678cc9c81721, head [5a558bd2…], TD 62397707944161850896
I0918 23:43:15.457691 eth/downloader/downloader.go:292] Synchronisation already in progress
I0918 23:43:15.502671 eth/handler.go:263] Peer 5108e144422a0615 [eth/63]: handshake failed: Protocol version mismatch - 64 (!= 63)
I0918 23:43:15.502694 p2p/peer.go:308] Peer 5108e144422a0615 83.81.125.74:47498: Protocol eth/63 error: Protocol version mismatch - 64 (!= 63)
I0918 23:43:15.502715 p2p/peer.go:177] Peer 5108e144422a0615 83.81.125.74:47498: protocol error: Protocol version mismatch - 64 (!= 63) (Subprotocol error)
I0918 23:43:15.502849 p2p/server.go:690] Removed Peer 5108e144422a0615 83.81.125.74:47498 (Subprotocol error)
I0918 23:43:15.502875 p2p/server.go:501] <-delpeer: Peer 5108e144422a0615 83.81.125.74:47498
I0918 23:43:15.512614 p2p/discover/udp.go:453] >>> 176.9.61.40:30303 discover.neighbors
I0918 23:43:15.512896 p2p/discover/udp.go:453] >>> 176.9.61.40:30303 discover.neighbors
I0918 23:43:15.512917 p2p/discover/udp.go:521] <<< 176.9.61.40:30303 *discover.findnode: ok
I0918 23:43:16.118131 p2p/server.go:590] Accepted conn 18.111.86.24:50954
I0918 23:43:16.120754 p2p/server.go:479] <-posthandshake: inbound conn 4cac3b3c8b6ae089 18.111.86.24:50954
I0918 23:43:16.250254 p2p/server.go:635] inbound conn 4cac3b3c8b6ae089 18.111.86.24:50954 failed proto handshake: read tcp 192.168.0.103:30303->18.111.86.24:50954: read: connection reset by peer
I0918 23:43:17.871205 p2p/dial.go:266] dial tcp 104.131.3.131:30303: i/o timeout
I0918 23:43:17.871249 p2p/server.go:469] <-taskdone: dyn dial e4fb2ea83db2434a 104.131.3.131:30303
I0918 23:43:17.871292 p2p/server.go:430] new task: dyn dial 27171dd06c679b24 139.59.29.80:30303
I0918 23:43:17.871329 p2p/dial.go:263] dial tcp 139.59.29.80:30303 (27171dd06c67)
I0918 23:43:18.032376 p2p/dial.go:266] dial tcp 95.54.70.84:30303: i/o timeout
I0918 23:43:18.032407 p2p/server.go:469] <-taskdone: dyn dial 21887534e19156ce 95.54.70.84:30303
I0918 23:43:18.032442 p2p/server.go:430] new task: dyn dial 93b1bb96effc8541 52.28.247.236:30303
I0918 23:43:18.032482 p2p/dial.go:263] dial tcp 52.28.247.236:30303 (93b1bb96effc)
I0918 23:43:18.113890 p2p/server.go:479] <-posthandshake: dyn dial conn 93b1bb96effc8541 52.28.247.236:30303
I0918 23:43:18.114592 p2p/server.go:485] <-addpeer: dyn dial conn 93b1bb96effc8541 52.28.247.236:30303
I0918 23:43:18.114648 p2p/server.go:469] <-taskdone: dyn dial 93b1bb96effc8541 52.28.247.236:30303
I0918 23:43:18.114649 p2p/server.go:674] Added Peer 93b1bb96effc8541 52.28.247.236:30303
I0918 23:43:18.114745 p2p/peer.go:301] Peer 93b1bb96effc8541 52.28.247.236:30303: Starting protocol eth/63
I0918 23:43:18.114785 eth/handler.go:258] Peer 93b1bb96effc8541 [eth/63]: peer connected [Parity/v1.3.0-beta/x86_64-linux-gnu/rustc1.10.0]
I0918 23:43:18.114854 eth/downloader/downloader.go:284] Attempting synchronisation: ea4f678cc9c81721, head [5a558bd2…], TD 62397707944161850896
I0918 23:43:18.114882 eth/downloader/downloader.go:292] Synchronisation already in progress
I0918 23:43:18.157286 eth/handler.go:270] Peer 93b1bb96effc8541 [eth/63]: adding peer
I0918 23:43:18.157334 eth/downloader/downloader.go:258] Registering peer 93b1bb96effc8541
I0918 23:43:18.157604 eth/peer.go:261] Peer 93b1bb96effc8541 [eth/63] fetching 1 headers from #1920000, skipping 0 (reverse = false)
I0918 23:43:18.198232 eth/handler.go:534] Peer 93b1bb96effc8541 [eth/63]: verified to be on the same side of the DAO fork
I0918 23:43:18.198255 eth/fetcher/fetcher.go:258] [eth/62] filtering 1 headers
I0918 23:43:18.235398 eth/handler.go:534] Peer bd524245c024d480 [eth/63]: verified to be on the same side of the DAO fork
I0918 23:43:18.235420 eth/fetcher/fetcher.go:258] [eth/62] filtering 1 headers
I0918 23:43:18.302138 p2p/server.go:479] <-posthandshake: dyn dial conn 27171dd06c679b24 139.59.29.80:30303
I0918 23:43:18.302681 eth/fetcher/fetcher.go:368] [eth/62] Peer f2e3cdbe8c866435: discarded announcement #2284000 [753eb180…], distance 585
I0918 23:43:18.304759 p2p/server.go:485] <-addpeer: dyn dial conn 27171dd06c679b24 139.59.29.80:30303
I0918 23:43:18.304838 p2p/server.go:469] <-taskdone: dyn dial 27171dd06c679b24 139.59.29.80:30303
I0918 23:43:18.304871 p2p/server.go:674] Added Peer 27171dd06c679b24 139.59.29.80:30303
I0918 23:43:18.304940 p2p/peer.go:301] Peer 27171dd06c679b24 139.59.29.80:30303: Starting protocol eth/63
I0918 23:43:18.304976 eth/handler.go:258] Peer 27171dd06c679b24 [eth/63]: peer connected [Parity/v1.3.1-beta-2a82fa0-20160911/x86_64-linux-gnu/rustc1.11.0]
I0918 23:43:18.305040 eth/downloader/downloader.go:284] Attempting synchronisation: ea4f678cc9c81721, head [5a558bd2…], TD 62397707944161850896
I0918 23:43:18.305061 eth/downloader/downloader.go:292] Synchronisation already in progress
I0918 23:43:18.506008 eth/handler.go:270] Peer 27171dd06c679b24 [eth/63]: adding peer
I0918 23:43:18.506034 eth/downloader/downloader.go:258] Registering peer 27171dd06c679b24
I0918 23:43:18.506210 eth/peer.go:261] Peer 27171dd06c679b24 [eth/63] fetching 1 headers from #1920000, skipping 0 (reverse = false)
I0918 23:43:18.746462 eth/fetcher/fetcher.go:368] [eth/62] Peer d897b67c2f6151c1: discarded announcement #2284000 [753eb180…], distance 585
I0918 23:43:18.750795 eth/handler.go:534] Peer 27171dd06c679b24 [eth/63]: verified to be on the same side of the DAO fork
I0918 23:43:18.750815 eth/fetcher/fetcher.go:258] [eth/62] filtering 1 headers
I0918 23:43:19.341873 p2p/server.go:590] Accepted conn 74.193.82.57:39138
I0918 23:43:19.345010 p2p/server.go:479] <-posthandshake: inbound conn c5df2a08731a7ab8 74.193.82.57:39138
I0918 23:43:19.542086 p2p/server.go:485] <-addpeer: inbound conn c5df2a08731a7ab8 74.193.82.57:39138
I0918 23:43:19.542155 p2p/server.go:674] Added Peer c5df2a08731a7ab8 74.193.82.57:39138
I0918 23:43:19.542246 p2p/peer.go:301] Peer c5df2a08731a7ab8 74.193.82.57:39138: Starting protocol eth/63
I0918 23:43:19.542284 eth/handler.go:258] Peer c5df2a08731a7ab8 [eth/63]: peer connected [Parity/v1.3.0-beta/x86_64-linux-gnu/rustc1.10.0]
I0918 23:43:19.542335 eth/downloader/downloader.go:284] Attempting synchronisation: ea4f678cc9c81721, head [5a558bd2…], TD 62397707944161850896
I0918 23:43:19.542371 eth/downloader/downloader.go:292] Synchronisation already in progress

Thread 7 "geth" received signal SIGPIPE, Broken pipe.

here are GDB logs:

Thread 7 "geth" received signal SIGPIPE, Broken pipe.
[Switching to Thread 0x7fffeffff700 (LWP 4623)]
syscall.Syscall () at /usr/lib/go-1.6/src/syscall/asm_linux_amd64.s:27
27      CMPQ    AX, $0xfffffffffffff001
(gdb) bt full
#0  syscall.Syscall () at /usr/lib/go-1.6/src/syscall/asm_linux_amd64.s:27
No locals.
#1  0x000000000063812f in syscall.write (fd=910, p=..., n=119, err=...) at /usr/lib/go-1.6/src/syscall/zsyscall_linux_amd64.go:1064
No locals.
#2  0x000000000063649d in syscall.Write (fd=910, p=..., n=32, err=...) at /usr/lib/go-1.6/src/syscall/syscall_unix.go:180
No locals.
#3  0x00000000009f51a7 in net.(*netFD).Write (fd=0xc8269aa540, p=..., nn=0, err=...) at /usr/lib/go-1.6/src/net/fd_unix.go:328
        n = 859718394112
        ~r0 = {tab = 0x0, data = 0x20}
        syscall·2 = 0xc82b35a100 ""
        err·3 = {tab = 0x20, data = 0xc82dd561c0}
        err = {tab = 0x0, data = 0x0}
        err = {tab = 0x0, data = 0x0}
#4  0x0000000000a09284 in net.(*conn).Write (c=0xc8263103f8, b=..., ~r1=0, ~r2=...) at /usr/lib/go-1.6/src/net/net.go:184
        n = 32
        err = {tab = 0x10, data = 0x10}
#5  0x00000000008fd1b3 in github.com/ethereum/go-ethereum/p2p.(*rlpxFrameRW).WriteMsg (rw=0xc82694a780, msg=..., ~r1=...)
    at /opt/go-ethereum/build/_workspace/src/github.com/ethereum/go-ethereum/p2p/rlpx.go:598
        fsize = 2
        ~r0 = {tab = 0x0, data = 0x7fff00000001}
        text·2 = 0x16 <error: Cannot access memory at address 0x16>
        err = {tab = 0x1666d682c9, data = 0x4281e2 <runtime.notewakeup+194>}
        err = {tab = 0x7ffff7e03140, data = 0xc800000001}
        err = {tab = 0x0, data = 0x80}
        err = {tab = 0x464399 <runtime.addtimerLocked+137>, data = 0x5a}
        ptype = {array = 0xc82af80070 "\002", len = 1, cap = 1}
        mac = {array = 0x442701 <net.runtime_pollSetDeadline+449> "\017\204 \001", len = 140737352052944, cap = 0}
        headbuf = {array = 0xc82b35a080 "\026y\377QA\033\071\247iT@\325&Lo0\374\022҇\341\341FD\r\241K9\273g\214\234|\273T\277\341\353g\331fi\361xK\266\236%\017", 
          len = 32, cap = 32}
        fmacseed = {array = 0xc8269aa540 "\f", len = 140737352052736, cap = 10430701}
        b = {array = 0xc82b35a080 "\026y\377QA\033\071\247iT@\325&Lo0\374\022҇\341\341FD\r\241K9\273g\214\234|\273T\277\341\353g\331fi\361xK\266\236%\017", len = 32, 
          cap = 32}
        tee = {S = {tab = 0xa09d43 <net.(*conn).SetWriteDeadline+211>, data = 0xc8269aa540}, W = {tab = 0xecf71018b, data = 0x1a308573}, Err = {
            tab = 0x1a08fe0 <time.localLoc>, data = 0x0}}
#6  0x00000000008f667a in github.com/ethereum/go-ethereum/p2p.(*rlpx).WriteMsg (t=0xc822303f80, msg=..., ~r1=...)
    at /opt/go-ethereum/build/_workspace/src/github.com/ethereum/go-ethereum/p2p/rlpx.go:96
        ~r0 = {sec = 63609831819, nsec = 439387507, loc = 0x1a08fe0 <time.localLoc>}
        t·2 = {sec = 63609831819, nsec = 439387507, loc = 0x1a08fe0 <time.localLoc>}
#7  0x000000000090878b in github.com/ethereum/go-ethereum/p2p.(*conn).WriteMsg (this=0xc822b97220, anon0=..., ~r1=...) at <autogenerated>:14
No locals.
#8  0x00000000008f14e1 in github.com/ethereum/go-ethereum/p2p.Send (w=..., msgcode=2, data=..., ~r3=...)
    at /opt/go-ethereum/build/_workspace/src/github.com/ethereum/go-ethereum/p2p/message.go:97
        r = {tab = 0x7ffff7f48cc8, data = 0xc83183e120}
        err = {tab = 0x0, data = 0x0}
#9  0x00000000008f15b7 in github.com/ethereum/go-ethereum/p2p.SendItems (w=..., msgcode=2, elems=..., ~r3=...)
    at /opt/go-ethereum/build/_workspace/src/github.com/ethereum/go-ethereum/p2p/message.go:110
No locals.
#10 0x00000000008f2e9f in github.com/ethereum/go-ethereum/p2p.(*Peer).pingLoop (p=0xc8267a7540)
    at /opt/go-ethereum/build/_workspace/src/github.com/ethereum/go-ethereum/p2p/peer.go:201
        ping = 0xc8267a7780
        err = {tab = 0x0, data = 0x0}
#11 0x0000000000479491 in runtime.goexit () at /usr/lib/go-1.6/src/runtime/asm_amd64.s:1998
No locals.
#12 0x000000c8267a7540 in ?? ()
No symbol table info available.
#13 0x0000000000000000 in ?? ()
No symbol table info available.

@gstarnberger

This comment has been minimized.

Show comment
Hide comment
@gstarnberger

gstarnberger Sep 18, 2016

Not sure if related, but the block that triggers this issue has another transaction with an unusually high gas limit and gas usage: https://etherchain.org/tx/0x7bf56f8f9b98e51fd7d1c76818f6c0607e9738f191afae87edd3a34595803455 which calls the contract at 0xd6a64D7E8C8A94fa5068ca33229D88436A743B14 (without passing any data).

gstarnberger commented Sep 18, 2016

Not sure if related, but the block that triggers this issue has another transaction with an unusually high gas limit and gas usage: https://etherchain.org/tx/0x7bf56f8f9b98e51fd7d1c76818f6c0607e9738f191afae87edd3a34595803455 which calls the contract at 0xd6a64D7E8C8A94fa5068ca33229D88436A743B14 (without passing any data).

@fjl

This comment has been minimized.

Show comment
Hide comment
@fjl

fjl Sep 18, 2016

Contributor

We have identified the issue, working on a fix.

Contributor

fjl commented Sep 18, 2016

We have identified the issue, working on a fix.

@promag

This comment has been minimized.

Show comment
Hide comment
@promag

promag Sep 18, 2016

@fjl care to elaborate?

promag commented Sep 18, 2016

@fjl care to elaborate?

@ChuckSRQ

This comment has been minimized.

Show comment
Hide comment
@ChuckSRQ

ChuckSRQ Sep 18, 2016

Does it have to do with the HF code @fjl ?

ChuckSRQ commented Sep 18, 2016

Does it have to do with the HF code @fjl ?

@pdaian

This comment has been minimized.

Show comment
Hide comment
@pdaian

pdaian Sep 18, 2016

@ChuckSRQ no, the attack is not network level (speaking only as someone completely unofficial who's overheard some discussions, read a bit of code, and independently decompiled some contracts; take it with a grain of salt).

If it had to do with the hard fork code you'd also expect all implementations to be equally vulnerable. Geth only and memory overflow points to a flaw in memory management in Go.

pdaian commented Sep 18, 2016

@ChuckSRQ no, the attack is not network level (speaking only as someone completely unofficial who's overheard some discussions, read a bit of code, and independently decompiled some contracts; take it with a grain of salt).

If it had to do with the hard fork code you'd also expect all implementations to be equally vulnerable. Geth only and memory overflow points to a flaw in memory management in Go.

@ChuckSRQ

This comment has been minimized.

Show comment
Hide comment
@ChuckSRQ

ChuckSRQ Sep 19, 2016

@pdaian Right. Only Geth seems to be affected. I guess what I'm really asking is does it affect Geth in ETC as well? Is it possible that it has only to do with the code added on to Geth for the DAO Fork?

ChuckSRQ commented Sep 19, 2016

@pdaian Right. Only Geth seems to be affected. I guess what I'm really asking is does it affect Geth in ETC as well? Is it possible that it has only to do with the code added on to Geth for the DAO Fork?

@pdaian

This comment has been minimized.

Show comment
Hide comment
@pdaian

pdaian Sep 19, 2016

@ChuckSRQ Geth in ETC is definitely affected if my understanding is correct. Whether or not anyone is actively running the attack (aka whether the attack has replay protection or not), I have no idea. ETC developers watch this space ;).

pdaian commented Sep 19, 2016

@ChuckSRQ Geth in ETC is definitely affected if my understanding is correct. Whether or not anyone is actively running the attack (aka whether the attack has replay protection or not), I have no idea. ETC developers watch this space ;).

@ChuckSRQ

This comment has been minimized.

Show comment
Hide comment
@ChuckSRQ

ChuckSRQ Sep 19, 2016

This looks like the fix here.
#3006

ChuckSRQ commented Sep 19, 2016

This looks like the fix here.
#3006

@karalabe

This comment has been minimized.

Show comment
Hide comment
@karalabe

karalabe Sep 19, 2016

Member

Fixed and released as Geth 1.4.12. Thank you everyone for your support in tracing this issue.

Member

karalabe commented Sep 19, 2016

Fixed and released as Geth 1.4.12. Thank you everyone for your support in tracing this issue.

@karalabe karalabe closed this Sep 19, 2016

@Serjster

This comment has been minimized.

Show comment
Hide comment
@Serjster

Serjster Sep 19, 2016

This may be fixed, but dropping this in the Mist resource folder causes Mist to crash:
untitled-2

Serjster commented Sep 19, 2016

This may be fixed, but dropping this in the Mist resource folder causes Mist to crash:
untitled-2

@paradise

This comment has been minimized.

Show comment
Hide comment
@paradise

paradise Sep 19, 2016

how can I upgrade ethereum on Ubuntu ? apt-get shows that there is no upate

paradise commented Sep 19, 2016

how can I upgrade ethereum on Ubuntu ? apt-get shows that there is no upate

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment