0.96 preliminary testing

[goatpig]

Something that just occurred to me

Is it not the case that "native" (i.e. not nested P2SH) P2WPKH and P2WSH address formats will appear subsequent to Segwit activation? And I say "appear", as they're AFAIA unspecified at this point.

Any reasonable expectation that the un-nested Witness address specifications will be available to implement before 0.97? Surely the wallet format needs to be change to incorporate them, although presumably not the signer? Will the wallet format actually stabilise at 97.1 or 0.98, in other words?

sipa has a proposal:

https://gist.github.com/sipa/c291da162f6ef8cc770bfc7f015c6c49

It will be discussed at the s3nd meet among other topics:

https://s3nd.org/berlin2017

I can't tell whether this will be ready for 0.97, but I expect it will be by 0.98.

[Carlton Banks]

Ah, so there is at least a proposal for a spec (I seem to remember there was an old one that was withdrawn)

Last wallet question

Have you guys tested the compressed P2SH keys on testnet? Any problems? I'd quite like to begin using them, it seems incredibly anti-social to continue to use uncompressed keys if their implementation is considered safe to use now.

[goatpig]

Have you guys tested the compressed P2SH keys on testnet? Any problems? I'd quite like to begin using them, it seems incredibly anti-social to continue to use uncompressed keys if their implementation is considered safe to use now.

Both nested script types have been tested on the testnet. I cross compiled 0.96 for my RPi yesterday and will test the nested compressed key script on the mainnet with my own coins sometimes before I post the first testing builds.

[droark]

Just submitted a PR that should squash the final-ish bug keeping the OSX build from getting off the ground. It's still not quite working, though. While the DB is being populated after the initial block/Tx scan, Armory seems to get confused and never gets past the scan stage, despite Armory appearing to still be scanning. I really don't see anything else in the logs, unfortunately.

Code:

-INFO  - 1489439887: (SocketObject.cpp:516) POLLIN recv return 0

[goatpig]

While the DB is being populated after the initial block/Tx scan, Armory seems to get confused and never gets past the scan stage, despite Armory appearing to still be scanning. I really don't see anything else in the logs, unfortunately.

Code:

-INFO  - 1489439887: (SocketObject.cpp:516) POLLIN recv return 0

Use some print statements in the client side callback thread, figure out what signal is not going through:

https://github.com/goatpig/BitcoinArmory/blob/dev/cppForSwig/SwigClient.cpp#L894

It should receive one case of CBO_BDM_Ready after the scan is complete. Before that, it should be all CBO_progress packets. If it gets those properly, then something is chocking in this scope:

https://github.com/goatpig/BitcoinArmory/blob/master/ArmoryQt.py#L5834

[droark]

While the DB is being populated after the initial block/Tx scan, Armory seems to get confused and never gets past the scan stage, despite Armory appearing to still be scanning. I really don't see anything else in the logs, unfortunately.

Code:

-INFO  - 1489439887: (SocketObject.cpp:516) POLLIN recv return 0

Use some print statements in the client side callback thread, figure out what signal is not going through:

https://github.com/goatpig/BitcoinArmory/blob/dev/cppForSwig/SwigClient.cpp#L894

It should receive one case of CBO_BDM_Ready after the scan is complete. Before that, it should be all CBO_progress packets. If it gets those properly, then something is chocking in this scope:

https://github.com/goatpig/BitcoinArmory/blob/master/ArmoryQt.py#L5834

Thanks. Will do. Pushed some more build stuff in the meantime. The build process should be reasonably solid at this point.

[droark]

While the DB is being populated after the initial block/Tx scan, Armory seems to get confused and never gets past the scan stage, despite Armory appearing to still be scanning. I really don't see anything else in the logs, unfortunately.

Code:

-INFO  - 1489439887: (SocketObject.cpp:516) POLLIN recv return 0

Use some print statements in the client side callback thread, figure out what signal is not going through:

https://github.com/goatpig/BitcoinArmory/blob/dev/cppForSwig/SwigClient.cpp#L894

It should receive one case of CBO_BDM_Ready after the scan is complete. Before that, it should be all CBO_progress packets. If it gets those properly, then something is chocking in this scope:

https://github.com/goatpig/BitcoinArmory/blob/master/ArmoryQt.py#L5834

Just checked. No CBO_BDM_Ready message comes in. Also discovered that FINISH_LOAD_BLOCKCHAIN_ACTION is never seen in ArmoryQt.py either. Looked at the code a little bit but didn't have much time to sift through it. Where should I look next?

[goatpig]

Just checked. No CBO_BDM_Ready message comes in. Also discovered that FINISH_LOAD_BLOCKCHAIN_ACTION is never seen in ArmoryQt.py either.

