search

interledgerjs / ilp-connector

Reference implementation of an Interledger connector.
Other
133 stars 59 forks source link

Connector sends remote quoted payment to wrong next hop #382

Open sharafian opened 7 years ago

sharafian commented 7 years ago

When sending a remote quote, the connector stores the result as a route, but it appears to add it onto every one of its local routes. Then, when the payment is sent, it might be sent out over the wrong plugin.

second-ilp-kit    | [api] 2017-07-20T12:27:48.466Z ilp:ilqp debug remote quote connector=test.dev.kit2.connector query={"destinationAccount":"test.dev.kit1.admin.i3VTIsLNHvs1WwtbQ3HQ-0KhLiZGlUgjA","destinationHoldDuration":10000,"sourceAmount":null,"destinationAmount":"1"}
second-ilp-kit    | [api]   ilp-plugin-bells:plugin sending message: {"id":"99beb457-0320-4ba3-9a7f-596abe67c9d6","ledger":"test.dev.kit2.","from":"test.dev.kit2.admin","to":"test.dev.kit2.connector","ilp":"BkM1dGVzdC5kZXYua2l0MS5hZG1pbi5pM1ZUSXNMTkh2czFXd3RiUTNIUS0wS2hMaVpHbFVnakEAAAAAAAAAAQAAJxAA","timeout":5000} +183ms
second-ilp-kit    | [api]   ilp-plugin-bells:plugin converted to ledger message: {"ledger":"http://ilp-kit2:4010/ledger","from":"http://ilp-kit2:4010/ledger/accounts/admin","to":"http://ilp-kit2:4010/ledger/accounts/connector","data":{"id":"99beb457-0320-4ba3-9a7f-596abe67c9d6","ilp":"BkM1dGVzdC5kZXYua2l0MS5hZG1pbi5pM1ZUSXNMTkh2czFXd3RiUTNIUS0wS2hMaVpHbFVnakEAAAAAAAAAAQAAJxAA"}} +3ms
second-ilp-kit    | [ledger] 2017-07-20T12:27:48.490Z ledger:koa info <-- POST /messages
second-ilp-kit    | [ledger] 2017-07-20T12:27:48.516Z ledger:koa info --> POST /messages 201 26ms 300B
second-ilp-kit    | [api]   ilp-plugin-bells:translate notify message http://ilp-kit2:4010/ledger/accounts/admin +47ms
second-ilp-kit    | [api] 2017-07-20T12:27:48.550Z connector:route-builder info creating quote sourceAccount=test.dev.kit2.admin destinationAccount=test.dev.kit1.admin.i3VTIsLNHvs1WwtbQ3HQ-0KhLiZGlUgjA destinationAmount=1
second-ilp-kit    | [api] 2017-07-20T12:27:48.554Z ilp-routing:routing-tables debug searching best hop from test.dev.kit2.admin to test.dev.kit1.admin.i3VTIsLNHvs1WwtbQ3HQ-0KhLiZGlUgjA for 0 (by src amount)
second-ilp-kit    | [api] 2017-07-20T12:27:48.558Z ilp-routing:routing-table debug findBestHopForSourceAmount to test.dev.kit1.admin.i3VTIsLNHvs1WwtbQ3HQ-0KhLiZGlUgjA for 0 found route through test.dev.ledger2.ledger2-testconnector
second-ilp-kit    | [api] 2017-07-20T12:27:48.564Z ilp:ilqp debug remote quote connector=test.dev.ledger2.ledger2-testconnector query={"destinationAccount":"test.dev.kit1.admin.i3VTIsLNHvs1WwtbQ3HQ-0KhLiZGlUgjA","destinationHoldDuration":10000}
second-ilp-kit    | [api]   ilp-plugin-bells:plugin sending message: {"id":"e028afc3-e59d-495a-bdda-41fb7405b1ca","ledger":"test.dev.ledger2.","from":"test.dev.ledger2.alice","to":"test.dev.ledger2.ledger2-testconnector","ilp":"Ajs1dGVzdC5kZXYua2l0MS5hZG1pbi5pM1ZUSXNMTkh2czFXd3RiUTNIUS0wS2hMaVpHbFVnakEAACcQAA==","timeout":5000} +53ms
second-ilp-kit    | [api]   ilp-plugin-bells:plugin converted to ledger message: {"ledger":"http://ledger2.example:8088/ilp/ledger/v1","from":"http://ledger2.example:8088/ilp/ledger/v1/accounts/alice","to":"http://ledger2.example:8088/ilp/ledger/v1/accounts/ledger2-testconnector","data":{"id":"e028afc3-e59d-495a-bdda-41fb7405b1ca","ilp":"Ajs1dGVzdC5kZXYua2l0MS5hZG1pbi5pM1ZUSXNMTkh2czFXd3RiUTNIUS0wS2hMaVpHbFVnakEAACcQAA=="}} +4ms
second-ilp-kit    | [api]   ilp-plugin-bells:translate notify message http://ledger2.example:8088/ilp/ledger/v1/accounts/ledger2-testconnector +375ms
second-ilp-kit    | [api] 2017-07-20T12:27:48.964Z ilp-routing:routing-tables debug added route matching  test.dev.kit1. : test.crypto.ripple.escrow.r9yVLWvhY9pKmJtQMbE6ZyxNaB6hdMDX1J test.dev.kit1. epoch: 4
second-ilp-kit    | [api] 2017-07-20T12:27:48.966Z ilp-routing:routing-tables debug added route matching  test.dev.kit1. : test.dev.kit2.connector test.dev.kit1. epoch: 5
second-ilp-kit    | [api] 2017-07-20T12:27:48.966Z ilp-routing:routing-tables debug added route matching  test.dev.kit1. : test.dev.ledger2.ledger2-testconnector test.dev.kit1. epoch: 3
second-ilp-kit    | [api] 2017-07-20T12:27:48.966Z ilp-routing:routing-tables debug searching best hop from test.dev.kit2.admin to test.dev.kit1.admin.i3VTIsLNHvs1WwtbQ3HQ-0KhLiZGlUgjA for 0 (by src amount)
second-ilp-kit    | [api] 2017-07-20T12:27:48.968Z ilp-routing:routing-table debug findBestHopForSourceAmount to test.dev.kit1.admin.i3VTIsLNHvs1WwtbQ3HQ-0KhLiZGlUgjA for 0 found route through test.crypto.ripple.escrow.r9yVLWvhY9pKmJtQMbE6ZyxNaB6hdMDX1J
second-ilp-kit    | [api]   ilp-plugin-bells:plugin sending message: {"id":"99beb457-0320-4ba3-9a7f-596abe67c9d6","ledger":"test.dev.kit2.","from":"test.dev.kit2.connector","to":"test.dev.kit2.admin","ilp":"Bw0AAAAAAAAAAgAAOpgA"} +21ms
second-ilp-kit    | [api]   ilp-plugin-bells:plugin converted to ledger message: {"ledger":"http://ilp-kit2:4010/ledger","from":"http://ilp-kit2:4010/ledger/accounts/connector","to":"http://ilp-kit2:4010/ledger/accounts/admin","data":{"id":"99beb457-0320-4ba3-9a7f-596abe67c9d6","ilp":"Bw0AAAAAAAAAAgAAOpgA"}} +1ms
second-ilp-kit    | [ledger] 2017-07-20T12:27:48.982Z ledger:koa info <-- POST /messages
second-ilp-kit    | [api]   ilp-plugin-bells:factory sending notification to http://ilp-kit2:4010/ledger/accounts/admin +32ms
second-ilp-kit    | [api]   ilp-plugin-bells:translate notify message http://ilp-kit2:4010/ledger/accounts/connector +1ms
second-ilp-kit    | [ledger] 2017-07-20T12:27:49.013Z ledger:koa info --> POST /messages 201 31ms 228B
second-ilp-kit    | [api] 2017-07-20T12:27:49.013Z ilp:ilqp debug got best quote from connector: test.dev.kit2.connector quote: {"connector":"test.dev.kit2.connector","responseType":7,"sourceAmount":"2","sourceHoldDuration":15000}
second-ilp-kit    | [api] 2017-07-20T12:27:49.027Z http INFO   --> POST /payments/quote 200 820ms -
ilp-kit           | [ledger] 2017-07-20T12:28:08.877Z ledger:koa info <-- GET /accounts/connector
ilp-kit           | [ledger] 2017-07-20T12:28:08.901Z ledger:koa info --> GET /accounts/connector 200 23ms 183B
ilp-kit           | [api] 2017-07-20T12:28:09.245Z connector:route-broadcaster debug broadcasting to 0 adjacent ledgers
second-ilp-kit    | [ledger] 2017-07-20T12:28:11.934Z ledger:koa info <-- GET /accounts/connector
second-ilp-kit    | [ledger] 2017-07-20T12:28:11.964Z ledger:koa info <-- GET /accounts/connector
second-ilp-kit    | [ledger] 2017-07-20T12:28:11.982Z ledger:koa info --> GET /accounts/connector 200 48ms 182B
second-ilp-kit    | [ledger] 2017-07-20T12:28:11.999Z ledger:koa info --> GET /accounts/connector 200 35ms 182B
second-ilp-kit    | [api] 2017-07-20T12:28:12.336Z connector:route-broadcaster debug broadcasting to 0 adjacent ledgers
ilp-kit           | [ledger] 2017-07-20T12:28:39.269Z ledger:koa info <-- GET /accounts/connector
ilp-kit           | [ledger] 2017-07-20T12:28:39.280Z ledger:koa info --> GET /accounts/connector 200 11ms 183B
ilp-kit           | [api] 2017-07-20T12:28:39.630Z connector:route-broadcaster debug broadcasting to 0 adjacent ledgers
second-ilp-kit    | [api] 2017-07-20T12:28:42.336Z ilp-routing:routing-tables debug removing expired route ledgerA: test.crypto.ripple.escrow.  ledgerB: test.dev.kit1.  nextHop: test.dev.ledger2.ledger2-testconnector
second-ilp-kit    | [api] 2017-07-20T12:28:42.338Z ilp-routing:routing-tables debug removing expired route ledgerA: test.crypto.ripple.escrow.  ledgerB: test.dev.kit1.  nextHop: test.dev.kit2.connector
second-ilp-kit    | [api] 2017-07-20T12:28:42.345Z ilp-routing:routing-tables debug removing expired route ledgerA: test.dev.kit2.  ledgerB: test.dev.kit1.  nextHop: test.crypto.ripple.escrow.r9yVLWvhY9pKmJtQMbE6ZyxNaB6hdMDX1J
second-ilp-kit    | [api] 2017-07-20T12:28:42.345Z ilp-routing:routing-tables debug removing expired route ledgerA: test.dev.kit2.  ledgerB: test.dev.kit1.  nextHop: test.dev.ledger2.ledger2-testconnector
sentientwaffle commented 7 years ago

@sharafian can you confirm whether or not this is fixed in the latest ilp-connector version?