Trasaction broadcast bug

[hodlwave]

Description

After taking an offer and funding my Bisq wallet, neither the Multisig deposit nor the Taker and tx fee transactions are broadcast to the blockchain making it impossible for the trade to progress. To claw back the funds, I have to Resync the SPV chain, at which point Bisq recognizes that the deposit Tx is missing and allows me to move the trade to failed trades.

Version

v1.3.7

Steps to reproduce

Explained above

Expected behaviour

Both Multisig deposit and Taker and tx fee should be broadcast.

Actual behaviour

Neither txs are broadcast.

Screenshots

Device or machine

Running in a modified version of https://github.com/leshik/bisq-docker (so via Docker).

Additional info

I think this is related to #4521 (comment). At the time when the Txs are broadcast, I see the following error log:

} TxBroadcastException{
     txId='null'
} bisq.core.btc.exceptions.TxBroadcastTimeoutException: The transaction was not broadcasted in 5 seconds. txId=...

I'm not familiar with the Bisq codebase, but if there is a known viable solution to this problem, I'd be happy to help implement it as Bisq is currently unusable for me because of this issue.

[boring-cyborg]

Thanks for opening your first issue here!

Be sure to follow the issue template. Your issue will be reviewed by a maintainer and labeled for further action.

[ghost]

The transaction was not broadcasted in 5 seconds means that it took longer than 5 seconds for the transaction to propagate to the required number of nodes. (This generally happens a lot, e.g. 86 times in my bisq log). That's why I asked @chimp1984 if it could be addressed. Typically you'll see more information surrounding that message, for example:

