Go: Path Finding Started to Return Invalid Paths in Horizon 1.4.0 (op_too_few_offers)

Created on 13 Jul 2020  Â·  22Comments  Â·  Source: stellar/go

What version are you using?

Horizon 1.4.0

What did you do?

I'm obtaining paths from /paths/strict-receive and then use the most economic path in a path-payment-strict-receive operation. This has been working fine up until 1.3.0 but now we're intermittently (and increasingly often) seeing op_too_few_offers when the best path is used. Looking at the returned paths from /paths/strict-receive they seem implausible actually. I think there might be an issue with pathfinder, which started with version 1.4.0.

What did you expect to see?

I'd expect paths given be the pathfinder to work fine and not result in op_too_few_offers when used in a path payment operation.

What did you see instead?

Tx fails with op_too_few_offers.

Example. /paths/strict-receive finds this path, which then results in op_too_few_offers if used:

{
   "sourceAssetType":"credit_alphanum4",
   "sourceAssetCode":"ETH",
   "sourceAssetIssuer":"GBDEVU63Y6NTHJQQZIKVTC23NWLQVP3WJ2RI2OTSJTNYOIGICST6DUXR",
   "sourceAmount":"0.0414144",
   "destinationAssetType":"credit_alphanum4",
   "destinationAssetCode":"USD",
   "destinationAssetIssuer":"GDUKMGUGDZQK6YHYA5Z6AY2G4XDSZPSZ3SW5UN3ARVMO6QSRDWP5YLEX",
   "destinationAmount":"10.0000000",
   "path":[
      {
         "assetType":"credit_alphanum4",
         "assetCode":"ETH",
         "assetIssuer":"GBVOL67TMUQBGL4TZYNMY3ZQ5WGQYFPFD5VJRWXR72VA33VFNL225PL5"
      },
      {
         "assetType":"credit_alphanum4",
         "assetCode":"ETH",
         "assetIssuer":"GCNSGHUCG5VMGLT5RIYYZSO7VQULQKAJ62QA33DBC5PPBSO57LFWVV6P"
      },
      {
         "assetType":"native",
         "assetCode":"XLM",
         "assetIssuer":null
      }
   ]
}

Upon manual inspection, this does not look like a plausible path: ETH -> {ETH -> ETH -> XLM} -> USD and correctly got rejected by the Network with tx_failed and op_too_few_offers.

Normally in 100% of the cases this would be a bad trade. Trading tethers horizontally across several issuers always is a loss of money. So it looks like pathfinder indeed finds invalid paths and then core rejects them because they don't actually exist and the tx fails.

Please let me know if you need more info. @bartekn @abuiles

bug

Most helpful comment

@marcinx glad to hear this is not a Horizon bug. For the future, anything you can do to provide a repro out of the gate (e.g. exact Horizon call + failed txhash) would be awesome. We spent some time on this and turnaround could be a lot faster next time with a little more info up front.

Yeah, I can imagine. I feel bad for wasting your time. It seemed so obvious at first, considering that path finding gave wrong results in the very past. Contrary to that it looks very robust and fast now though 💯Will triple-check better and provide more meta out of the box next time I run into any issues. Thanks for helping to find the root cause of this!!

All 22 comments

@marcinx thanks for the report we'll check it out. If you see something like this again, could you also add Latest-Ledger header from the HTTP response to the issue? It will help us bring orderbook graph to the ledger in which the path existed.

@tamirms if the fix is easy let's try to include it in 1.6.0.

Thanks, @bartekn! I added some additional logging to capture the ledger. Will post here when I catch some extra data.

Not sure if related or if I am wrong here but I seem to remember that the --max-path-length=4 setting previously used to count the source asset and destination asset. With above setting, the results used to have a maximum of two assets in the found paths: sourceAsset -> pathAsset1, -> pathAsset2 -> destinationAsset (=4 total assets; =max-path-length). I am almost 99% sure that this used to be the case in the past.

Now I am observing up to three path assets, i.e. sourceAsset -> pathAsset1 -> pathAsset2 -> pathAsset3 -> destinationAsset (see the path pasted in the issue description). Is this correct behavior? Is max-path-length supposed to count only the path assets or sourceAsset and destinationAsset as well ? @bartekn @tamirms @abuiles

