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.

Sign up for GitHub

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

Jump to bottom

btcd panic'd during handleTxMsg #70

Closed
flammit opened this issue Dec 28, 2013 · 6 comments
Closed

btcd panic'd during handleTxMsg #70

flammit opened this issue Dec 28, 2013 · 6 comments
Labels
bug high priority

Comments

@flammit
Copy link
Contributor

flammit commented Dec 28, 2013

Looks like my btcd daemon crashed overnight sometime. I've attached the screen output prior to the crash. It restarted fine just now, but I wanted to put this on the radar.

02:38:44 2013-12-28 [INF] BMGR: Processed 1 block in the last 4m46.62s (133 transactions, height 277370, 2013-12-28 02:38:30 -0500 EST)
02:42:13 2013-12-28 [INF] BMGR: Processed 1 block in the last 3m28.9s (99 transactions, height 277371, 2013-12-28 02:41:47 -0500 EST)
03:02:50 2013-12-28 [INF] BMGR: Processed 1 block in the last 20m37.48s (540 transactions, height 277372, 2013-12-28 03:04:12 -0500 EST)
03:22:09 2013-12-28 [INF] BMGR: Processed 1 block in the last 19m18.46s (492 transactions, height 277373, 2013-12-28 03:21:26 -0500 EST)
03:44:36 2013-12-28 [INF] CHAN: Adding orphan block 000000000000000108b1d0bf3b341ef006cb7e56477138a68aba7ea4ea73458b with parent 0000000000000002ab0b9e2
c971183e56ae5390c33dd9087f9bdf7473acc0dc4
03:44:36 2013-12-28 [INF] BMGR: Processed 1 block in the last 22m27.06s (86 transactions, height 277373, 2013-12-28 03:21:26 -0500 EST)
03:44:36 2013-12-28 [INF] CHAN: FORK: Block 0000000000000002ab0b9e2c971183e56ae5390c33dd9087f9bdf7473acc0dc4 forks the chain at height 277372/block 0000
0000000000032d2196079991eff1886da6e64ed74f85f664b3fec540b8db, but does not cause a reorganize
03:44:36 2013-12-28 [INF] CHAN: REORGANIZE: Block 000000000000000108b1d0bf3b341ef006cb7e56477138a68aba7ea4ea73458b is causing a reorganize.
03:44:37 2013-12-28 [INF] CHAN: REORGANIZE: Chain forks at 00000000000000032d2196079991eff1886da6e64ed74f85f664b3fec540b8db
03:44:37 2013-12-28 [INF] CHAN: REORGANIZE: Old best chain head was 000000000000000122bd83ab0188a3111b2cf0fa2d88b8faf0dbae9f52a66234
03:44:37 2013-12-28 [INF] CHAN: REORGANIZE: New best chain head is 000000000000000108b1d0bf3b341ef006cb7e56477138a68aba7ea4ea73458b
panic: runtime error: slice bounds out of range