INFO  o.b.c.TransactionBroadcast: broadcastTransaction: SEEN_PEERS:  TX [...] seen by 1 peers 
WARN  b.c.b.w.TxBroadcaster: Broadcast of tx [...] not completed after 5 sec. 
WARN  b.c.b.w.TxBroadcaster: TxBroadcaster.onTimeout called: TxBroadcastTimeoutException{
INFO  o.b.c.TransactionBroadcast: broadcastTransaction: SEEN_PEERS:  TX [...] seen by 2 peers 
INFO  o.b.c.TransactionBroadcast: broadcastTransaction: [...] complete 
WARN  b.c.b.w.TxBroadcaster: We got an onSuccess callback for a broadcast which already triggered the timeout. txId=[...]

Could you dig around in your log file and see what was the end result similar to above? And perhaps provide a snippet if there is some different message other than "complete" / "success" / "seen by 2 peers".

[chimp1984]

@hodlwave Do you run a local btc node?
There is a known issue that BSQ txs cause that timeout but in fact they get broadcasted. We need to fix that on BitcoinJ level. Not broadcast at all is not a common issue and likely related to your environment setup. Bisq running on Qubes for instance causes lots of problems. But I think there is a real problem in the code which just gets more problematic in certain conditions.

If you have time you could certainly help to investigate that issues, specially if you are able to reproduce that issue on regtest. You dont need lot of Bisq code base knowledge, the TxBroadcast class calls APIs on the BitcoinJ and there is likely the problem. But maybe worth to wait a few days until BitcoinJ 0.15 is merged. That comes with many changes and maybe the bug got fixed already there.
@oscarguindzberg Are you aware of any change in 0.15 which is related to tx broadcasting (specially the case that 2 wallets - btc and bsq - are involved)?

[oscarguindzberg]

Maybe related: #2639

@chimp1984 I don't remember any tx broadcasting bugfix in bitcoinj 0.15, but bitcoinj 0.15 is a big release and there were many changes, so I might have missed it.

bitcoinj is not fully tested to work with multiple wallets. I did some research on that back in 2019.
Some related info:
- bisq-network/bitcoinj#18
- bitcoinj mailing list - Design doc: separating confidence out from transaction objects https://groups.google.com/forum/#!topic/bitcoinj/KsEWEnSdbN0
- bitcoinj/bitcoinj#877
- bitcoinj/bitcoinj#1553

[chimp1984]

@oscarguindzberg Seems on the BitcoinJ side there have been not even a comment or feedback to your suggestion. As we have sometimes issues with not broadcast txs I think we should put this issue on our high prio list and hope we can find a way that @oscarguindzberg can work on that after segwit and that we manage to get funding for that work.

[hodlwave]

@jmacxx, here's my (blinded) logfile with more context around the TxBroadcastTimeoutException. Nothing particularly jumps out at me (maybe Waiting for 4 peers required for broadcast, we have 3?).

[JavaFX Application Thread] INFO  b.c.t.TaskRunner: Run task: BuyerAsTakerCreatesDepositTxInputs 
[JavaFX Application Thread] INFO  b.c.t.TaskRunner: Run task: TakerSendInputsForDepositTxRequest 
[JavaFX Application Thread] INFO  b.c.t.p.t.t.TakerSendInputsForDepositTxRequest: Send InputsForDepositTxRequest with offerId ... and uid ... to peer ...
[JavaFX Application Thread] INFO  b.c.o.a.OfferAvailabilityProtocol: AckMessage for OfferAvailabilityResponse arrived at makersNodeAddress .... offerId=...
[JavaFX Application Thread] INFO  b.c.t.p.BuyerAsTakerProtocol: Received InputsForDepositTxResponse from ... with tradeId ... and uid ...
[JavaFX Application Thread] INFO  b.c.t.TaskRunner: Run task: TakerProcessesInputsForDepositTxResponse 
[JavaFX Application Thread] INFO  b.c.t.p.t.t.TakerProcessesInputsForDepositTxResponse: lockTime=..., delay=-2880
[JavaFX Application Thread] INFO  b.c.trade.Trade: Set new state at BuyerAsTakerTrade (id=...): TAKER_RECEIVED_PUBLISH_DEPOSIT_TX_REQUEST 
[JavaFX Application Thread] INFO  b.c.t.TaskRunner: Run task: ApplyFilter 
[JavaFX Application Thread] INFO  b.c.t.TaskRunner: Run task: TakerVerifyMakerAccount 
[JavaFX Application Thread] INFO  b.c.t.TaskRunner: Run task: VerifyPeersAccountAgeWitness 
[JavaFX Application Thread] INFO  b.c.t.TaskRunner: Run task: TakerVerifyMakerFeePayment 
[JavaFX Application Thread] INFO  b.c.t.TaskRunner: Run task: TakerVerifyAndSignContract 
[JavaFX Application Thread] INFO  b.c.t.TaskRunner: Run task: TakerPublishFeeTx 
[JavaFX Application Thread] INFO  o.b.w.Wallet: commitTx of ...
[JavaFX Application Thread] INFO  o.b.w.Wallet:   marked ...:1 as spent by ... 
[JavaFX Application Thread] INFO  o.b.w.Wallet:   ... prevtx <-unspent ->spent 
[JavaFX Application Thread] INFO  o.b.w.Wallet: ->pending: ...
[JavaFX Application Thread] INFO  o.b.w.Wallet: Estimated balance is now: ... BTC 
[JavaFX Application Thread] INFO  o.b.w.WalletFiles: Saving wallet; last seen block is height ..., date ..., hash ...
[JavaFX Application Thread] INFO  o.b.w.WalletFiles: Save completed in 5.595 ms 
[JavaFX Application Thread] INFO  o.b.c.TransactionBroadcast: Waiting for 4 peers required for broadcast, we have 3 ... 
[JavaFX Application Thread] INFO  b.c.t.p.TradeProtocol: Received AckMessage for InputsForDepositTxRequest from ... with tradeId ... and uid ...
[PeerGroup Thread] WARN  o.b.n.BlockingClient: Attempted to write to a closed socket. 
[PeerGroup Thread] WARN  o.b.n.BlockingClient: Attempted to write to a closed socket. 
[JavaFX Application Thread] WARN  b.c.b.w.TxBroadcaster: Broadcast of tx ... not completed after 5 sec. 
[JavaFX Application Thread] WARN  b.c.b.w.TxBroadcaster: TxBroadcaster.onTimeout called: TxBroadcastTimeoutException{
     localTx=  ...
  updated: ...
     in   PUSHDATA(72)[...] PUSHDATA(33)[...] ... BTC (...)
          outpoint:...:1 hash160:...
     out  HASH160 PUSHDATA(20)[...] EQUAL ... BTC (...) ScriptPubKey: ... Address:...
     out  DUP HASH160 PUSHDATA(20)[...] EQUALVERIFY CHECKSIG ... BTC (...) ScriptPubKey: ... Address:...
     fee  ... BTC for 224 bytes (... Satoshi/Byte)
     prps USER_PAYMENT
,
     delay=5
} TxBroadcastException{
     txId='null'
} bisq.core.btc.exceptions.TxBroadcastTimeoutException: The transaction was not broadcasted in 5 seconds. txId=... 
[JavaFX Application Thread] INFO  b.c.trade.Trade: Set new state at BuyerAsTakerTrade (id=...): TAKER_PUBLISHED_TAKER_FEE_TX 
[JavaFX Application Thread] INFO  b.c.t.TaskRunner: Run task: BuyerAsTakerSignsDepositTx 
[JavaFX Application Thread] INFO  b.c.b.w.WalletService: 
makersDepositTx:
  ...
     in   <no scriptSig>
          outpoint:...
     in   <no scriptSig>
          outpoint:...:1
     out  HASH160 PUSHDATA(20)[...] EQUAL ... BTC (...) ... Address:...
     out  RETURN PUSHDATA(32)[...] 0.00 BTC (0) ScriptPubKey: ... Address:[exception: Cannot cast this script to a pay-to-address type]
     prps UNKNOWN
 
[JavaFX Application Thread] INFO  b.c.b.w.WalletService: 
takerSignsDepositTx:
  ...
     in   PUSHDATA(71)[...] PUSHDATA(33)[...] ... BTC (...)
          outpoint:...:1 hash160:hash160:
     in   <no scriptSig> ... BTC (...)
          outpoint:...:1 hash160:...
     out  HASH160 PUSHDATA(20)[...] EQUAL ... BTC (...) ScriptPubKey: ... Address:...
     out  RETURN PUSHDATA(32)[...] 0.00 BTC (0) ScriptPubKey: ... Address:[exception: Cannot cast this script to a pay-to-address type]
     fee  ... BTC for 273 bytes (... Satoshi/Byte)
     prps UNKNOWN
 
[JavaFX Application Thread] INFO  b.c.t.p.t.b.BuyerAsTakerSendsDepositTxMessage: Send DepositTxMessage to peer .... tradeId=..., uid=...
[JavaFX Application Thread] INFO  b.c.t.p.t.b.BuyerAsTakerSendsDepositTxMessage: DepositTxMessage arrived at peer .... tradeId=..., uid=... 
[JavaFX Application Thread] INFO  b.c.t.p.TradeProtocol: Send AckMessage for InputsForDepositTxResponse to peer .... tradeId=..., sourceUid= 
[JavaFX Application Thread] INFO  b.c.t.p.TradeProtocol: AckMessage for InputsForDepositTxResponse arrived at peer .... tradeId=..., sourceUid= 
[JavaFX Application Thread] INFO  b.c.t.p.BuyerAsTakerProtocol: Received DelayedPayoutTxSignatureRequest from ... with tradeId ... and uid ...
[JavaFX Application Thread] INFO  b.c.t.TaskRunner: Run task: BuyerVerifiesPreparedDelayedPayoutTx 

@chimp1984
Bisq is not connected to a local Bitcoin node. My environment could well be the issue as I'm running v.1.3.7 in an ad hoc docker container (https://github.com/leshik/bisq-docker), although it seems kind of odd that only one type of network communication would fail since all data is going over Tor. I will try to reproduce on regtest if I get some time.

[chimp1984]

I am pretty sure its related to what Oscar posted above. Its the tx confidence table issue....

[stale]

This issue has been automatically marked as stale because it has not had recent activity. It will be closed if no further activity occurs. Thank you for your contributions.

[ghost]

Since PR #4943 has been implemented, has it resolved this issue?

[chimp1984]

I think it can be closed. There is another open bug in BitcoinJ but there is a dedicated issue for that.