Bug in flow (Version: 1.7.0)

[RichardAH]

Issue Description

An unusual / wrong Offer node created by 3589187DEF462C8EC8B249E3A5767504F243A1C929FCF52F9092C1C9658FE111 on mainnet.

Transaction:

{
    "Account": "rLCV6fxaWsqyeWbC2USQEmP7s1J2gygjfo",
    "Fee": "12",
    "Flags": 2148007936,
    "LastLedgerSequence": 62932639,
    "Memos": [
      {
        "Memo": {
          "MemoData": "7274312E312D32362D6762656236386162",
          "MemoType": "636C69656E74"
        }
      }
    ],
    "Sequence": 4452,
    "SigningPubKey": "02CC8A20749B8132A3BCD01F38FA24C5C101F40B4A94CD508DD495584186F0C6F6",
    "TakerGets": "1000",
    "TakerPays": {
      "currency": "USD",
      "issuer": "rhub8VRN55s94qWKDv6jmDy1pUykJzF3wq",
      "value": "0.00001"
    },
    "TransactionType": "OfferCreate",
    "TxnSignature": "3044022022A0E2F5FE33E0810B3624D159BC8CB229A6B29DC14EAF14306A9942FFF0A3FC02200C684AFC655D44258251ECC9C9654F5A6B0B7033422EB1629507264068450FAF"
}

Steps to Reproduce

Replay of ledger 62932632:

2021-Apr-16 12:45:59.669765987 UTC LedgerConsensus:TRC New flow iter (iter, in, out): 0 1 1956087824351297e-29
2021-Apr-16 12:45:59.669781827 UTC LedgerConsensus:TRC Path rejected by limitQuality limit: 6702356245527298048 path q: 7066756460614896913
2021-Apr-16 12:45:59.669800923 UTC LedgerConsensus:TRC All strands dry.
2021-Apr-16 12:45:59.669816332 UTC LedgerConsensus:TRC Total flow: in: 0 out: 0
2021-Apr-16 12:45:59.669830507 UTC LedgerConsensus:TRC Cross result: tesSUCCESS
2021-Apr-16 12:45:59.669853441 UTC LedgerConsensus:TRC      in: 1000/XRP
2021-Apr-16 12:45:59.669869030 UTC LedgerConsensus:TRC     out: 0.00001/USD
2021-Apr-16 12:45:59.669883397 UTC LedgerConsensus:TRC Place offer:
2021-Apr-16 12:45:59.669901279 UTC LedgerConsensus:TRC     Pays: 0.00001/USD/rhub8VRN55s94qWKDv6jmDy1pUykJzF3wq
2021-Apr-16 12:45:59.669916438 UTC LedgerConsensus:TRC     Gets: 1000/XRP
2021-Apr-16 12:45:59.669967094 UTC LedgerConsensus:TRC adding to book: rhub8VRN55s94qWKDv6jmDy1pUykJzF3wq/USD : XRP
2021-Apr-16 12:45:59.670023539 UTC LedgerConsensus:DBG final result: success
2021-Apr-16 12:45:59.670041542 UTC LedgerConsensus:TRC preclaim result: tesSUCCESS

Expected Result

