BIP78 PayJoin to .onion fails, fallback tx is not broadcast after timeout

[MaxHillebrand]

@openoms and I are testing cross-wallet PayJoin functionality.

Setup

Openoms is sending from a non-torified JoinMarket wallet master branch.
I am receiving in Wasabi Wallet to an ephemeral hidden service. [it's a reckless feature, not planned to be released, this is mainly to test JM, not WW.]

The URI got properly decoded, but the hostname lookup failed with no result.

Problem

I would say, that in such a case, the Joinmarket wallet should fall back to the non-PayJoin transaction, and broadcast this directly.

Joinmarket Logs

$ python sendpayment.py -m0 test.jmdat "bitcoin:tb1qut6yaj9lvt5g8hndgjw07mpngpxdrd25fz5clv?amount=0.00100000&pj=http://l3prea6fft7lwp3lz654nrrglljdrrzoovae7uyqkelnw73i5cvdu5qd.onion:37129"
User data location: /home/joinmarket/.joinmarket/
Attempting to pay via payjoin.
2020-07-13 11:35:25,647 [INFO]  Using this min relay fee as tx fee floor: 1000 sat/vkB (1.0 sat/vB)
2020-07-13 11:35:25,647 [INFO]  starting sendpayment
Enter wallet decryption passphrase: 
2020-07-13 11:35:28,016 [INFO]  Estimated miner/tx fees for this coinjoin amount: 0.3%
2020-07-13 11:35:28,023 [INFO]  Using this min relay fee as tx fee floor: 1000 sat/vkB (1.0 sat/vB)
2020-07-13 11:35:28,027 [INFO]  Using this min relay fee as tx fee floor: 1000 sat/vkB (1.0 sat/vB)
2020-07-13 11:35:28,046 [INFO]  Using a fee of : 0.00000172 BTC (172 sat).
2020-07-13 11:35:28,046 [INFO]  Using a change value of: 0.00899828 BTC (899828 sat).
Completed PSBT created: 
{
    "psbt-version": 0,
    "unsigned-tx": {
        "hex": "02000000010d0fa5c7c57978002e60de767b41f3149680bdcc596d74426cd127a1fdc6b0ce0100000000feffffff02f4ba0d000000000017a9144eac8d536baa2510f8ac51d1b08c7144004359ce87a086010000000000160014e2f44ec8bf62e883de6d449cff6c33404cd1b5546f2b1b00",
        "inputs": [
            {
                "outpoint": "ceb0c6fda127d16c42746d59ccbd809614f3417b76de602e007879c5c7a50f0d:1",
                "scriptSig": "",
                "nSequence": 4294967294
            }
        ],
        "outputs": [
            {
                "value_sats": 899828,
                "scriptPubKey": "a9144eac8d536baa2510f8ac51d1b08c7144004359ce87",
                "address": "2MzRDQNd9VDejsy7QG1RYgU4FFcqE4j4C54"
            },
            {
                "value_sats": 100000,
                "scriptPubKey": "0014e2f44ec8bf62e883de6d449cff6c33404cd1b554",
                "address": "tb1qut6yaj9lvt5g8hndgjw07mpngpxdrd25fz5clv"
            }
        ],
        "txid": "491151224d6ff277b5e6580acf3ceb8d9adc6ca040a1434b72bee72266036fb7",
        "nLockTime": 1780591,
        "nVersion": 2
    },
    "psbt-inputs": [
        {
            "input-index": 0,
            "utxo": {
                "value_sats": 1000000,
                "scriptPubKey": "a914bcb74e6970874baf809e21353469975295ae08fb87",
                "address": "2NAT4ch8vV22dkv93awXzxYsXEk3dn2yGr6"
            },
            "final-scriptSig": "16001455c661de60f94e9e4366e2461276d74f7ed9bdbd",
            "final-scriptWitness": "02473044022004ed4913d626bd7c6ac72f29accf5995510464a54ece6edb5186c41c603c72ed02203f08764aa09fc21b7e6f66a6dc26817d39d6bd8aed831d8412fe9bc9f8c920e20121024e51dbd00f72e6b9051d3dad9e305009a37a9a55abb358eff1079e04b62e0b4d"
        }
    ],
    "psbt-outputs": [
        {
            "output-index": 0
        },
        {
            "output-index": 1
        }
    ]
}
From destination url:  b'http://l3prea6fft7lwp3lz654nrrglljdrrzoovae7uyqkelnw73i5cvdu5qd.onion:37129'  got urlparts:  [b'http', b'l3prea6fft7lwp3lz654nrrglljdrrzoovae7uyqkelnw73i5cvdu5qd.onion:37129', b'', b'', b'', b'']
after insertion, url_parts is:  [b'http', b'l3prea6fft7lwp3lz654nrrglljdrrzoovae7uyqkelnw73i5cvdu5qd.onion:37129', b'', b'', b'v=1&disableoutputsubstitution=false&additionalfeeoutputindex=0&maxadditionalfeecontribution=113&minfeerate=1.1', b'']
2020-07-13 11:35:28,084 [INFO]  Starting transaction monitor in walletservice

"no results for hostname lookup: {}".format(self._hostStr)
twisted.internet.error.DNSLookupError: DNS lookup failed: no results for hostname lookup: l3prea6fft7lwp3lz654nrrglljdrrzoovae7uyqkelnw73i5cvdu5qd.onion.

[MaxHillebrand]

Next attempt!

@openoms torified his JM+Core, I started a new ephemeral hidden service.

JM decoded the URI properly.

JM successfully setup a connection to the P2EP. [I got notification about the negotiation in Wasabi]

Wasabi sent a wrong PSBT [probably because I am running an out of date branch, with last development in April, and the BIP has changed since?]

2020-07-13 11:55:30,318 [INFO]  Starting transaction monitor in walletservice
2020-07-13 11:55:36,229 [ERROR]  Payjoin tx from server could not be parsed: SerializationError('Invalid PSBT magic bytes')
2020-07-13 11:55:36,229 [WARNING]  Payjoin did not succeed, falling back to non-payjoin payment.

However again, no fallback transaction is broadcast by JM.

^Cdone
Unhandled error in Deferred:

Traceback (most recent call last):
  File "/home/joinmarket/joinmarket-clientserver/jmvenv/lib/python3.7/site-packages/twisted/web/_newclient.py", line 1306, in _bodyDataFinished_CONNECTED
    self._bodyProtocol.connectionLost(reason)
  File "/home/joinmarket/joinmarket-clientserver/jmvenv/lib/python3.7/site-packages/twisted/web/client.py", line 2259, in connectionLost
    self.deferred.callback(b''.join(self.dataBuffer))
  File "/home/joinmarket/joinmarket-clientserver/jmvenv/lib/python3.7/site-packages/twisted/internet/defer.py", line 460, in callback
    self._startRunCallbacks(result)
  File "/home/joinmarket/joinmarket-clientserver/jmvenv/lib/python3.7/site-packages/twisted/internet/defer.py", line 568, in _startRunCallbacks
    self._runCallbacks()
--- <exception caught here> ---
  File "/home/joinmarket/joinmarket-clientserver/jmvenv/lib/python3.7/site-packages/twisted/internet/defer.py", line 654, in _runCallbacks
    current.result = callback(current.result, *args, **kw)
  File "/home/joinmarket/joinmarket-clientserver/jmclient/jmclient/payjoin.py", line 543, in process_payjoin_proposal_from_server
    fallback_nonpayjoin_broadcast(manager, err="Server sent invalid psbt")
  File "/home/joinmarket/joinmarket-clientserver/jmclient/jmclient/payjoin.py", line 511, in fallback_nonpayjoin_broadcast
    log.warn("Error message was: " + err.decode("utf-8"))
builtins.AttributeError: 'str' object has no attribute 'decode'

[openoms]

Would like to add to here:
I could only connect to wasabi HS when running the command with torify/torsocks.
That needed the bitcoind RPC connection to be over Tor as well.
(did not try with localhost RPC - was using a remote node over LAN).

Should be able to communicate the PayJoin over Tor without needing to torify the bitcoindRPC calls too.

[AdamISZ]

Right, a couple of things here. (1) fallback on client side .. it is not implemented properly yet; my bad. I will do this shortly. It's pretty simple (just a simple reactor.callLater)

(2) hidden service receiver - that is also not implemented at all yet. If anyone feels inclined to work on it, I can suggest you look at jmclient/jmclient/payjoin.py for how we use the Agent object in twisted to set up a connection, and jmdaemon/jmdaemon/irc.py for how we use txtorcon to connect to hidden services. I'm guessing it's not too hard, just unfortunately for now I have only done the TLS clearnet version.

Edit: oh and btw thanks very much for testing guys, that is hugely useful.

[openoms]

Another test with https://demo.payjoin.kukks.org

Here the PJ does not happen repeatedly with the error:

Error message was: Service Unavailable

$ python sendpayment.py -m0 test.jmdat "bitcoin:tb1q9arzj0tmaysc427egvea688ucrtzmpwru88r7p?amount=0.00010758&pj=https://demo.payjoin.kukks.org/BTC/pj"
User data location: /home/joinmarket/.joinmarket/
2020-07-13 12:27:51,293 [DEBUG]  rpc: getblockchaininfo []
Attempting to pay via payjoin.
2020-07-13 12:27:51,300 [DEBUG]  rpc: getnetworkinfo None
2020-07-13 12:27:51,303 [INFO]  Using this min relay fee as tx fee floor: 1000 sat/vkB (1.0 sat/vB)
2020-07-13 12:27:51,304 [DEBUG]  Estimated miner/tx fee for each cj participant: 273
2020-07-13 12:27:51,304 [INFO]  starting sendpayment
Enter wallet decryption passphrase: 
2020-07-13 12:27:53,629 [DEBUG]  rpc: listaddressgroupings []
2020-07-13 12:27:53,631 [DEBUG]  Fast sync in progress. Got this many used addresses: 4
2020-07-13 12:27:54,295 [DEBUG]  rpc: listunspent []
2020-07-13 12:27:54,298 [DEBUG]  bitcoind sync_unspent took 0.008160114288330078sec
2020-07-13 12:27:54,303 [INFO]  Estimated miner/tx fees for this coinjoin amount: 2.5%
2020-07-13 12:27:54,306 [DEBUG]  rpc: getnetworkinfo None
2020-07-13 12:27:54,309 [INFO]  Using this min relay fee as tx fee floor: 1000 sat/vkB (1.0 sat/vB)
2020-07-13 12:27:54,312 [DEBUG]  rpc: getnetworkinfo None
2020-07-13 12:27:54,314 [INFO]  Using this min relay fee as tx fee floor: 1000 sat/vkB (1.0 sat/vB)
2020-07-13 12:27:54,332 [INFO]  Using a fee of : 0.00000179 BTC (179 sat).
2020-07-13 12:27:54,332 [INFO]  Using a change value of: 0.00978046 BTC (978046 sat).
Completed PSBT created: 
{
    "psbt-version": 0,
    "unsigned-tx": {
        "hex": "02000000013b7761b59994221135f55940dbe02f0fe39e1629b7b16f3ab9eb35e4f34a460d0000000000feffffff027eec0e000000000017a9142ade73c1e73adfb2934d30d19dd18b0ee03ce25587062a0000000000001600142f46293d7be9218aabd94333dd1cfcc0d62d85c3732b1b00",
        "inputs": [
            {
                "outpoint": "0d464af3e435ebb93a6fb1b729169ee30f2fe0db4059f53511229499b561773b:0",
                "scriptSig": "",
                "nSequence": 4294967294
            }
        ],
        "outputs": [
            {
                "value_sats": 978046,
                "scriptPubKey": "a9142ade73c1e73adfb2934d30d19dd18b0ee03ce25587",
                "address": "2Mw9trb7wgER1aw4tDE9evuURoTdt2wRmtL"
            },
            {
                "value_sats": 10758,
                "scriptPubKey": "00142f46293d7be9218aabd94333dd1cfcc0d62d85c3",
                "address": "tb1q9arzj0tmaysc427egvea688ucrtzmpwru88r7p"
            }
        ],
        "txid": "711388d8fc646c66e02a47ce12af3f50b8d8e579402587f9dd950a20c5f1be1b",
        "nLockTime": 1780595,
        "nVersion": 2
    },
    "psbt-inputs": [
        {
            "input-index": 0,
            "utxo": {
                "value_sats": 988983,
                "scriptPubKey": "a9144eac8d536baa2510f8ac51d1b08c7144004359ce87",
                "address": "2MzRDQNd9VDejsy7QG1RYgU4FFcqE4j4C54"
            },
            "final-scriptSig": "160014b985038fb302b89218cb4926b4a7098f48b77acc",
            "final-scriptWitness": "02483045022100a1bf6c36512ae83098cada54c944eefae242754e049eee7a511a2158076ec6ee022058a22842b533b25f97aecc6d16f1ae0a74ee2d46e632195197b74e1a0a250873012102fc473c51c8028070091e18a224812aa4ddc23d4233deaf1c8914dd777c10c994"
        }
    ],
    "psbt-outputs": [
        {
            "output-index": 0
        },
        {
            "output-index": 1
        }
    ]
}
2020-07-13 12:27:54,365 [DEBUG]  Initial nonpayjoin transaction feerate is: 1.084848484848485
2020-07-13 12:27:54,366 [DEBUG]  From which we calculated a max additional fee contribution of: 118
From destination url:  b'https://demo.payjoin.kukks.org/BTC/pj'  got urlparts:  [b'https', b'demo.payjoin.kukks.org', b'/BTC/pj', b'', b'', b'']
after insertion, url_parts is:  [b'https', b'demo.payjoin.kukks.org', b'/BTC/pj', b'', b'v=1&disableoutputsubstitution=false&additionalfeeoutputindex=0&maxadditionalfeecontribution=118&minfeerate=1.1', b'']
2020-07-13 12:27:54,377 [INFO]  Starting transaction monitor in walletservice
2020-07-13 12:27:54,666 [WARNING]  Payjoin did not succeed, falling back to non-payjoin payment.
2020-07-13 12:27:54,666 [WARNING]  Error message was: Service Unavailable
2020-07-13 12:27:54,675 [DEBUG]  rpc: sendrawtransaction ['020000000001013b7761b59994221135f55940dbe02f0fe39e1629b7b16f3ab9eb35e4f34a460d0000000017160014b985038fb302b89218cb4926b4a7098f48b77accfeffffff027eec0e000000000017a9142ade73c1e73adfb2934d30d19dd18b0ee03ce25587062a0000000000001600142f46293d7be9218aabd94333dd1cfcc0d62d85c302483045022100a1bf6c36512ae83098cada54c944eefae242754e049eee7a511a2158076ec6ee022058a22842b533b25f97aecc6d16f1ae0a74ee2d46e632195197b74e1a0a250873012102fc473c51c8028070091e18a224812aa4ddc23d4233deaf1c8914dd777c10c994732b1b00']
2020-07-13 12:27:54,680 [INFO]  We paid without coinjoin. Transaction: 
2020-07-13 12:27:54,683 [INFO]  {
    "hex": "020000000001013b7761b59994221135f55940dbe02f0fe39e1629b7b16f3ab9eb35e4f34a460d0000000017160014b985038fb302b89218cb4926b4a7098f48b77accfeffffff027eec0e000000000017a9142ade73c1e73adfb2934d30d19dd18b0ee03ce25587062a0000000000001600142f46293d7be9218aabd94333dd1cfcc0d62d85c302483045022100a1bf6c36512ae83098cada54c944eefae242754e049eee7a511a2158076ec6ee022058a22842b533b25f97aecc6d16f1ae0a74ee2d46e632195197b74e1a0a250873012102fc473c51c8028070091e18a224812aa4ddc23d4233deaf1c8914dd777c10c994732b1b00",
    "inputs": [
        {
            "outpoint": "0d464af3e435ebb93a6fb1b729169ee30f2fe0db4059f53511229499b561773b:0",
            "scriptSig": "160014b985038fb302b89218cb4926b4a7098f48b77acc",
            "nSequence": 4294967294,
            "witness": "02483045022100a1bf6c36512ae83098cada54c944eefae242754e049eee7a511a2158076ec6ee022058a22842b533b25f97aecc6d16f1ae0a74ee2d46e632195197b74e1a0a250873012102fc473c51c8028070091e18a224812aa4ddc23d4233deaf1c8914dd777c10c994"
        }
    ],
    "outputs": [
        {
            "value_sats": 978046,
            "scriptPubKey": "a9142ade73c1e73adfb2934d30d19dd18b0ee03ce25587",
            "address": "2Mw9trb7wgER1aw4tDE9evuURoTdt2wRmtL"
        },
        {
            "value_sats": 10758,
            "scriptPubKey": "00142f46293d7be9218aabd94333dd1cfcc0d62d85c3",
            "address": "tb1q9arzj0tmaysc427egvea688ucrtzmpwru88r7p"
        }
    ],
    "txid": "ff85fd9b0f17bdfd1af857a32ebb2dc7b77b74ba2590a98c9bd2071d47e9a942",
    "nLockTime": 1780595,
    "nVersion": 2
}
done

[AdamISZ]

I used https://btc.donate.kukks.org/ a couple of days ago with a similarly small amount and it worked fine for me. You seem to have a successful payment given the service was unavailable, as it says ... probably they are out of suitable utxos to serve? (it is actually good and correct that we don't easily understand what caused the error .. the server should not be telling everything about its internal state).

[MaxHillebrand]

It's really really difficult to see you guys working on such awesome magic, and then keep the cool and not prematurely test everything... 😀

Since these reported issues are expected, feel free to close the issue to keep the repo clean; or close it after it's implemented, up to you!

probably they are out of suitable utxos to serve?

afaik, @Kukks has plenty of coins on that server.

[AdamISZ]

feel free to close the issue

No seems fine here, good a place as any to keep track of these updates.

afaik, @Kukks has plenty of coins on that server.

Oh I just remembered. the problem is simple - you need bech32.

As explained elsewhere (maybe #536 I forget where i wrote it), btcpayserver plans to have support for merchant wallets to do p2sh wrap and bech32 both in the same wallet/merchant endpoint, but now they don't have it.
So you can't do Kukks' server without bech32. It's likely that. ("Service Unavailable" matches). Edit: and you can do that with Joinmarket by generating a bech32 wallet with native=true before you do generate.

[openoms]

@waxwing can confirm that PJ works with a bech32 wallet:
https://pastebin.com/raw/h17QxPx7

    "txid": "d57f86a2435a08c8b7ddca04cb1dbf1a522b869139a48afba427bb9ff119d2dd",
    "nLockTime": 1780597,
    "nVersion": 2
}

2020-07-13 12:58:12,380 [INFO]  Payjoin transaction broadcast successfully.
done

Looking great: https://blockstream.info/testnet/tx/d57f86a2435a08c8b7ddca04cb1dbf1a522b869139a48afba427bb9ff119d2dd

[lontivero]

Wow, this is great. About the old-discarded Wasabi PoC branch withpayjoin support: do not use it. It was created to show an idea and the implementation is previous to the bip78 discussions (it doesn't support none of these: disableoutputsubstitution, additionalfeeoutputindexm maxadditionalfeecontribution, minfeerate) and it returns transactions encoded as hex only.

[AdamISZ]

Changing title slightly to better reflect situation and will keep it open until the hidden service stuff is done client-side.

[AdamISZ]

Added support for paying to hidden service in this branch: https://github.com/JoinMarket-Org/joinmarket-clientserver/tree/hiddenservice-bip78 (see #638 ).

If you guys could test it that'd be great; it worked for me with the ephemeral HS i set up. I was using p2sh wrap wallets both sides, and a v2 onion; I think it should work fine with native wallet and v3 onion, but that'd be of interest to test (well; just testing any combination is super interesting, if we can get a Joinmarket to Wasabi payment work).

[openoms]

I have tested a PayJoin with latest master between two bech32 JM wallets. RPC connection over Tor.
It goes through and succeeds: https://blockstream.info/testnet/tx/1a6dd224801c1f2aa2656d2e5bb00ea565e58d3b7cbce367c0f40c813bf571e9
but throws and error on both sides:

twisted.internet.error.ReactorNotRunning: Can't stop reactor that isn't running.

Sender output:
https://pastebin.com/raw/SL9f7dTn
Receiver output:
https://pastebin.com/raw/yWjTzQdr

Did not have the opportunity test to test with a Tor HS endpoint yet.

[AdamISZ]

Just to be clear: the above experiment is not connected with the topic of this thread, which is BIP78 Payjoin between two joinmarket wallets a JM wallet and a non-JM wallet (sorry doh).
You were trying out the old JM-JM payjoin protocol. This has already caused confusion, see e.g. #622 (comment)

I won't remove/deprecate the old JM-JM version until at least we have a BIP78 receiver implemented, which could be done soonish if anyone had the intent to do it (see the test/payjoinserver code). But this is already seeming to cause a lot of confusion.

Thanks for the bug report and the positive test result. That bug is easy to fix (and indeed, harmless).

[AdamISZ]

Closing this as resolved after merge of #648 (see #638 ) and #636