goroutine 19 [running]:
runtime.panic(0x8e1f60, 0xfc0eaa)
/usr/local/go/src/pkg/runtime/panic.c:266 +0xb6
github.com/conformal/btcdb/ldb.(_LevelDb).fetchTxDataByLoc(0xc210106070, 0x43b7d, 0x18d8e, 0x149, 0xc21030f218, ...)
/home/flam/devel/go/ext/src/github.com/conformal/btcdb/ldb/tx.go:350 +0x453
github.com/conformal/btcdb/ldb.(_LevelDb).fetchTxDataBySha(0xc210106070, 0xc2122f6880, 0x0, 0x0, 0x0, ...)
/home/flam/devel/go/ext/src/github.com/conformal/btcdb/ldb/tx.go:330 +0x183
github.com/conformal/btcdb/ldb.(_LevelDb).FetchUnSpentTxByShaList(0xc210106070, 0xc21268e500, 0x2, 0x2, 0x0, ...)
/home/flam/devel/go/ext/src/github.com/conformal/btcdb/ldb/tx.go:301 +0x142
github.com/conformal/btcdb.Db.FetchUnSpentTxByShaList·fm(0xc21268e500, 0x2, 0x2, 0x0, 0x0, ...)
/home/flam/devel/go/ext/src/github.com/conformal/btcchain/txlookup.go:118 +0x67
github.com/conformal/btcchain.fetchTxStoreMain(0x7f87dcf54448, 0xc210106070, 0xc21369b120, 0xc89b16d9f08e0800, 0x5ddae96804e2cbbd)
/home/flam/devel/go/ext/src/github.com/conformal/btcchain/txlookup.go:122 +0x39a
github.com/conformal/btcchain.(_BlockChain).FetchTransactionStore(0xc210100280, 0xc21369b090, 0x41a2cd, 0x8016c0, 0xc21078ae10)
/home/flam/devel/go/ext/src/github.com/conformal/btcchain/txlookup.go:309 +0x13a
main.(_txMemPool).fetchInputTransactions(0xc21186b500, 0xc21369b090, 0x0, 0x0, 0x0)
/home/flam/devel/go/ext/src/github.com/conformal/btcd/mempool.go:677 +0x4b
main.(_txMemPool).maybeAcceptTransaction(0xc21186b500, 0xc21369b090, 0x7f87d85e0e43, 0xc21268e4e0, 0x1)
/home/flam/devel/go/ext/src/github.com/conformal/btcd/mempool.go:798 +0x698
main.(_txMemPool).ProcessTransaction(0xc21186b500, 0xc21369b090, 0x0, 0x0)
/home/flam/devel/go/ext/src/github.com/conformal/btcd/mempool.go:975 +0x14a
main.(_blockManager).handleTxMsg(0xc2100744e0, 0xc21268e4d0)
/home/flam/devel/go/ext/src/github.com/conformal/btcd/blockmanager.go:317 +0x1c1
main.(_blockManager).blockHandler(0xc2100744e0)
/home/flam/devel/go/ext/src/github.com/conformal/btcd/blockmanager.go:646 +0x2ae
created by main.(_blockManager).Start
/home/flam/devel/go/ext/src/github.com/conformal/btcd/blockmanager.go:849 +0x12e

goroutine 1 [chan receive]:
main.btcdMain(0x0, 0x0, 0x0)
/home/flam/devel/go/ext/src/github.com/conformal/btcd/btcd.go:121 +0x8ee
main.main()
/home/flam/devel/go/ext/src/github.com/conformal/btcd/btcd.go:150 +0x59

goroutine 3 [syscall]:
os/signal.loop()
/usr/local/go/src/pkg/os/signal/signal_unix.go:21 +0x1e
created by os/signal.init·1
/usr/local/go/src/pkg/os/signal/signal_unix.go:27 +0x31

goroutine 4 [semacquire]:
sync.runtime_Syncsemacquire(0xc21007c010)
/usr/local/go/src/pkg/runtime/sema.goc:257 +0xca
sync.(_Cond).Wait(0xc21007c000)
/usr/local/go/src/pkg/sync/cond.go:62 +0x89
github.com/conformal/seelog.(_asyncLoopLogger).processItem(0xc2100385a0, 0x0)
/home/flam/devel/go/ext/src/github.com/conformal/seelog/behavior_asynclooplogger.go:50 +0x95
github.com/conformal/seelog.(*asyncLoopLogger).processQueue(0xc2100385a0)
/home/flam/devel/go/ext/src/github.com/conformal/seelog/behavior_asynclooplogger.go:63 +0x31
created by github.com/conformal/seelog.newAsyncLoopLogger
/home/flam/devel/go/ext/src/github.com/conformal/seelog/behavior_asynclooplogger.go:40 +0x74