If the cross fails with All strands dry it should not go on to return as tesSUCCESS. (I'm not sure if this is the only issue here.)

Actual Result

The order is "crossed" for 0 value then placed on the wrong side of the book.

Use the following:

{  "command": "book_offers", "taker_gets":{"currency":"XRP"}, "taker_pays":{"currency":"USD","issuer":"rhub8VRN55s94qWKDv6jmDy1pUykJzF3wq"}, "ledger": "62932633"}

Resuling in:

{"Account":"rLCV6fxaWsqyeWbC2USQEmP7s1J2gygjfo","BookDirectory":"79C54A4EBD69AB2EADCE313042F36092BE432423CC6A4F784D038D7EA4C68000","BookNode":"0","Flags":131072,"LedgerEntryType":"Offer","OwnerNode":"7","PreviousTxnID":"3589187DEF462C8EC8B249E3A5767504F243A1C929FCF52F9092C1C9658FE111","PreviousTxnLgrSeq":62932632,"Sequence":4452,"TakerGets":"1000","TakerPays":{"currency":"USD","issuer":"rhub8VRN55s94qWKDv6jmDy1pUykJzF3wq","value":"0.00001"},"index":"9B9D7779B7DFAB1ECE26194E9AFD7C94AACEE6A02D9F953777F0536A198495E9","owner_funds":"10033645921","quality":"0.00000001"},{"Account":"rhS2H7ETM3wBkFETvYycoUm9FEDYi44Pg4","BookDirectory":"79C54A4EBD69AB2EADCE313042F36092BE432423CC6A4F784F05E437DB470D2B","BookNode":"0","Flags":0,"LedgerEntryType":"Offer","OwnerNode":"20","PreviousTxnID":"D5AFF66DA2D95855A76EC3D4165F8A93D39DBEF625682497B581287DC992C54A","PreviousTxnLgrSeq":62932625,"Sequence":34816927,"TakerGets":"1000000000","TakerPays":{"currency":"USD","issuer":"rhub8VRN55s94qWKDv6jmDy1pUykJzF3wq","value":"1658.303436754219"} ...

Environment

Mainnet

Quick analysis

It appears the following condition should fire but doesn't. https://github.com/ripple/rippled/blob/2913847925ec8cabde868e6502a55610a768736f/src/ripple/app/paths/impl/StrandFlow.h#L757-L760

Other notes

I tried to replicate the transaction in a later ledger (9C947F9E6B6358EEB3B4EA8D8A494A4B8299A1CC69B45A2AD371B0D8AE646EDB) and was unable to reproduce the behaviour suggesting it is probably not trivially exploitable

[donovanhide]

Not sure if what I saw and reported privately this morning is symptomatic of this same issue, but here goes:

rHxN3R2uoSeJ7q726pH8CT2D4gcmQhJiGV consumed an offer of raAbeTkVgXNqXyW6NYhQETsv2JyjRtkakf i n C2BDA5927C73419CBD9624DE717A68A3F69BA270273755F3590E3E588F5227BC that left a tiny remainder balance of -196e-16 of USD/rhub8VRN55s94qWKDv6jmDy1pUykJzF3wq. This offer persisted at the top of the orderbook and crossed the other side and could not be consumed until rYUZ3HYqNNd7TEzC4H7fXjANAoLzWY6ym donated a single dollar in ledger 62933767, which then let that offer be consumed.

I do not know the causes, just that the offer being unconsumable was highly unusual.

[seelabs]

Thanks for the bug report.

I took a look at the transaction, and it looks correct to me.

First, if we look at the transaction and its metadata, it's an OfferCreate for TakerPays .00001USD and TakerGets 1000 drops. The metadata shows an offer created with those TakerPays and TakerGets amounts. That looks correct.

The logging data is confusing, and I can see why that might look like a bug. The reason for the misleading log messages is that offer crossing uses the payment engine as part of its implementation (we used to use a different implementation). When offer crossing runs the payment engine, it doesn't find a suitable offer to cross, and fails with All strands dry message. But this just means there's no offer to cross, not that the offer create fails. The OfferCreate transaction succeeds with a tesSUCCESS even though the payment engine failed to cross the offer.

I also replayed the transaction, and there is something interesting about it. There's an offer with a TakerPays ~4XRP, TakerGets ~8USD. Normally that offer would cross. However, the owner only has ~10^-14USD to fund the offer. When that is taken into account, the offer becomes TakerPays 1 drop, TakerGets ~10^-14USD, and the offer no longer crosses and processing stops.

Please let me know if I misunderstood anything in the bug report, and thanks again for reporting!

[seelabs]

@donovanhide Although I have not replayed that transaction, the symptoms are similar. It also explains why sending a dollar makes the offer consumable. When taking the owner funds into account, the actual offer quality with be much closer to quality when first placed on the book (instead of something like 1 drop for 10^-14).

[donovanhide]

So the bug is that when a tiny remainder makes the calculated offer quality differ from the original offer quality, the offer may get stuck at the top of the orderbook even when an ImmediateOrCancel OfferCreate is submitted which crosses it?

[seelabs]

When doing offer crossing we use the actual offer quality, not the quality of the original offer. And when taking owner funds into account the actual quality no longer crosses. Yes, this can cause these tiny "dust" offers to stay at the top of the order book, even when there are offers with much better actual quality below it. Ideally, a regular payment will come along and consume the offer, but it appears these offers may be sticking longer than we'd like.

[donovanhide]

The problem that I had is an OfferCreate that crossed the dust offer didn't consume it or any offers beneath it in the quality ordering. For example BB1609F62E369DA40BE782B18BADF3419BC1876D52BD567E4D4A215E13E57F09

Waiting for a payment to come along to clear it away is far from ideal. It effectively blocks the orderbook, as could be witnessed this morning when trades on only one side of the XRP USD/rhub8VRN55s94qWKDv6jmDy1pUykJzF3wq orderbook were occurring, until the deliberate payment was made.

[seelabs]

@donovanhide Yes, I agree it's far from ideal. I recently made some changes that help with this on the payments side, but I haven't thought of a good solution for the offer create side. Given that it's becoming a real problem for people, I'll give it some more thought.

[donovanhide]

@seelabs this has just happened again with an offer of rH5WJmyWhjLpxzNWnpYaRZVGWV9jQz2Jd5 in many ledgers, including 62981379, with a micro amount of 2195608782435129e-33 BTC/rchGBxcD1A1C2tdxF6papQYZ8kjRKMYcL stopping offers being consumed. Don't know if this is a live exploit, or just coincidence.

[seelabs]

Thanks @donovanhide I'm actively working on a fix now.