@marcinx I think it doesn't count the source so the length is actually 4:

ETH -> {ETH -> ETH -> XLM} -> USD
        1      2      3       4

Caught another such case today. Here is some extra info:

Request: GET /stardust/v1/paths/strict-receive?sourceAccount=GBDHWMSXQ24FA2LJTPUH3HNK3WR7BJW3DUUBLMSNSJ7ST4XZK7WJHPCQ&destinationAssetType=credit_alphanum4&destinationAssetCode=EURT&destinationAssetIssuer=GAP5LETOV6YIE62YAM56STDANPRDO7ZFDBGSNHJQIYGGKSMOZAHOOS2S&destinationAmount=10.0000000 (this proxies the params to Horizon)

Complete Horizon Response Body: https://gist.github.com/marcinx/f3b3fbfadf9535822f9e5ab6472f7bce

Most Economic Apay ETH -> Tempo EURT path:

{
   "sourceAssetType":"credit_alphanum4",
   "sourceAssetCode":"ETH",
   "sourceAssetIssuer":"GBDEVU63Y6NTHJQQZIKVTC23NWLQVP3WJ2RI2OTSJTNYOIGICST6DUXR",
   "sourceAmount":"0.0476752",
   "destinationAssetType":"credit_alphanum4",
   "destinationAssetCode":"EURT",
   "destinationAssetIssuer":"GAP5LETOV6YIE62YAM56STDANPRDO7ZFDBGSNHJQIYGGKSMOZAHOOS2S",
   "destinationAmount":"10.0000000",
   "path":[
      {
         "assetType":"credit_alphanum4",
         "assetCode":"ETH",
         "assetIssuer":"GBVOL67TMUQBGL4TZYNMY3ZQ5WGQYFPFD5VJRWXR72VA33VFNL225PL5"
      },
      {
         "assetType":"credit_alphanum4",
         "assetCode":"ETH",
         "assetIssuer":"GCNSGHUCG5VMGLT5RIYYZSO7VQULQKAJ62QA33DBC5PPBSO57LFWVV6P"
      },
      {
         "assetType":"native",
         "assetCode":"XLM",
         "assetIssuer":null
      }
   ]
}

Ledger from pathfinder http response headers: 'latest-ledger': '30609467'

When trying to use this path in ledger 30609468 with a path-payment-strict-receive, the response is: op_too_few_offers.

This happens intermittently.

Hope this helps. Please let me know when you have more questions. @bartekn @tamirms @abuiles

@marcinx I started v1.4.0 horizon locally and ingested ledgers up to 30609467. When I sent the following curl request:

curl -v "http://localhost:8000/paths/strict-receive?source_assets=ETH:GBDEVU63Y6NTHJQQZIKVTC23NWLQVP3WJ2RI2OTSJTNYOIGICST6DUXR&destination_asset_type=credit_alphanum4&destination_asset_code=EURT&destination_asset_issuer=GAP5LETOV6YIE62YAM56STDANPRDO7ZFDBGSNHJQIYGGKSMOZAHOOS2S&destination_amount=10.0000000"

I got a different result than the one you have. The first entry in my result was:

       {
        "source_asset_type": "credit_alphanum4",
        "source_asset_code": "ETH",
        "source_asset_issuer": "GBDEVU63Y6NTHJQQZIKVTC23NWLQVP3WJ2RI2OTSJTNYOIGICST6DUXR",
        "source_amount": "0.0478696",
        "destination_asset_type": "credit_alphanum4",
        "destination_asset_code": "EURT",
        "destination_asset_issuer": "GAP5LETOV6YIE62YAM56STDANPRDO7ZFDBGSNHJQIYGGKSMOZAHOOS2S",
        "destination_amount": "10.0000000",
        "path": [
          {
            "asset_type": "credit_alphanum4",
            "asset_code": "USDT",
            "asset_issuer": "GCQTGZQQ5G4PTM2GL7CDIFKUBIPEC52BROAQIAPW53XBRJVN6ZJVTG6V"
          },
          {
            "asset_type": "native"
          }
        ]
      }

Here is the full response from the curl request: https://gist.github.com/tamirms/d530f73c479886bffe0b14c1dd078e6d

are you doing any sort of caching when proxying requests to horizon? The path finding code should be completely deterministic. Given the same ledger state the path finder should always return the same set of results. So, I'm a bit confused as to why your response differs from mine