goroutine 5 [semacquire]:
sync.runtime_Syncsemacquire(0xc21007c190)
/usr/local/go/src/pkg/runtime/sema.goc:257 +0xca
sync.(_Cond).Wait(0xc21007c180)
/usr/local/go/src/pkg/sync/cond.go:62 +0x89
github.com/conformal/seelog.(_asyncLoopLogger).processItem(0xc210038660, 0x0)
/home/flam/devel/go/ext/src/github.com/conformal/seelog/behavior_asynclooplogger.go:50 +0x95
github.com/conformal/seelog.(*asyncLoopLogger).processQueue(0xc210038660)
/home/flam/devel/go/ext/src/github.com/conformal/seelog/behavior_asynclooplogger.go:63 +0x31
created by github.com/conformal/seelog.newAsyncLoopLogger
/home/flam/devel/go/ext/src/github.com/conformal/seelog/behavior_asynclooplogger.go:40 +0x74

goroutine 8 [semacquire]:
sync.runtime_Syncsemacquire(0xc21007ce90)
/usr/local/go/src/pkg/runtime/sema.goc:257 +0xca
sync.(_Cond).Wait(0xc21007ce80)
/usr/local/go/src/pkg/sync/cond.go:62 +0x89
github.com/conformal/seelog.(_asyncAdaptiveLogger).processItem(0xc210068d20, 0xc213c1ba00, 0x0)
/home/flam/devel/go/ext/src/github.com/conformal/seelog/behavior_adaptivelogger.go:94 +0x9e
github.com/conformal/seelog.(*asyncAdaptiveLogger).processQueue(0xc210068d20)
/home/flam/devel/go/ext/src/github.com/conformal/seelog/behavior_adaptivelogger.go:119 +0x31
created by github.com/conformal/seelog.newAsyncAdaptiveLogger
/home/flam/devel/go/ext/src/github.com/conformal/seelog/behavior_adaptivelogger.go:84 +0x4a2

goroutine 7 [syscall]:
runtime.goexit()
/usr/local/go/src/pkg/runtime/proc.c:1394

goroutine 10 [select]:
github.com/conformal/goleveldb/leveldb.(*DB).compactionError(0xc21000bd80)
/home/flam/devel/go/ext/src/github.com/conformal/goleveldb/leveldb/db_compaction.go:115 +0x1c5
created by github.com/conformal/goleveldb/leveldb.openDB
/home/flam/devel/go/ext/src/github.com/conformal/goleveldb/leveldb/db.go:114 +0x402

goroutine 11 [select]:
github.com/conformal/goleveldb/leveldb.(*DB).compaction(0xc21000bd80)
/home/flam/devel/go/ext/src/github.com/conformal/goleveldb/leveldb/db_compaction.go:437 +0x75f
created by github.com/conformal/goleveldb/leveldb.openDB
/home/flam/devel/go/ext/src/github.com/conformal/goleveldb/leveldb/db.go:117 +0x443

goroutine 12 [select]:
github.com/conformal/goleveldb/leveldb.(*DB).writeJournal(0xc21000bd80)
/home/flam/devel/go/ext/src/github.com/conformal/goleveldb/leveldb/db_write.go:36 +0x142
created by github.com/conformal/goleveldb/leveldb.openDB
/home/flam/devel/go/ext/src/github.com/conformal/goleveldb/leveldb/db.go:118 +0x45a

goroutine 13 [select]:
main.mainInterruptHandler()
/home/flam/devel/go/ext/src/github.com/conformal/btcd/signal.go:28 +0x216
created by main.addInterruptHandler
/home/flam/devel/go/ext/src/github.com/conformal/btcd/signal.go:55 +0xcb

goroutine 14 [select]:
main.(_server).peerHandler(0xc210074340)
/home/flam/devel/go/ext/src/github.com/conformal/btcd/server.go:486 +0xaf5
created by main.(_server).Start
/home/flam/devel/go/ext/src/github.com/conformal/btcd/server.go:686 +0x1ec