FINISH_LOAD_BLOCKCHAIN_ACTION is triggered by CBO_BDM_Ready.

Where should I look next?

On the DB side, the signal is emitted here:

https://github.com/goatpig/BitcoinArmory/blob/dev/cppForSwig/BDM_Server.cpp#L1420

There is a lot of code running before it gets to this point. This is the point at which the signal is being prepared to be sent over the socket. My intuition tells me the issue is taking place after that event. A simple print statement should determine that the code always gets past this point (or just looking at the DB log, if it gets past "enabling zero conf", the scan was successful)

If the issue is happening before this, I'll lay out the details of the code behind that signal for you to observe.

Assuming it gets past this point, my first and foremost culprit would be packet mangling over the socket. The code will not choke over a bad packet, it will simply ignore it. The first thing you should do is log the packets you get from the DB.

https://github.com/goatpig/BitcoinArmory/blob/dev/cppForSwig/SwigClient.cpp#L987

retval is a string, you can either output it to stdout or save it to a file. Let the code run and show me the packet log for analysis.

EDIT:

Here is my packet log for comparison:

Code:

-INFO  - 1489659588: (..\SwigClient.cpp:988) 040c4244565f50726f67726573730704617e578b9b30ef3f000000004d00000000
-INFO  - 1489659588: (..\SwigClient.cpp:988) 040c4244565f50726f6772657373070431bfabc54d98ef3f180000004e00000000
-INFO  - 1489659588: (..\SwigClient.cpp:988) 040c4244565f50726f677265737307020000000000000000ffffffff0000000000
-INFO  - 1489659588: (..\SwigClient.cpp:988) 040c4244565f50726f677265737307053ff99c0248ecef3fffffffff3131be7100
-INFO  - 1489659589: (..\SwigClient.cpp:988) 040c4244565f50726f67726573730705000000000000f03f000000001eb6407300
-INFO  - 1489659589: (..\SwigClient.cpp:988) 040c4244565f50726f677265737307060000000000000000000000000000000000
-INFO  - 1489659589: (..\SwigClient.cpp:988) 040c4244565f50726f677265737307070000000000000000ffffffff0000000000
-INFO  - 1489659589: (..\SwigClient.cpp:988) 040942444d5f526561647902fee8b01000
BDM is ready!

The last packet is the BDM_ready signal. This 42444d5f5265616479 stands for BDM_Ready in hexits, the last part is a 4bytes integer with its header (02).

[droark]

Thanks. I looked into some of this late last night. You wrote a much more detailed version of what I found.

Here's an excerpt from dbLog.txt. I think there's something wrong with how the file's written, as it crashed my normal text editor! (A bug in my text editor, I know, but the actual log is still mangled under other text editors. ~550 KB worth of ^@ can be seen at the front of my log under vim and nano.) While I haven't confirmed yet, I suspect something's going wrong inside this call. In any event, it seems like the registerWalletMutex_ lock gets screwed up along the way and leaves ArmoryDB hanging.

Code:

--------ERROR ERROR ERROR ERROR ERROR ERROR ERROR ERROR - - - - - - - 14896841641489684164148968416414896841641489684164- 148968416414896841641489684164: : : : : : : (((((: (((BlockchainScanner.cppBlockchainScanner.cppBlockchainScanner.cppBlockchainScanner.cppBlockchainScanner.cppBlockchainScanner.cppBlockchainScanner.cpp:::::BlockchainScanner.cpp::271271271271271:271271271) ) ) ) ) ) ) ) raw data does not match expected block hashraw data does not match expected block hashraw data does not match expected block hashraw data does not match expected block hashraw data does not match expected block hashraw data does not match expected block hashraw data does not match expected block hash



raw data does not match expected block hash

[goatpig]