@tamirms No caching whatsoever.

Our request is different from yours though because we query all source assets (trustlines) on a given source account.
In your example source_assets is ETH:GBDEVU63Y6NTHJQQZIKVTC23NWLQVP3WJ2RI2OTSJTNYOIGICST6DUXR, but in our request, source_assets are all trustlines (and XLM) on a given source account.

Can you re-create the issue when using the following as source_assets?

BRL:GDVKY2GU2DRXWTBEYJJWSFXIGBZV6AZNBVVSUHEPZI54LIS6BA7DVVSP,BTC:GAUTUYY2THLF7SGITDFMXJVYH3LHDSMGEAKSBU267M2K7A3W543CKUEF,BTC:GBVOL67TMUQBGL4TZYNMY3ZQ5WGQYFPFD5VJRWXR72VA33VFNL225PL5,CAD:GBLR5MVHI7PCN24JIHDR5LUYFBHSA2IOVPZP7F75L7PIF3WU3TQGQC3P,ETH:GBDEVU63Y6NTHJQQZIKVTC23NWLQVP3WJ2RI2OTSJTNYOIGICST6DUXR,ETH:GBVOL67TMUQBGL4TZYNMY3ZQ5WGQYFPFD5VJRWXR72VA33VFNL225PL5,EURT:GAP5LETOV6YIE62YAM56STDANPRDO7ZFDBGSNHJQIYGGKSMOZAHOOS2S,LTC:GBVOL67TMUQBGL4TZYNMY3ZQ5WGQYFPFD5VJRWXR72VA33VFNL225PL5,LTC:GC5LOR3BK6KIOK7GKAUD5EGHQCMFOGHJTC7I3ELB66PTDFXORC2VM5LP,NGNT:GAWODAROMJ33V5YDFY3NPYTHVYQG7MJXVJ2ND3AOGIHYRWINES6ACCPD,USD:GDUKMGUGDZQK6YHYA5Z6AY2G4XDSZPSZ3SW5UN3ARVMO6QSRDWP5YLEX,XRP:GBVOL67TMUQBGL4TZYNMY3ZQ5WGQYFPFD5VJRWXR72VA33VFNL225PL5,native

@tamirms In our response it finds the path you posted above as third most economic option: https://gist.github.com/marcinx/f3b3fbfadf9535822f9e5ab6472f7bce

Maybe the additional source assets (we have two source ETH with different issuers) are causing this issue somehow?

@marcinx here's my response using the full list of source assets: https://gist.github.com/tamirms/3778b07fd5c9b228f3d798bd922cd0f2

as you can see it still does not match your response. I cannot find any entry where the source amount is 0.0476752 with source asset ETH:GBDEVU63Y6NTHJQQZIKVTC23NWLQVP3WJ2RI2OTSJTNYOIGICST6DUXR