goroutine 15 [select]:
main.(_rpcServer).walletListenerDuplicator(0xc21010b2c0)
/home/flam/devel/go/ext/src/github.com/conformal/btcd/rpcserver.go:1544 +0x199
created by main.(_rpcServer).Start
/home/flam/devel/go/ext/src/github.com/conformal/btcd/rpcserver.go:286 +0x25b

goroutine 16 [IO wait]:
net.runtime_pollWait(0x7f87d8592478, 0x72, 0x0)
/usr/local/go/src/pkg/runtime/netpoll.goc:116 +0x6a
net.(_pollDesc).Wait(0xc21055b7d0, 0x72, 0x7f87dcf31098, 0xb)
/usr/local/go/src/pkg/net/fd_poll_runtime.go:81 +0x34
net.(_pollDesc).WaitRead(0xc21055b7d0, 0xb, 0x7f87dcf31098)
/usr/local/go/src/pkg/net/fd_poll_runtime.go:86 +0x30
net.(_netFD).accept(0xc21055b770, 0xaa0828, 0x0, 0x7f87dcf31098, 0xb)
/usr/local/go/src/pkg/net/fd_unix.go:382 +0x2c2
net.(_TCPListener).AcceptTCP(0xc21084d5d0, 0xc2124a9b40, 0x8, 0x8108c6780)
/usr/local/go/src/pkg/net/tcpsock_posix.go:233 +0x47
net.(_TCPListener).Accept(0xc21084d5d0, 0xaa0850, 0x7f87d85e6e88, 0x8, 0x54225b)
/usr/local/go/src/pkg/net/tcpsock_posix.go:243 +0x27
crypto/tls.(_listener).Accept(0xc21134c900, 0x0, 0x0, 0x0, 0x0)
/usr/local/go/src/pkg/crypto/tls/tls.go:46 +0x53
net/http.(_Server).Serve(0xc211610910, 0x7f87d8592520, 0xc21134c900, 0x0, 0x0)
/usr/local/go/src/pkg/net/http/server.go:1622 +0x91
main.func·021(0x7f87d8592520, 0xc21134c900)
/home/flam/devel/go/ext/src/github.com/conformal/btcd/rpcserver.go:299 +0x135
created by main.(_rpcServer).Start
/home/flam/devel/go/ext/src/github.com/conformal/btcd/rpcserver.go:302 +0x366

goroutine 17 [semacquire]:
sync.runtime_Semacquire(0xc21061f0c8)
/usr/local/go/src/pkg/runtime/sema.goc:199 +0x30
sync.(_WaitGroup).Wait(0xc2100743c8)
/usr/local/go/src/pkg/sync/waitgroup.go:127 +0x14b
main.(_server).WaitForShutdown(0xc210074340)
/home/flam/devel/go/ext/src/github.com/conformal/btcd/server.go:730 +0x36
main.func·006()
/home/flam/devel/go/ext/src/github.com/conformal/btcd/btcd.go:114 +0x29
created by main.btcdMain
/home/flam/devel/go/ext/src/github.com/conformal/btcd/btcd.go:117 +0x8d2

goroutine 18 [select]:
main.(_AddrManager).addressHandler(0xc210230c00)
/home/flam/devel/go/ext/src/github.com/conformal/btcd/addrmanager.go:389 +0x1c3
created by main.(_AddrManager).Start
/home/flam/devel/go/ext/src/github.com/conformal/btcd/addrmanager.go:622 +0x142

goroutine 21 [chan receive]:
main.(_peer).handleTxMsg(0xc2106a6000, 0xc2107b1980)
/home/flam/devel/go/ext/src/github.com/conformal/btcd/peer.go:534 +0x108
main.(_peer).inHandler(0xc2106a6000)
/home/flam/devel/go/ext/src/github.com/conformal/btcd/peer.go:1092 +0xa73
created by main.(*peer).Start
/home/flam/devel/go/ext/src/github.com/conformal/btcd/peer.go:1456 +0x25a

