v0.15.1 on Fedora 23 just added addnode=nkf5e6b7pl4jfd4a.onion in bitcoin.conf and loading is stuck on the splash screen with "Done loading" message for many minutes. Regular activity in the debug log but, I am getting new tip's pretty early on without any version messages first. Added node is not showing in the GUI once loading is eventually finished (I suppose it is down?)
bitcoin.conf
uacomment={redacted}
prune=10239
banscore=10
bantime=31536000
maxmempool=900
mempoolexpiry=2160
proxy=127.0.0.1:9050
listen=1
bind=127.0.0.1
addnode=nkf5e6b7pl4jfd4a.onion
debug.log
2018-02-05 12:52:01 InitParameterInteraction: parameter interaction: -proxy set -> setting -upnp=0
2018-02-05 12:52:01 InitParameterInteraction: parameter interaction: -proxy set -> setting -discover=0
2018-02-05 12:52:01 InitParameterInteraction: parameter interaction: -whitelistforcerelay=1 -> setting -whitelistrelay=1
2018-02-05 12:52:01 Assuming ancestors of block 0000000000000000003b9ce759c2a087d52abc4266f8f4ebd6d768b89defa50a have valid signatures.
2018-02-05 12:52:01 Setting nMinimumChainWork=000000000000000000000000000000000000000000723d3581fe1bd55373540a
2018-02-05 12:52:01 Prune configured to target 10239MiB on disk for block and undo files.
2018-02-05 12:52:01 Using the 'standard' SHA256 implementation
2018-02-05 12:52:01 Using RdRand as an additional entropy source
2018-02-05 12:52:01 Default data directory /{default}/.bitcoin
2018-02-05 12:52:01 Using data directory /{default}/.bitcoin
2018-02-05 12:52:01 Using config file /{default}/.bitcoin/bitcoin.conf
2018-02-05 12:52:01 Using at most 125 automatic connections (1024 file descriptors available)
2018-02-05 12:52:01 Using 16 MiB out of 32/2 requested for signature cache, able to store 524288 elements
2018-02-05 12:52:01 Using 16 MiB out of 32/2 requested for script execution cache, able to store 524288 elements
2018-02-05 12:52:01 Using 2 threads for script verification
2018-02-05 12:52:01 scheduler thread start
2018-02-05 12:52:01 init message: Verifying wallet(s)...
2018-02-05 12:52:01 Using BerkeleyDB version Berkeley DB 4.8.30: (April 9, 2010)
2018-02-05 12:52:01 Using wallet wallet.dat
2018-02-05 12:52:01 CDBEnv::Open: LogDir=/{default}/.bitcoin/database ErrorFile=/{default}/.bitcoin/db.log
2018-02-05 12:52:02 Cache configuration:
2018-02-05 12:52:02 * Using 2.0MiB for block index database
2018-02-05 12:52:02 * Using 8.0MiB for chain state database
2018-02-05 12:52:02 * Using 440.0MiB for in-memory UTXO set (plus up to 858.3MiB of unused mempool space)
2018-02-05 12:52:02 init message: Loading block index...
2018-02-05 12:52:02 Opening LevelDB in /{default}/.bitcoin/blocks/index
2018-02-05 12:52:02 Opened LevelDB successfully
2018-02-05 12:52:02 Using obfuscation key for /{default}/.bitcoin/blocks/index: 0000000000000000
2018-02-05 12:52:09 LoadBlockIndexDB: last block file = 1167
2018-02-05 12:52:09 LoadBlockIndexDB: last block file info: CBlockFileInfo(blocks=55, size=61790110, heights=507638...507772, time=2018-02-04...2018-02-05)
2018-02-05 12:52:09 Checking all blk files are present...
2018-02-05 12:52:09 LoadBlockIndexDB(): Block files have previously been pruned
2018-02-05 12:52:09 LoadBlockIndexDB: transaction index disabled
2018-02-05 12:52:09 Opening LevelDB in /{default}/.bitcoin/chainstate
2018-02-05 12:52:09 Opened LevelDB successfully
2018-02-05 12:52:09 Using obfuscation key for /{default}/.bitcoin/chainstate: {redacted}
2018-02-05 12:52:09 Loaded best chain: hashBestChain=000000000000000000463e98ae2fa6cf30840d8774f80e85e70e819bf731dfba height=507764 date=2018-02-05 10:33:50 progress=0.999914
2018-02-05 12:52:09 init message: Rewinding blocks...
2018-02-05 12:52:11 init message: Verifying blocks...
2018-02-05 12:52:11 Verifying last 6 blocks at level 3
2018-02-05 12:52:11 [0%]...[16%]...[33%]...[50%]...[66%]...[83%]...[99%]...[DONE].
2018-02-05 12:52:26 No coin database inconsistencies in last 7 blocks (7254 transactions)
2018-02-05 12:52:26 block index 24927ms
2018-02-05 12:52:27 init message: Loading wallet...
2018-02-05 12:52:27 nFileVersion = 150100
2018-02-05 12:52:27 Keys: 0 plaintext, 4014 encrypted, 4014 w/ metadata, 4014 total
2018-02-05 12:52:27 wallet 298ms
2018-02-05 12:52:27 setKeyPool.size() = 1997
2018-02-05 12:52:27 mapWallet.size() = 13
2018-02-05 12:52:27 mapAddressBook.size() = 14
2018-02-05 12:52:27 Unsetting NODE_NETWORK on prune mode
2018-02-05 12:52:27 init message: Pruning blockstore...
2018-02-05 12:52:27 mapBlockIndex.size() = 507779
2018-02-05 12:52:27 nBestHeight = 507764
2018-02-05 12:52:27 torcontrol thread start
2018-02-05 12:52:27 Bound to 127.0.0.1:8333
2018-02-05 12:52:27 init message: Loading P2P addresses...
2018-02-05 12:52:27 tor: Got service ID {onion}, advertising service {onion}.onion:8333
2018-02-05 12:52:27 AddLocal({onion}.onion:8333,4)
2018-02-05 12:52:28 Loaded 66259 addresses from peers.dat 1377ms
2018-02-05 12:52:28 init message: Loading banlist...
2018-02-05 12:52:28 init message: Starting network threads...
2018-02-05 12:52:28 init message: Done loading
2018-02-05 12:52:28 net thread start
2018-02-05 12:52:28 dnsseed thread start
2018-02-05 12:52:28 addcon thread start
2018-02-05 12:52:28 opencon thread start
2018-02-05 12:52:28 msghand thread start
2018-02-05 12:52:39 Loading addresses from DNS seeds (could take a while)
2018-02-05 12:52:39 0 addresses found from DNS seeds
2018-02-05 12:52:39 dnsseed thread exit
2018-02-05 12:53:31 UpdateTip: new best=00000000000000000044024fe59374ee53b90ffeec41e7dec6a67883023ffd84 height=507765 version=0x20000000 log2_work=88.048836 tx=297655998 date='2018-02-05 10:44:25' progress=0.999919 cache=1.3MiB(9921txo)
2018-02-05 12:54:27 UpdateTip: new best=00000000000000000063e2d8531fec221ba1cdfd0aa875119c10a871f19aab03 height=507766 version=0x20000000 log2_work=88.048886 tx=297657797 date='2018-02-05 11:01:35' progress=0.999929 cache=2.5MiB(18814txo)
2018-02-05 12:55:50 UpdateTip: new best=0000000000000000006ab064f21d83ec80d68f8e70bb3a5f3f0dd338b31b822f height=507767 version=0x20000000 log2_work=88.048937 tx=297659421 date='2018-02-05 11:08:42' progress=0.999933 cache=3.5MiB(26912txo)
2018-02-05 12:58:55 UpdateTip: new best=000000000000000000089c6abc2ee3a2d95c990c30f6f73ed43ced7619d02250 height=507768 version=0x20000000 log2_work=88.048987 tx=297659962 date='2018-02-05 11:12:09' progress=0.999933 cache=4.6MiB(33664txo)
2018-02-05 12:58:56 socket send error Broken pipe (32)
2018-02-05 12:58:56 socket send error Broken pipe (32)
2018-02-05 12:58:56 GUI: Platform customization: "other"
2018-02-05 12:58:58 GUI: PaymentServer::LoadRootCAs: Loaded 161 root certificates
2018-02-05 12:59:25 UpdateTip: new best=0000000000000000002bfbc6a296478cd3f285a2012aa34a78b41f2d01040460 height=507769 version=0x20000000 log2_work=88.049037 tx=297660426 date='2018-02-05 11:15:00' progress=0.999935 cache=4.8MiB(35610txo)
2018-02-05 13:02:28 UpdateTip: new best=0000000000000000003131315e2b122ea05c0bfe40aba2492767a9a38c20f3d6 height=507770 version=0x20000000 log2_work=88.049088 tx=297661080 date='2018-02-05 11:18:26' progress=0.999935 cache=5.5MiB(40979txo)
2018-02-05 13:02:29 socket send error Broken pipe (32)
2018-02-05 13:05:15 Pre-allocating up to position 0x800000 in rev01167.dat
2018-02-05 13:05:16 Prune: UnlinkPrunedFiles deleted blk/rev (01097)
2018-02-05 13:05:16 UpdateTip: new best=000000000000000000390e0c018ae0c4575417461045d782537aa356e703218d height=507771 version=0x20000000 log2_work=88.049138 tx=297661203 date='2018-02-05 11:18:30' progress=0.999933 cache=0.5MiB(0txo)
2018-02-05 13:05:16 socket send error Broken pipe (32)
2018-02-05 13:05:16 socket send error Broken pipe (32)
2018-02-05 13:05:17 Socks5() connect to 2001:0:9d38:953c:249f:5580:20b6:5fbb:8333 failed: connection not allowed
2018-02-05 13:06:27 UpdateTip: new best=0000000000000000001f6cbdfcd5e332439b4eb87a346e23129639242d7e6ffe height=507772 version=0x20000000 log2_work=88.049188 tx=297662713 date='2018-02-05 11:32:45' progress=0.999941 cache=1.6MiB(9438txo)
2018-02-05 13:06:27 Leaving InitialBlockDownload (latching to false)
2018-02-05 13:06:28 Socks5() connect to 2001:0:9d38:90d7:20fe:1526:47e9:88cd:8333 failed: connection not allowed
2018-02-05 13:06:33 receive version message: /Satoshi:0.15.1/: version 70015, blocks=507780, us=77.247.181.162:40332, peer=6
2018-02-05 13:06:39 receive version message: /Satoshi:0.15.1/: version 70015, blocks=507780, us=88.99.191.203:8333, peer=7
2018-02-05 13:06:43 receive version message: /Satoshi:0.15.1/: version 70015, blocks=507780, us=[::]:0, peer=8
2018-02-05 13:06:48 receive version message: /Satoshi:0.15.1/: version 70015, blocks=507780, us=192.36.27.4:26322, peer=9
2018-02-05 13:06:55 ProcessMessages(version, 113 bytes) FAILED peer=10
2018-02-05 13:08:12 UpdateTip: new best=00000000000000000051586a1554ead0413cdc60438b5797c1c9294fa11637bf height=507773 version=0x20000000 log2_work=88.049239 tx=297664837 date='2018-02-05 11:54:00' progress=0.999954 cache=3.7MiB(26032txo)
2018-02-05 13:08:17 socket send error Broken pipe (32)
2018-02-05 13:08:22 version handshake timeout from 11
2018-02-05 13:08:32 version handshake timeout from 12
2018-02-05 13:08:40 Socks5() connect to 188.132.169.88:8333 failed: connection refused
2018-02-05 13:08:41 Socks5() connect to 2001:0:9d38:6ab8:c34:7d5d:c343:2a4b:8333 failed: connection not allowed
2018-02-05 13:09:16 UpdateTip: new best=0000000000000000003fca00e547d6f32341d3c1627c627b8c005345d0196b97 height=507774 version=0x20000000 log2_work=88.049289 tx=297665525 date='2018-02-05 11:58:27' progress=0.999956 cache=4.6MiB(33907txo)
I thought socket send error Broken pipe (32) just means that Tor route is broken for a particular path and needs to be re-routed?
Is this behaviour normal? New tips even before version messages? Long wait?
Also tried adding four onion nodes with addnode= and loading was accomplished in the usual timeframe, this time with version messages before any update tip messages.