@tamirms is it possible that OrderBookStream that was added in 1.4.0 is causing inconsistencies? Maybe the Latest-Ledger header is not updated properly (it's loaded from a DB, not a graph?). Maybe we should check a range of ledgers, like 10 before, 10 after: [30609457, 30609477].

@tamirms I'll add some more logging where I capture the exact request URL sent to Horizon along with the response headers and body. I'll post here when I catch another such case. They seem to appear daily.

@marcinx I just realized that I was using the default max-path-length which is 3 and you are using a max-path-length value of 4. After changing the configuration to match yours I'm able to observe the 0.0476752 ETH:GBDEVU63Y6NTHJQQZIKVTC23NWLQVP3WJ2RI2OTSJTNYOIGICST6DUXR path in my response

@tamirms Okay, great! I guess now we just need to exclude the possibility of random front-running/out-running of the found path in the next ledger to be 100% sure this is a path finder issue? I find this explanation highly unlikely but it could theoretically be possible. From my manual observations and tests it is most likely a non-existent path.

@marcinx

do you have a link to the transaction containing your failed path payment? It would be helpful to know which ledger the network was at when your transaction was processed.

At ledger 30609467 the following path was available:

{
        "source_asset_type": "credit_alphanum4",
        "source_asset_code": "ETH",
        "source_asset_issuer": "GBDEVU63Y6NTHJQQZIKVTC23NWLQVP3WJ2RI2OTSJTNYOIGICST6DUXR",
        "source_amount": "0.0476752",
        "destination_asset_type": "credit_alphanum4",
        "destination_asset_code": "EURT",
        "destination_asset_issuer": "GAP5LETOV6YIE62YAM56STDANPRDO7ZFDBGSNHJQIYGGKSMOZAHOOS2S",
        "destination_amount": "10.0000000",
        "path": [
          {
            "asset_type": "credit_alphanum4",
            "asset_code": "ETH",
            "asset_issuer": "GBVOL67TMUQBGL4TZYNMY3ZQ5WGQYFPFD5VJRWXR72VA33VFNL225PL5"
          },
          {
            "asset_type": "credit_alphanum4",
            "asset_code": "ETH",
            "asset_issuer": "GCNSGHUCG5VMGLT5RIYYZSO7VQULQKAJ62QA33DBC5PPBSO57LFWVV6P"
          },
          {
            "asset_type": "native"
          }
        ]
 }

The source amount on the ETH -> {ETH -> ETH -> XLM} -> EURT path decreased from 0.0476752 to 0.0476656 on the next ledger 30609467.

That path remained available up until ledger 30609471.

On ledger 30609471 the source amount increased to 0.0476833.

@tamirms The tx should be sent in the ledger right after when this path was found. It's literally the next thing that happens in the code. As soon as we have a pathfinder response we take the best path and send the path-payment-strict-receive.

It's worth pointing out that we are adding 1.5% slippage padding to the source_amount in the path_payment operation. 0.0476752 found in the best path becomes 0.0483903 in the sendMax for the operation. So even if the required source amount increases somewhat to 0.0476752 to 0.0476656 the op should be able to execute.

I actually tried to find the failed tx manually a while ago but it doesn't seem to show up. Our Horizon doesn't ingest failed tx (yet) but I had no luck on horizon.stellar.org either. It should be somewhere on GBDHWMSXQ24FA2LJTPUH3HNK3WR7BJW3DUUBLMSNSJ7ST4XZK7WJHPCQ for the ledger(s) immediately after 30609467.

@tamirms PS: It's more complicated than that. The tx is sent from a channel account (which can be any of these):

GBGG4PZQFXZYF3OUPB5P4Z5SDYY6QS3YAB3EQPIOBTG4J3BGA3JMXDOR
GBIWIMXSMFXDK44VUNFUHSCUJVK7UJUAD5J7TUJOYQIKRGHAHPWLSYZ6
GC2AEFWNZJ6YFZO4HGQ5DW3P6DBHJ6QDTPFSOTWOTSSHJZD56VC3XOSK
GC4WSVHVHYWR2KF4Z7AMTOB7M3C2P67TQ4JWWW44DSS7LUFNUT2VF6RL
GD4XE5WQTJLFDY67XDN5SOIQVPLWUCLZ5UPOFFKOZKNAC6GV3WRHCS6M
GD776TFY6ECG6K2SZC3Q26RZDIXF7KLRRNKGOWGUDRSNK4CUITLUPPZU
GDRLNPHYGF3AYG2Q2NXHMXVWGMRA6KIMAL7UJ2O3CDHSFZ2TWOQNMDS5
GDV3ZOYWTAUR2VLHB2DM77AM5EDC5KU6UKLC5VDPAVDRNQJYKELPUNK5
GDXMVK2NJRND72NIJ2XF37VWLKP2YNA64IBSSGVTY7B5KAIVECZCM3LT

So when looking for the failed tx, it should have either of above as source account. The source and destination account for the op should be GBDHWMSXQ24FA2LJTPUH3HNK3WR7BJW3DUUBLMSNSJ7ST4XZK7WJHPCQ.

However, horizon.stellar.org doesn't seem to display failed transactions? When I go to https://horizon.stellar.org/ledgers/30609468 it tells me that there are 36 successful and 18 failed txs. When I visit https://horizon.stellar.org/ledgers/30609468/transactions?limit=200 it only has the 36 successful txs but no fails.

I tried, but really don't know how to find the failed one without doing a major database query operation, which I would have to research how to do in the first place ¯\_(ツ)_/¯

Maybe there is another way to verify/falsify that the suspicious path actually existed?

@marcinx you need to include_failed
https://horizon.stellar.org/ledgers/30609467/transactions?limit=200&include_failed=true

On Wed, Jul 15, 2020 at 2:34 PM marcinx notifications@github.com wrote:

@tamirms https://github.com/tamirms PS: It's more complicated than
that. The tx is sent from a channel account (which can be any of these):

GBBMI477CH2XZQ53R5PLTB5PUUPZEARARRF5LFEYOUEVWIC6J3WXWTN5

GBGG4PZQFXZYF3OUPB5P4Z5SDYY6QS3YAB3EQPIOBTG4J3BGA3JMXDOR

GBIWIMXSMFXDK44VUNFUHSCUJVK7UJUAD5J7TUJOYQIKRGHAHPWLSYZ6

GC2AEFWNZJ6YFZO4HGQ5DW3P6DBHJ6QDTPFSOTWOTSSHJZD56VC3XOSK

GC4WSVHVHYWR2KF4Z7AMTOB7M3C2P67TQ4JWWW44DSS7LUFNUT2VF6RL

GD4XE5WQTJLFDY67XDN5SOIQVPLWUCLZ5UPOFFKOZKNAC6GV3WRHCS6M

GD776TFY6ECG6K2SZC3Q26RZDIXF7KLRRNKGOWGUDRSNK4CUITLUPPZU

GDRLNPHYGF3AYG2Q2NXHMXVWGMRA6KIMAL7UJ2O3CDHSFZ2TWOQNMDS5

GDV3ZOYWTAUR2VLHB2DM77AM5EDC5KU6UKLC5VDPAVDRNQJYKELPUNK5

GDXMVK2NJRND72NIJ2XF37VWLKP2YNA64IBSSGVTY7B5KAIVECZCM3LT

So when looking for the failed tx, it should have either of above as
source account. The source account for the op should be GBDHWMSXQ24FA2LJTPUH3HNK3WR7BJW3DUUBLMSNSJ7ST4XZK7WJHPCQ
.

However, horizon.stellar.org doesn't seem to display failed transactions?
When I go https://horizon.stellar.org/ledgers/30609467 it tells me that
there are 31 successful and 10 failed txs. When I visit
https://horizon.stellar.org/ledgers/30609467/transactions?limit=200 it
only has the 31 successful txs but no fails.

I tried, but really don't know how to find the failed one without doing a
major database query operation, which I would have to research how to do in
the first place :) ¯_(ツ)_/¯ Maybe there is another way to verify that the
suspicious path actually existed?

