ethereum / go-ethereum

Go implementation of the Ethereum protocol
https://geth.ethereum.org
GNU Lesser General Public License v3.0
47.39k stars 20.05k forks source link

geth miner crash / panic: runtime error: invalid memory address or nil pointer dereference #1757

Closed jorisbontje closed 9 years ago

jorisbontje commented 9 years ago

Using geth (1.1.1) together with embark blockchain (embark 0.9.0):

running: geth --datadir="/tmp/embark" --logfile="/tmp/embark.log" --port 30304 --rpc --rpcport 8101 --rpcaddr localhost --networkid 52790 --rpccorsdomain "*" --minerthreads "1" --mine --genesis="config/genesis/dev_genesis.json" --rpcapi "eth,web3" --maxpeers 4 --password config/password --unlock d7b1faef27f5b9d6e11baa934f896ee9914bc20b js /tmp/js/mine.js
I0902 10:23:55.690176    8054 database.go:73] Alloted 16MB cache to /tmp/embark/chaindata
I0902 10:23:55.698103    8054 database.go:73] Alloted 16MB cache to /tmp/embark/dapp
I0902 10:23:55.699727    8054 backend.go:291] Protocol Versions: [61 60], Network Id: 52790
I0902 10:23:55.700271    8054 genesis.go:88] Genesis block already in chain. Writing canonical number
I0902 10:23:55.700346    8054 backend.go:303] Successfully wrote genesis block. New genesis hash = 2027e0692e34ff94ba67bb729833dac34e94fbb12127af1c0373a11fe9d21ddc
I0902 10:23:55.700443    8054 backend.go:328] Blockchain DB Version: 3
I0902 10:23:55.700628    8054 chain_manager.go:237] Last block (#26) 8e8df22f3594182dcc3b68458ccf29ae3057b9d073fe15b5f891b0cb31b3efe8 TD=3428683
I0902 10:23:55.705090    8054 cmd.go:125] Starting Geth/v1.1.1/darwin/go1.5
I0902 10:23:55.705174    8054 server.go:311] Starting Server
I0902 10:23:57.807873    8054 udp.go:207] Listening, enode://9b21f19bf005a8d21d0063a065ad298f2570a3aae13ef3bf7e71d039f09e4288abc222b8b8fb70bddf223c3153e5a2b6befa5edf2d69954457fa72ba86e492d3@[::]:30304
I0902 10:23:57.808065    8054 backend.go:557] Server started
I0902 10:23:57.808083    8054 backend.go:640] Automatic pregeneration of ethash DAG ON (ethash dir: /Users/mids/.ethash)
I0902 10:23:57.808081    8054 server.go:552] Listening on [::]:30304
I0902 10:23:57.808164    8054 backend.go:647] checking DAG (ethash dir: /Users/mids/.ethash)
Account 'd7b1faef27f5b9d6e11baa934f896ee9914bc20b' unlocked.
I0902 10:23:58.847304    8054 ipc_unix.go:104] IPC service started (/tmp/embark/geth.ipc)
I0902 10:23:58.848305    8054 miner.go:119] Starting mining operation (CPU=1 TOT=3)
I0902 10:23:58.848798    8054 worker.go:540] commit new work on block 27 with 0 txs & 0 uncles. Took 464.334µs
I0902 10:23:58.848859    8054 ethash.go:202] Generating DAG for epoch 0 (0000000000000000000000000000000000000000000000000000000000000000)
I0902 10:23:59.707966    8054 ethash.go:219] Done generating DAG for epoch 0, it took 859.103845ms
I0902 10:24:09.191373    8054 xeth.go:987] Tx(0xc165d728978da59e49488e1a165c0840f5aa267936c8b708604fcef37df73f99) to: 0xd5e55598c5b64f3a1e255d68063b8efc98a4316b
I0902 10:24:09.270110    8054 xeth.go:987] Tx(0xe001c2a582a855b5df184910e8f2ec70144505bd6c84d4e87e1d2d99ded106b9) to: 0x07436b4f8762fddf5cb8371404d621e273d15354
== Pending transactions! Looking for next block...
I0902 10:24:09.438560    8054 miner.go:119] Starting mining operation (CPU=1 TOT=3)
== Pending transactions! Looking for next block...
I0902 10:24:09.442099    8054 worker.go:540] commit new work on block 27 with 2 txs & 0 uncles. Took 3.477442ms
I0902 10:24:09.442141    8054 miner.go:119] Starting mining operation (CPU=1 TOT=4)
I0902 10:24:09.444837    8054 worker.go:540] commit new work on block 27 with 2 txs & 0 uncles. Took 2.66568ms
I0902 10:24:10.049305    8054 xeth.go:987] Tx(0x312e767adf1a444cdf73e0bce7bc6cef51ffb020aaca6e21f14e2e31fb54a04b) to: 0xd5e55598c5b64f3a1e255d68063b8efc98a4316b
I0902 10:24:10.486778    8054 xeth.go:987] Tx(0xd2c147aa6e64b669d4c86798fbb3b1610f9e53663ac030c9b8ac2a9f78898ab6) to: 0x07436b4f8762fddf5cb8371404d621e273d15354
I0902 10:24:10.572979    8054 xeth.go:987] Tx(0x70b50c5cf1d5c30514903826696c37f74351b2f45fe6680908a3e20f9d19de10) to: 0x07436b4f8762fddf5cb8371404d621e273d15354
I0902 10:24:10.627056    8054 xeth.go:987] Tx(0x490e2b76fdae235912b16c673ac2364786b29ade848c854f923a21b1e395f1ef) to: 0xd5e55598c5b64f3a1e255d68063b8efc98a4316b
I0902 10:24:10.671019    8054 xeth.go:987] Tx(0xb1f190ea883e6a05b049a37ffe0716afafc5fafa4a8cfe59843168fd35917f52) to: 0x07436b4f8762fddf5cb8371404d621e273d15354
I0902 10:24:10.729541    8054 xeth.go:987] Tx(0xf4a98af06f166d8d1022f746cf1175970b5cfa59d7e203db1aacc40502cd9412) to: 0xd5e55598c5b64f3a1e255d68063b8efc98a4316b
I0902 10:24:10.793937    8054 xeth.go:987] Tx(0xbab38e269fb6c19042c1d18bee21d0d85854564997e5667cb4c220d666228b03) to: 0x07436b4f8762fddf5cb8371404d621e273d15354
I0902 10:24:10.900331    8054 worker.go:322] 🔨  Mined block (#27 / c856b915). Wait 5 blocks for confirmation
I0902 10:24:10.918554    8054 worker.go:540] commit new work on block 28 with 7 txs & 0 uncles. Took 18.179856ms
I0902 10:24:10.937481    8054 worker.go:540] commit new work on block 28 with 7 txs & 0 uncles. Took 18.858575ms
I0902 10:24:11.074893    8054 worker.go:322] 🔨  Mined block (#28 / ea96ed16). Wait 5 blocks for confirmation
I0902 10:24:11.075459    8054 worker.go:540] commit new work on block 29 with 0 txs & 0 uncles. Took 532.514µs
I0902 10:24:11.075762    8054 worker.go:540] commit new work on block 29 with 0 txs & 0 uncles. Took 261.515µs
== No transactions left. Stopping miner...
I0902 10:24:30.262999    8054 xeth.go:987] Tx(0xe06e75b974f69dcdedfc3c94ed353df26b51685bd65bb71cea3ea2efdeb2af93) to: 0x07436b4f8762fddf5cb8371404d621e273d15354
I0902 10:24:30.316136    8054 xeth.go:987] Tx(0x2e942420feac4f5890c8c0ad1e4c04836443dbed2096ebbf04bcc0a7b2dba04b) to: 0xd5e55598c5b64f3a1e255d68063b8efc98a4316b
I0902 10:24:30.338182    8054 xeth.go:987] Tx(0xc498ebec84f75e5bfdeb7b10f5e551c731d45035de651487cdd24462b837ea57) to: 0x07436b4f8762fddf5cb8371404d621e273d15354
I0902 10:24:30.398965    8054 xeth.go:987] Tx(0x9c4e0b9dce8e0be9b15d5cf63f9a17b54acabf3cce8e4dff407e7f7dc6b4e420) to: 0xd5e55598c5b64f3a1e255d68063b8efc98a4316b
I0902 10:24:30.421050    8054 xeth.go:987] Tx(0xdfb7fb4ae0508279fd83e91403bfab351d48ff9a62613aa60f5e55e425b14428) to: 0x07436b4f8762fddf5cb8371404d621e273d15354
I0902 10:24:30.488104    8054 xeth.go:987] Tx(0x89a5cd1edc725384b4f0f3a3b87e9ebdaa3f0746f1cb4f8ea78b3738d5547b9a) to: 0xd5e55598c5b64f3a1e255d68063b8efc98a4316b
I0902 10:24:30.511747    8054 xeth.go:987] Tx(0x4448d87c041fc46af199ecd5b8c02142be7eb70c06748a6c084586fa7d2648b9) to: 0x07436b4f8762fddf5cb8371404d621e273d15354
== Pending transactions! Looking for next block...
I0902 10:24:30.562704    8054 miner.go:119] Starting mining operation (CPU=1 TOT=3)
== Pending transactions! Looking for next block...
== Pending transactions! Looking for next block...
== Pending transactions! Looking for next block...
I0902 10:24:30.573945    8054 xeth.go:987] Tx(0x2f87fb37445650075067b5f8c8368a1b183283394a897fe4b092c9478599b78b) to: 0xd5e55598c5b64f3a1e255d68063b8efc98a4316b
== Pending transactions! Looking for next block...
I0902 10:24:30.574447    8054 worker.go:540] commit new work on block 29 with 7 txs & 0 uncles. Took 11.698025ms
I0902 10:24:30.574501    8054 miner.go:119] Starting mining operation (CPU=1 TOT=4)
I0902 10:24:30.584646    8054 worker.go:540] commit new work on block 29 with 8 txs & 0 uncles. Took 10.111875ms
I0902 10:24:30.584704    8054 miner.go:119] Starting mining operation (CPU=1 TOT=5)
I0902 10:24:30.594544    8054 worker.go:540] commit new work on block 29 with 8 txs & 0 uncles. Took 9.806376ms
I0902 10:24:30.594620    8054 miner.go:119] Starting mining operation (CPU=1 TOT=6)
I0902 10:24:30.606446    8054 worker.go:540] commit new work on block 29 with 8 txs & 0 uncles. Took 11.791454ms
I0902 10:24:30.606525    8054 miner.go:119] Starting mining operation (CPU=1 TOT=7)
I0902 10:24:30.624169    8054 worker.go:540] commit new work on block 29 with 8 txs & 0 uncles. Took 17.601971ms
I0902 10:24:30.671293    8054 worker.go:322] 🔨  Mined block (#29 / 3ee81bd2). Wait 5 blocks for confirmation
I0902 10:24:30.671918    8054 worker.go:540] commit new work on block 30 with 0 txs & 0 uncles. Took 585.067µs
I0902 10:24:30.673069    8054 worker.go:540] commit new work on block 30 with 0 txs & 0 uncles. Took 369.316µs
I0902 10:24:30.676993    8054 xeth.go:987] Tx(0xdc417a78dc74a50a286bafc71b04906b46630f8392f5ed731c17f50c348459c0) to: 0x07436b4f8762fddf5cb8371404d621e273d15354
I0902 10:24:31.253725    8054 worker.go:322] 🔨  Mined block (#30 / 4402cdf9). Wait 5 blocks for confirmation
I0902 10:24:31.260412    8054 worker.go:540] commit new work on block 31 with 1 txs & 0 uncles. Took 6.64936ms
I0902 10:24:31.267653    8054 worker.go:540] commit new work on block 31 with 1 txs & 0 uncles. Took 7.168354ms
I0902 10:24:31.589567    8054 worker.go:322] 🔨  Mined block (#31 / 241d386c). Wait 5 blocks for confirmation
I0902 10:24:31.590116    8054 worker.go:540] commit new work on block 32 with 0 txs & 0 uncles. Took 507.664µs
I0902 10:24:31.590725    8054 worker.go:540] commit new work on block 32 with 0 txs & 0 uncles. Took 463.587µs
I0902 10:24:31.630399    8054 worker.go:322] 🔨  Mined block (#32 / c7b70730). Wait 5 blocks for confirmation
I0902 10:24:31.630983    8054 worker.go:540] commit new work on block 33 with 0 txs & 0 uncles. Took 538.945µs
I0902 10:24:31.631055    8054 worker.go:420] 🔨 🔗  Mined 5 blocks back: block #27
I0902 10:24:31.631504    8054 worker.go:540] commit new work on block 33 with 0 txs & 0 uncles. Took 408.806µs
I0902 10:24:31.704780    8054 worker.go:322] 🔨  Mined block (#33 / 478cad73). Wait 5 blocks for confirmation
I0902 10:24:31.705406    8054 worker.go:540] commit new work on block 34 with 0 txs & 0 uncles. Took 586.163µs
I0902 10:24:31.705480    8054 worker.go:420] 🔨 🔗  Mined 5 blocks back: block #28
I0902 10:24:31.705932    8054 worker.go:540] commit new work on block 34 with 0 txs & 0 uncles. Took 418.387µs
I0902 10:24:31.898566    8054 worker.go:322] 🔨  Mined block (#34 / 6e1d75b8). Wait 5 blocks for confirmation
I0902 10:24:31.899098    8054 worker.go:540] commit new work on block 35 with 0 txs & 0 uncles. Took 493.557µs
I0902 10:24:31.899203    8054 worker.go:420] 🔨 🔗  Mined 5 blocks back: block #29
I0902 10:24:31.899758    8054 worker.go:540] commit new work on block 35 with 0 txs & 0 uncles. Took 515.576µs
I0902 10:24:31.984597    8054 worker.go:322] 🔨  Mined block (#35 / 59f96e30). Wait 5 blocks for confirmation
I0902 10:24:31.985245    8054 worker.go:540] commit new work on block 36 with 0 txs & 0 uncles. Took 587.262µs
I0902 10:24:31.985340    8054 worker.go:420] 🔨 🔗  Mined 5 blocks back: block #30
I0902 10:24:31.986413    8054 worker.go:540] commit new work on block 36 with 0 txs & 0 uncles. Took 372.346µs
== No transactions left. Stopping miner...
panic: runtime error: invalid memory address or nil pointer dereference
[signal 0xb code=0x1 addr=0x70 pc=0x449c7c6]

goroutine 1159 [running]:
github.com/ethereum/go-ethereum/miner.(*CpuAgent).mine(0xc820efb380, 0x0, 0xc822139080)
    /private/tmp/ethereum20150901-320-2mbr53/src/github.com/ethereum/go-ethereum/miner/agent.go:112 +0x166
created by github.com/ethereum/go-ethereum/miner.(*CpuAgent).update
    /private/tmp/ethereum20150901-320-2mbr53/src/github.com/ethereum/go-ethereum/miner/agent.go:82 +0x154

(other goroutines omitted from dump, but available upon request)

jorisbontje commented 9 years ago

Also happening with geth 1.1.2 and embark 0.9.1. Embark uses this script to toggle mining on and off; which is the trigger for this crash https://github.com/iurimatias/embark-framework/blob/develop/js/mine.js

bas-vk commented 9 years ago

@jorisbontje, could you provide the full trace?

jorisbontje commented 9 years ago

@bas-vk https://gist.github.com/jorisbontje/f0f0e0a65d9ade021216

obscuren commented 9 years ago

@bas-vk status?

jorisbontje commented 9 years ago

fixed in 1.2.1