receiving a SharedCoin transaction generates an insane amount of logs (and requests?)

[GoogleCodeExporter]

A user has contacted me recently, telling me that a transaction they've sent to 
the wallet through Blockchain.info's SharedCoin (a version of CoinJoin) hasn't 
arrived in the wallet, although it appears as sent on the site.

I've asked them for logs. I've looked at them, and the files are full of 
messages like: "Bottomed out dep tree at ...". I actually couldn't see the 
beginning of the event, because it generated so many lines of logs that the 
beginning of the log was already truncated by the time it finished. It also 
seems to have broken connection to the peer, because it ended with this:

2014-07-19 15:49:51 +0000 Peer processNotFoundMessage INFO: [88.135.237.118]:8333: Bottomed out dep tree at (...) 2014-07-19 15:55:10 +0000 ConnectionHandler handleKey ERROR: Error handling SelectionKey: Connection reset by peer 2014-07-19 15:55:10 +0000 PeerGroup handlePeerDeath INFO: [88.135.237.118]:8333: Peer died

I've tried it myself - I've sent a transaction from my Blockchain.info wallet 
through SharedCoin to my Hive wallet 
(https://blockchain.info/tx/b2bc48b067c15b7c8050583e1427e21d7d2aca95c213b02425d5
b118654f66e7). Receiving this transaction generated half a million lines of 
logs (!). I'm attaching a zipped version here.

Some stats about the file:

- receiving the transaction took about a minute
- there are 119041 lines with a "Bottomed out dep tree" message
- there are only 56 different kinds of these lines (i.e. 56 different hashes 
appearing with that message)
- the most "popular" hash appears 13816 times in the file

I don't know what's going on here, but this doesn't sound like expected 
behavior...

Note: I'm running this on 0.11.3. I tried testing on 0.12 today, but it looks 
like a lot of things have changed in the API and I can't even get it to 
compile, so it will take some time to port my code to 0.12.

Original issue reported on code.google.com by jakub.su...@gmail.com on 14 Oct 2014 at 11:41

Attachments:

• sharedcoin1.log.zip

[GoogleCodeExporter]

The release notes contain info on how to port to 0.12 - after doing the sed to 
change all the package imports, and sedding BigInteger -> Coin, most of the 
changes left should be fairly small.

WRT the SharedCoin issue. I think this can happen when something is constantly 
sending lots of big transactions that chain together very fast, which sounds 
like what SharedCoin is probably doing. The problem is that the code assumes 
getdata only works for mempool transactions but it does actually also work for 
"relay memory", which isn't purged when a block is received, unlike the 
mempool. It's basically "all recent transactions". So you can end up 
downloading transaction graphs that are in fact already in blocks, which is 
pointless.

The dependency download logic can be disabled by calling 
peerGroup.setDownloadTxDependencies(false). It has other issues. We may need to 
re-evaluate whether this feature is worth the problems it can cause.

Original comment by mh.in.en...@gmail.com on 14 Oct 2014 at 12:53

[GoogleCodeExporter]

But why is it trying to download the same transactions again and again? 
Shouldn't it have, like, a Set of hashes that were already requested, and if it 
finds one there it doesn't request it again? (Sorry if I misunderstood what's 
happening here.)

For example, this line was printed 2354 times during that minute:

"Downloaded dependency of 
5635970dc6a4919d589313e301be12ee1f70e13554f633e96b827bc15e10d2f3: 
7cb742dc655f2c141eab9e85ff5bc3b95c1a4c4445b4963acda550a837b7d386"

As for 0.12: I had some other errors too, some stuff was renamed in the payment 
protocol area, there were also errors about 
WalletProtobufSerializer.readWallet, Wallet.getKeys, ECKey.clearPrivateKey etc.

Original comment by jakub.su...@gmail.com on 14 Oct 2014 at 2:00

[GoogleCodeExporter]

Yes, that sounds like a bug. I suspect diamond shaped transaction graphs are 
not used outside of SharedCoin so we never encountered this before. Also I 
noticed a lot of closure/user thread spam in the log too. I think that might go 
away with 0.12 but I'd have to check.

At any rate, the dep resolution process has a bunch of bugs and needs some 
love, that's for sure. For now you can disable it.

Original comment by mh.in.en...@gmail.com on 14 Oct 2014 at 4:33

• Changed state: Accepted
• Added labels: Type-Defect
• Removed labels: Type-Enhancement