—
You are receiving this because you were mentioned.
Reply to this email directly, view it on GitHub
https://github.com/stellar/go/issues/2810#issuecomment-658964666, or
unsubscribe
https://github.com/notifications/unsubscribe-auth/AAAFKDG7KLULPW2XRWVABD3R3YACTANCNFSM4OYRVMHA
.

Thanks, @abuiles !

@tamirms Here is the failed op in 30609468: https://horizon.stellar.org/transactions/8fb1a81737c841df5a9f32254d5e24df3c7214d0b009566f5304b0e4bfdff680/operations and now I feel stupid because the path is not what the pathfinder gave me. It's missing the first asset.

Sigh. It looks like it's an issue on our end then. Sorry for wasting your time. I'm glad it's not an issue on Horizon though 💪 Thanks for the excellent support.

@marcinx no worries :)

one tip which may be helpful:

you can log the transaction hash in your backend whenever a transaction fails. then, if you need to debug why the transaction failed, you will be able to easily look up the transaction details via horizon

@marcinx glad to hear this is not a Horizon bug. For the future, anything you can do to provide a repro out of the gate (e.g. exact Horizon call + failed txhash) would be awesome. We spent some time on this and turnaround could be a lot faster next time with a little more info up front.

@marcinx glad to hear this is not a Horizon bug. For the future, anything you can do to provide a repro out of the gate (e.g. exact Horizon call + failed txhash) would be awesome. We spent some time on this and turnaround could be a lot faster next time with a little more info up front.

Yeah, I can imagine. I feel bad for wasting your time. It seemed so obvious at first, considering that path finding gave wrong results in the very past. Contrary to that it looks very robust and fast now though 💯Will triple-check better and provide more meta out of the box next time I run into any issues. Thanks for helping to find the root cause of this!!

Was this page helpful?
0 / 5 - 0 ratings