goroutine 22 [select]:
main.(_peer).queueHandler(0xc2106a6000)
/home/flam/devel/go/ext/src/github.com/conformal/btcd/peer.go:1187 +0xba3
created by main.(_peer).Start
/home/flam/devel/go/ext/src/github.com/conformal/btcd/peer.go:1460 +0x297

goroutine 23 [select]:
main.(_peer).outHandler(0xc2106a6000)
/home/flam/devel/go/ext/src/github.com/conformal/btcd/peer.go:1302 +0x746
created by main.(_peer).Start
/home/flam/devel/go/ext/src/github.com/conformal/btcd/peer.go:1461 +0x2ae
@flammit
Copy link
Contributor Author

flammit commented Dec 28, 2013

It looks like there might be a problem during chain reorganization and handling new mempool txns that spend from newly-orphaned blocks.

Based on the stack trace line:

...fetchTxDataByLoc( blkHeight=277373, txOff=101774, txLen=329, ... )

it looks like there was a transaction that attempted to spend from a transaction (hash=f222fcf95b1ce5ee5ddae96804e2cbbdc89b16d9f08e08f9ec03e85f5ba05c76) while the chain reorganization was happening.

That transaction was included in the orphaned block at height 277373 (hash=000000000000000122bd83ab0188a3111b2cf0fa2d88b8faf0dbae9f52a66234), but the new block at height 277373 (hash=0000000000000002ab0b9e2c971183e56ae5390c33dd9087f9bdf7473acc0dc4) doesn't have it and the block data returned wasn't long enough (only 32kb) causing the slice bounds out range runtime error.

I think someone with a more intimate knowledge of the locking guarantees for the data stores during block disconnects would need to assess what needs to be fixed.

@jcvernaleo
Copy link
Member

I seem to have hit the same thing at a slightly different block:
10:57:23 2013-12-31 [INF] CHAN: REORGANIZE: New best chain head is 0000000000000
003618d89ed238449803363aed110d8bd7a8d84cc4f62f2c78a
10:57:23 2013-12-31 [INF] BMGR: Processed 2 blocks in the last 12m23.7s (811 tra
nsactions, height 277936, 2013-12-31 10:55:20 -0500 EST)
panic: runtime error: slice bounds out of range

with what looks like the same junk after.

@davecgh
Copy link
Member

davecgh commented Jan 9, 2014

We've managed to reproduce this reliably. A fix should be forthcoming.

@davecgh
Copy link
Member

davecgh commented Jan 11, 2014

We have tracked this down to a bug in goleveldb which I have reported here: syndtr/goleveldb#42.

@davecgh
Copy link
Member

davecgh commented Jan 13, 2014 •
edited
Loading

This has been resolved by syndtr/goleveldb@92de35c. We'll be merging it into the Conformal fork shortly.

@davecgh
Copy link
Member

davecgh commented Jan 13, 2014

The fix for this has now been merged into the Conformal fork of goleveldb as of commit conformal/leveldb@3ce16077443eab51c7bc8371fef66fddee0b5870.

@davecgh davecgh closed this as completed Jan 13, 2014
gsalgado pushed a commit to gsalgado/btcd that referenced this issue Jul 29, 2014
@jrick
Do not serialize/deserialize armory unique ID.
03ffa0c 
Closes btcsuite#70.
kcalvinalvin added a commit to kcalvinalvin/btcd that referenced this issue Nov 29, 2024
@kcalvinalvin
Merge pull request btcsuite#70 from kcalvinalvin/2023-08-30-add-check…
8da45fa 
…-to-utreexoviewpoint

blockchain: add assertion check to ProcessUData
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
bug high priority
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
3 participants
@jcvernaleo @flammit @davecgh