The error in your code snippet is the scan process failing to grab valid block data (it's failing the merkle hash check in basically every thread).

I suspect something's going wrong inside this call

Is the promise failing to signal the future or the code leading to set the promise failing? This is surprising, that code didn't change at all from 0.95 to 0.96. Have you considered building with XCode 8?

[droark]

The error in your code snippet is the scan process failing to grab valid block data (it's failing the merkle hash check in basically every thread).

Interesting.

I suspect something's going wrong inside this call

Is the promise failing to signal the future or the code leading to set the promise failing? This is surprising, that code didn't change at all from 0.95 to 0.96. Have you considered building with XCode 8?

Okay, I confirmed that, for whatever reasons, the wait() call causes things to go sideways, or at least gets stuck due to registerAddressBatch() never truly finishing. The code doesn't crash. It just never seems to get past the wait. Right now, I'm compiling on an OSX 10.12/Xcode 8 combo, as that's the easiest for me. (10.11/7.3.1, the combo I use for release builds, requires me to use a VM. It seems to fail in a similar manner, though, based off a version I ran a few days ago.)

Just in case I've missed something, I've copied & pasted the entire ArmoryDB log. Maybe the cookie error means something? Hard to say since I don't know this code.

Code:

Log file opened at 1489698375: /Users/droark/Library/Application Support/Armory/testnet3/dbLog.txt
-INFO  - 1489698375: (main.cpp:23) Running on 8 threads
-INFO  - 1489698375: (main.cpp:24) Ram usage level: 4
-INFO  - 1489698375: (BlockUtils.cpp:907) blkfile dir: /Users/droark/Library/Application Support/Bitcoin/testnet3/blocks
-INFO  - 1489698375: (BlockUtils.cpp:908) lmdb dir: /Users/droark/Library/Application Support/Armory/testnet3/databases
-INFO  - 1489698375: (lmdb_wrapper.cpp:388) Opening databases...
-INFO  -- ERROR 1489698375- : (BitcoinP2P.cpp:937) Connected to Bitcoin node
1489698375: (nodeRPC.cpp:150) unexpected cookie file content
-ERROR - 1489698375: (nodeRPC.cpp:150) unexpected cookie file content
-INFO  - 1489698375: (BlockUtils.cpp:1091) Executing: doInitialSyncOnLoad
-INFO  - 1489698375: (DatabaseBuilder.cpp:169) Reading headers from db
-INFO  - 1489698375: (BDM_Server.cpp:957) registered bdv: af128699cd6352d8c225
-INFO  - 1489698387: (DatabaseBuilder.cpp:208) Found 1093946 headers in db
-WARN  - 1489698390: (BDM_supportClasses.cpp:1741) running 0 zc parser threads
-INFO  - 1489698392: (DatabaseBuilder.cpp:51) updating HEADERS db
-INFO  - 1489698392: (DatabaseBuilder.cpp:477) Found next block after skipping 4610bytes
-INFO  - 1489698393: (DatabaseBuilder.cpp:268) parsed block file #73
-DEBUG - 1489698393: (Blockchain.cpp:242) Organizing chain 
-INFO  - 1489698393: (DatabaseBuilder.cpp:56) updated HEADERS db in 0.582443s
-INFO  - 1489698393: (DatabaseBuilder.cpp:106) scanning new blocks from #1093925 to #1093925
-INFO  - 1489698393: (BlockchainScanner.cpp:650) scanned from height #1093925 to #1093925
-INFO  - 1489698393: (DatabaseBuilder.cpp:156) scanned new blocks in 0.044219s
-INFO  - 1489698393: (DatabaseBuilder.cpp:160) init db in 13.0463s
-INFO  - 1489698393: (BlockUtils.cpp:1208) Enabling zero-conf tracking 
-INFO  - 1489698393: (BDM_supportClasses.cpp:372) Starting address registration process
--------ERROR ERROR ERROR ERROR ERROR ERROR ERROR ERROR - - - - - - - - 14896983931489698393148969839314896983931489698393148969839314896983931489698393: : : : : : : : ((((((((BlockchainScanner.cppBlockchainScanner.cppBlockchainScanner.cppBlockchainScanner.cppBlockchainScanner.cppBlockchainScanner.cppBlockchainScanner.cppBlockchainScanner.cpp::::::::271271271271271271271271) ) ) ) ) ) ) ) raw data does not match expected block hashraw data does not match expected block hashraw data does not match expected block hashraw data does not match expected block hashraw data does not match expected block hashraw data does not match expected block hashraw data does not match expected block hashraw data does not match expected block hash

[goatpig]

cookie error means you aren't running your node with server=1. Maybe that has something to do with the whole process? That's the only new code somehow related to this (it uses the same notification pipeline).

[Carlton Banks]

Yep, exactly the symptoms I experienced (cookie error) before achow101 set it straight. Needs to be in the 0.96 release notes, and if possible written to bitcoin.conf automatically (IMO)

[goatpig]

Yep, exactly the symptoms I experienced (cookie error) before achow101 set it straight. Needs to be in the 0.96 release notes, and if possible written to bitcoin.conf automatically (IMO)

Code just needs fixed to not nuke everything else on failure. As for the automated bitcoin.conf modification, that introduces the credential issues from before that I don't want to deal with at all.

I don't mind that the RPC may fail to setup, I mind that it takes the entire ship on its way down.

[droark]

Yep, exactly the symptoms I experienced (cookie error) before achow101 set it straight. Needs to be in the 0.96 release notes, and if possible written to bitcoin.conf automatically (IMO)

Agreed (although a bitcoin.conf auto-write worries me). It didn't make my main problem go away but it did fix that particular error.

[Carlton Banks]

Hmmm, can't help but agree. I say it though as I'm anticipating constant creation of new & potentially long threads where this issue is troubleshooted, until round about the end of time itself

[droark]

cookie error means you aren't running your node with server=1. Maybe that has something to do with the whole process? That's the only new code somehow related to this (it uses the same notification pipeline).

Gaaaaaaah. I thought I had deleted the DB earlier and started from scratch. I hadn't. Once I did, Armory scanned everything just fine.

Just curious, is ArmoryDB supposed to take awhile to shut down? It takes something like 20-30 seconds to shut down on my machine, even though the CPU isn't active for most of that time. Of course, it's an improvement over 0.95, where it never shut down, period.

[Carlton Banks]

Have you guys tested the compressed P2SH keys on testnet? Any problems? I'd quite like to begin using them, it seems incredibly anti-social to continue to use uncompressed keys if their implementation is considered safe to use now.

Both nested script types have been tested on the testnet. I cross compiled 0.96 for my RPi yesterday and will test the nested compressed key script on the mainnet with my own coins sometimes before I post the first testing builds.

Any news on this?

[goatpig]

It takes something like 20-30 seconds to shut down on my machine, even though the CPU isn't active for most of that time. Of course, it's an improvement over 0.95, where it never shut down, period.

This is still (imo) the FCGI lib taking a while to shutdown. Again, you can try to profile that stuff. Here is a list of all the threads that need end for the process to exit gracefully:

Code:

1) client callback thread

https://github.com/goatpig/BitcoinArmory/blob/dev/cppForSwig/BDM_Server.cpp#L1617

2) client control thread

