DAO: Submitting proposal, bond, or asset fee took 30 seconds without indicating anything was happening

[devinbileck]

While attempting to lock up funds for a bonded reputation, it took about 30 seconds from the time I submitted until I got a confirmation prompt. During that time there was no indication anything was happening.

I saw this in the debug log:

Dec-06 14:37:33.420 [JavaFX Application Thread] WARN  b.c.btc.wallet.TxBroadcaster: Broadcast of tx 9c8d0c8b16230c22f516ba248459c734d64d3ccc99ed619f77303f603ca996fa not completed after 30 sec. 
Dec-06 14:37:33.422 [JavaFX Application Thread] WARN  b.c.btc.wallet.TxBroadcaster: TxBroadcaster.onTimeout called: TxBroadcastTimeoutException{
     localTx=  9c8d0c8b16230c22f516ba248459c734d64d3ccc99ed619f77303f603ca996fa
  updated: 2018-12-06T22:37:03Z
     in   PUSHDATA(72)[3045022100c0be01e1143bbf92dfba621b944983286e217169a68c9622fce31bdf853508e302206fbbca49f56a0ceef6823d05f819f110103e428a0e897942bea361585ba7951801] PUSHDATA(33)[02ed10fad91d6b06b1b6d9e077e8e2a603064bf3124fd166d7dd9ac72d75fc4ddb] 0.00066667 BTC (66667)
          outpoint:23627e8eb666f89a1ffe75b4dd620c35c5132bd9a774778de9dde9520b038157:0 hash160:e2a3353c785785a649d1a0010101beeed62b9271
     in   PUSHDATA(72)[3045022100d07bb58aadbde50aa7577599f9618bf300aea7bb0948487df04203ab03cb8f2e02200d9184024d100c2135f3ea17fb980d904957625890394f3bc1d764bd14ab935c01] PUSHDATA(33)[034f6895252c5f6d15a53f29a964e14e64576acb3c6869b7cb33de5f4307269ffc] 0.04348763 BTC (4348763)
          outpoint:1451c0f82f6f463b718a71cd09f3ddb945877150c1030cf7500989d658604d3d:2 hash160:c415f84f0e8f92d30e0470e6f45a386bb98133d6
     out  DUP HASH160 PUSHDATA(20)[9610105809198ff4efc23ee2a2daa068775d917a] EQUALVERIFY CHECKSIG 0.0001 BTC (10000) ScriptPubKey: 76a9149610105809198ff4efc23ee2a2daa068775d917a88ac Address:muCQtxs6eZmwEFMc9ydLXTEhQHwefKMFrJ 
     out  DUP HASH160 PUSHDATA(20)[9610105809198ff4efc23ee2a2daa068775d917a] EQUALVERIFY CHECKSIG 0.00056667 BTC (56667) ScriptPubKey: 76a9149610105809198ff4efc23ee2a2daa068775d917a88ac Address:muCQtxs6eZmwEFMc9ydLXTEhQHwefKMFrJ 
     out  DUP HASH160 PUSHDATA(20)[4b237196c2dbeb0f640bf3dfb21998a6a024f73e] EQUALVERIFY CHECKSIG 0.04337973 BTC (4337973) ScriptPubKey: 76a9144b237196c2dbeb0f640bf3dfb21998a6a024f73e88ac Address:mnNFS7X7XpRM67G6dbzCn3PcPbKMMPn14n 
     out  RETURN PUSHDATA(25)[15010200018e41fca82ae8d13d5921458f74c33c1fa47e55ba] 0.00 BTC (0) ScriptPubKey: 6a1915010200018e41fca82ae8d13d5921458f74c33c1fa47e55ba Address:[exception: Cannot cast this script to a pay-to-address type]
     fee  0.0001079 BTC for 444 bytes (24 Satoshi/Byte)
     prps USER_PAYMENT
,
     delay=30
} TxBroadcastException{
     txId='null'
} bisq.core.btc.exceptions.TxBroadcastTimeoutException: The transaction was not broadcasted in 30seconds. txId=9c8d0c8b16230c22f516ba248459c734d64d3ccc99ed619f77303f603ca996fa 
We optimistically assume that the tx broadcast succeeds later and call onSuccess on the callback handler. This behaviour carries less potential problems than if we would trigger a failure (e.g. which would cause a failed create offer attempt of failed take offer attempt).
We have no guarantee how long it will take to get the information that sufficiently many BTC nodes have reported back to BitcoinJ that the tx is in their mempool.
In normal situations that's very fast but in some cases it can take minutes (mostly related to Tor connection issues). So if we just go on in the application logic and treat it as successful and the tx will be broadcast successfully later all is fine.
If it will fail to get broadcast, it will lead to a failure state, the same as if we would trigger a failure due the timeout.So we can assume that this behaviour will lead to less problems as otherwise.
Long term we should implement better monitoring for Tor and the provided Bitcoin nodes to find out why those delays happen and add some rollback behaviour to the app state in case the tx will never get broadcast. 

[ManfredKarrer]

Yes, seems the tx broadcast did not succeed in time. Did u test with a local BTC core node or with public testnet? Was your connection stable?

[devinbileck]

It was on testnet and yes my connection is stable. Looks like it did eventually go through because I see it was locked up.
But in any case, I assume we should have some kind of progress indicator.

[ManfredKarrer]

Yes agree. Those tx broadcast issues are an open issue but have become more rare over the last releases.

[devinbileck]

Note, it is not just explicitly for bonding. I have also encountered this when submitting a proposal and asset listing fee.

[ManfredKarrer]

This is already fixed.

[devinbileck]

@ManfredKarrer I am still encountering this issue on testnet running against master.
bisq.log

[ManfredKarrer]

@ben-kaufman Could u have a look into that. The TxBroadcaster class id doing the publishing and there is a timeout. You can simulate the timout behaviour by avoiding there temporarily to send out the tx. The UI should show a progress bar. It was added already when making a proposal, but seems it is missing at the other areas where we publich a tx (blind vote, asset fee, proof of burn, bonds)