https://github.com/goatpig/BitcoinArmory/blob/dev/cppForSwig/BDM_Server.cpp#L1427

3) FCGI loop

https://github.com/goatpig/BitcoinArmory/blob/dev/cppForSwig/BDM_Server.cpp#L1155

4) server control thread

https://github.com/goatpig/BitcoinArmory/blob/dev/cppForSwig/BDM_Server.cpp#L991

5) server garbage collector

https://github.com/goatpig/BitcoinArmory/blob/dev/cppForSwig/BDM_Server.cpp#L1042

6) zero conf process threads

https://github.com/goatpig/BitcoinArmory/blob/dev/cppForSwig/BDM_supportClasses.cpp#L1741

7) zc parser control thread

https://github.com/goatpig/BitcoinArmory/blob/dev/cppForSwig/BDM_supportClasses.cpp#L1001

8 ) node P2P connect loop

https://github.com/goatpig/BitcoinArmory/blob/dev/cppForSwig/BitcoinP2P.cpp#L868

9) DB control thread

https://github.com/goatpig/BitcoinArmory/blob/dev/cppForSwig/BDM_mainthread.cpp#L128

10) main thread

https://github.com/goatpig/BitcoinArmory/blob/dev/cppForSwig/main.cpp#L12

This list assumes you got out of the initial scan. Otherwise, it gets a lot more complicated. Just exiting the main thread should be enough to kill the process, although that alone won't guarantee a gracious shutdown. The most important thing to do during shutdown is to properly close the LMDB objects.

Any news on this?

Sorry, busy IRL, will get to it sometimes before the Sunday.

[Carlton Banks]

Sorry, busy IRL, will get to it sometimes before the Sunday.

No real rush, like I said, I'd just prefer to start using compressed keys for everyone's sake. On that note, will compressed keys become the default key chain in the new wallets? And nested P2WPKH subsequently? I'm hardly expecting a no, I'm just wondering if you think that might cause an issue I'm not seeing.


A mild Bug in 0.96


The scroll bar magic (that traverses super long balance lists) becomes stuck if I try to get beyond a certain proportion of the balance entries.

I'm just clicking, holding the click, and dragging the bar all the way to the base of the bar's range. Releasing the click and re-dragging to the base of the bar gets me to the actual definitively oldest tx, but trying to do the same trick on the way back to the top doesn't work; the magic itself begins to loop to the sticking point, as if that's the most recent transaction. Simply using the 'Goto' button's 'Top' hyperlink style thingy remedies this bottom->top sticking.

Edit - A separate issue is possibly triggered by this; after provoking this bug, when a new block comes in, Armory sends the tx entry highlight/selection bar ~ 60 tx entries lower down the list, where it would ordinarily remain scrolled to the top and de-highlight the entry that was highlighted before the block arrived. If that makes sense!



The server=1/RPC cookie issue

If the absence of server=1 can be detected, why not get Armory to produce an Error dialog box to tell the user how to deal with the issue? As I said, there'll be infinity threads about this if it's not handled at the software end somehow