ExchangeUnion / xud

Exchange Union Daemon 🔁 ⚡️
https://exchangeunion.com
GNU Affero General Public License v3.0
115 stars 44 forks source link

cancel order failure on partial taking #506

Closed offerm closed 6 years ago

offerm commented 6 years ago

See what I did and what I got.

admins-MacBook-Pro-2:xud admin$ ./bin/xucli -p 7002 connect 0235584e2ac9a34a13ce6f6dc9fb8aa1e7918d7701f0b4b69dc002887e6b3fbba3@localhost:8885
(node:70263) [DEP0005] DeprecationWarning: Buffer() is deprecated due to security and usability issues. Please use the Buffer.alloc(), Buffer.allocUnsafe(), or Buffer.from() methods instead.
success
admins-MacBook-Pro-2:xud admin$ ./bin/xucli -p 7001 buy 0.004 LTC/BTC  0.96
(node:70264) [DEP0005] DeprecationWarning: Buffer() is deprecated due to security and usability issues. Please use the Buffer.alloc(), Buffer.allocUnsafe(), or Buffer.from() methods instead.
{
  "matchesList": [],
  "remainingOrder": {
    "price": 0.96,
    "quantity": 0.004,
    "pairId": "LTC/BTC",
    "peerPubKey": "",
    "id": "762937e1-bc92-11e8-9f43-a5047fcd0223",
    "localId": "762937e0-bc92-11e8-9f43-a5047fcd0223",
    "createdAt": 1537419786846,
    "invoice": "",
    "canceled": false
  }
}
admins-MacBook-Pro-2:xud admin$ ./bin/xucli -p 7002 sell 0.003 LTC/BTC  market
(node:70265) [DEP0005] DeprecationWarning: Buffer() is deprecated due to security and usability issues. Please use the Buffer.alloc(), Buffer.allocUnsafe(), or Buffer.from() methods instead.
{
  "matchesList": [
    {
      "maker": {
        "price": 0.96,
        "quantity": 0.003,
        "pairId": "LTC/BTC",
        "peerPubKey": "0235584e2ac9a34a13ce6f6dc9fb8aa1e7918d7701f0b4b69dc002887e6b3fbba3",
        "id": "762937e1-bc92-11e8-9f43-a5047fcd0223",
        "localId": "",
        "createdAt": 1537419786848,
        "invoice": "",
        "canceled": false
      },
      "taker": {
        "price": 0,
        "quantity": -0.003,
        "pairId": "LTC/BTC",
        "peerPubKey": "",
        "id": "77c18b21-bc92-11e8-a8e6-a7e8fdc9cfa2",
        "localId": "77c18b20-bc92-11e8-a8e6-a7e8fdc9cfa2",
        "createdAt": 1537419789522,
        "invoice": "",
        "canceled": false
      }
    }
  ]
}
9/20/2018, 8:03:09 AM [ORDERBOOK] debug: order match: {"maker":{"pairId":"LTC/BTC","price":0.96,"quantity":0.003,"id":"762937e1-bc92-11e8-9f43-a5047fcd0223","peerPubKey":"0235584e2ac9a34a13ce6f6dc9fb8aa1e7918d7701f0b4b69dc002887e6b3fbba3","createdAt":1537419786848},"taker":{"pairId":"LTC/BTC","price":0,"quantity":-0.003,"localId":"77c18b20-bc92-11e8-a8e6-a7e8fdc9cfa2","id":"77c18b21-bc92-11e8-a8e6-a7e8fdc9cfa2","createdAt":1537419789522}}
9/20/2018, 8:03:09 AM [SWAPS] debug: New deal: {"takerCurrency":"BTC","makerCurrency":"LTC","takerAmount":288000,"makerAmount":300000,"takerCltvDelta":144,"r_hash":"6acb27197517d5a12d7c7be554b985df0acee87555e78e00d2cac3c30483a220","orderId":"762937e1-bc92-11e8-9f43-a5047fcd0223","pairId":"LTC/BTC","proposedQuantity":-0.003,"phase":0,"state":0,"stateReason":"","r_preimage":"4536dda6537b626146d99f79751bfa7d447a387aba6c0ea038359be951852909","myRole":0,"createTime":1537419789524}
9/20/2018, 8:03:09 AM [SWAPS] debug: Requesting deal: {"takerCurrency":"BTC","makerCurrency":"LTC","takerAmount":288000,"makerAmount":300000,"takerCltvDelta":144,"r_hash":"6acb27197517d5a12d7c7be554b985df0acee87555e78e00d2cac3c30483a220","orderId":"762937e1-bc92-11e8-9f43-a5047fcd0223","pairId":"LTC/BTC","proposedQuantity":-0.003,"phase":0,"state":0,"stateReason":"","r_preimage":"4536dda6537b626146d99f79751bfa7d447a387aba6c0ea038359be951852909","myRole":0,"createTime":1537419789524}
9/20/2018, 8:03:09 AM [P2P] debug: received swapResponse from 0235584e2ac9a34a13ce6f6dc9fb8aa1e7918d7701f0b4b69dc002887e6b3fbba3: {"makerCltvDelta":1152,"r_hash":"6acb27197517d5a12d7c7be554b985df0acee87555e78e00d2cac3c30483a220","quantity":-0.003}
9/20/2018, 8:03:09 AM [SWAPS] info: ResolveHash starting with hash: 6acb27197517d5a12d7c7be554b985df0acee87555e78e00d2cac3c30483a220
9/20/2018, 8:03:09 AM [SWAPS] debug: Executing taker code
9/20/2018, 8:03:09 AM [SWAPS] debug: Amount received for preImage 4536dda6537b626146d99f79751bfa7d447a387aba6c0ea038359be951852909
9/20/2018, 8:03:10 AM [P2P] verbose: canceled order from 0235584e2ac9a34a13ce6f6dc9fb8aa1e7918d7701f0b4b69dc002887e6b3fbba3: {"orderId":"762937e1-bc92-11e8-9f43-a5047fcd0223","pairId":"LTC/BTC"}
{ AssertionError [ERR_ASSERTION]: order quantity must equal quantityToDecrease
    at OrderBook.removePeerOrder (/Users/admin/github/xud/dist/orderbook/OrderBook.js:259:33)
    at Pool.pool.on.order (/Users/admin/github/xud/dist/orderbook/OrderBook.js:50:72)
    at Pool.emit (events.js:182:13)
    at Pool.<anonymous> (/Users/admin/github/xud/dist/p2p/Pool.js:275:26)
    at Generator.next (<anonymous>)
    at /Users/admin/github/xud/dist/p2p/Pool.js:7:71
    at new Promise (<anonymous>)
    at __awaiter (/Users/admin/github/xud/dist/p2p/Pool.js:3:12)
    at Pool.handlePacket (/Users/admin/github/xud/dist/p2p/Pool.js:264:47)
    at Pool.<anonymous> (/Users/admin/github/xud/dist/p2p/Pool.js:394:28)
    at Generator.next (<anonymous>)
    at /Users/admin/github/xud/dist/p2p/Pool.js:7:71
    at new Promise (<anonymous>)
    at __awaiter (/Users/admin/github/xud/dist/p2p/Pool.js:3:12)
    at Peer.peer.on (/Users/admin/github/xud/dist/p2p/Pool.js:393:43)
    at Peer.emit (events.js:182:13)
    at Parser.Peer.handlePacket (/Users/admin/github/xud/dist/p2p/Peer.js:376:30)
    at Parser.emit (events.js:182:13)
    at Parser.parsePacket (/Users/admin/github/xud/dist/p2p/Parser.js:100:22)
    at Parser.feed (/Users/admin/github/xud/dist/p2p/Parser.js:91:22)
    at Socket.socket.on (/Users/admin/github/xud/dist/p2p/Peer.js:324:29)
    at Socket.emit (events.js:182:13)
  generatedMessage: false,
  name: 'AssertionError [ERR_ASSERTION]',
  code: 'ERR_ASSERTION',
  actual: false,
  expected: true,
  operator: '==' }
/Users/admin/github/xud/dist/bootstrap.js:13
        throw err;
        ^

AssertionError [ERR_ASSERTION]: order quantity must equal quantityToDecrease
    at OrderBook.removePeerOrder (/Users/admin/github/xud/dist/orderbook/OrderBook.js:259:33)
    at Pool.pool.on.order (/Users/admin/github/xud/dist/orderbook/OrderBook.js:50:72)
    at Pool.emit (events.js:182:13)
    at Pool.<anonymous> (/Users/admin/github/xud/dist/p2p/Pool.js:275:26)
    at Generator.next (<anonymous>)
    at /Users/admin/github/xud/dist/p2p/Pool.js:7:71
    at new Promise (<anonymous>)
    at __awaiter (/Users/admin/github/xud/dist/p2p/Pool.js:3:12)
    at Pool.handlePacket (/Users/admin/github/xud/dist/p2p/Pool.js:264:47)
    at Pool.<anonymous> (/Users/admin/github/xud/dist/p2p/Pool.js:394:28)
    at Generator.next (<anonymous>)
    at /Users/admin/github/xud/dist/p2p/Pool.js:7:71
    at new Promise (<anonymous>)
    at __awaiter (/Users/admin/github/xud/dist/p2p/Pool.js:3:12)
    at Peer.peer.on (/Users/admin/github/xud/dist/p2p/Pool.js:393:43)
    at Peer.emit (events.js:182:13)
    at Parser.Peer.handlePacket (/Users/admin/github/xud/dist/p2p/Peer.js:376:30)
    at Parser.emit (events.js:182:13)
    at Parser.parsePacket (/Users/admin/github/xud/dist/p2p/Parser.js:100:22)
    at Parser.feed (/Users/admin/github/xud/dist/p2p/Parser.js:91:22)
    at Socket.socket.on (/Users/admin/github/xud/dist/p2p/Peer.js:324:29)
    at Socket.emit (events.js:182:13)
sangaman commented 6 years ago

I believe this is related to #478 - the order is being invalidated twice on swap. All the more reason we don't send order invalidation packets to the peer we just swapped the order with. I created a test case for the order book to try to simulate locally and it passes, I'll open a PR for that because canceling a partially filled order is a good test case to have but it's separate from this. I think separate from fixing #478 we'd probably also need to gracefully handle the case where a peer tries to invalidate an order for a greater quantity than what we currently show available, which is what's happening here.

offerm commented 6 years ago

Not sure I understand the reason for the failure here. Can you explain this before we get for a solution?

I also not follow the terminology of invalidated. Does it mean removed? later you mentioned cancel

It is also not clear to me why the order was removed at by the maker when only part of it was executed.

sangaman commented 6 years ago

Yeah, an invalidation is the term for the packet to tell peers that one of our orders is no longer available/valid. The cause can be either due to cancellation or to the order being filled, but the peer doesn't have to know that.

I haven't dug very deeply into this yet but I believe what's happening is this:

Exchange A places 0.004 buy order Exchange B places 0.003 matching sell order Swap successful, exchange B reduces the quantity of the buy order to 0.001 Exchange A broadcasts to all its peers (here is the problem, tracked in #478, it should not send packet to the peer it swapped with) an order invalidation packet saying "hey, 0.003 of my 0.004 buy order is no longer available Exchange B receives the packet, and tries to reduce the quantity of the order by 0.003, but that's more than the current quantity of the order which is 0.001, so we get this error

offerm commented 6 years ago

Well, the invalidation message can be "hey, only 0.001 letf". This can work also with the taker.

In our case the message is "hey, undefined of my 0.004 buy order is no longer available"

9/20/2018, 6:16:42 PM [SWAPS] debug: Executing taker code
9/20/2018, 6:16:42 PM [SWAPS] debug: Amount received for preImage ce6e2b054d0e0349bc5b1d25edfa3959500502dae0c4ec54a4f79c7923d48080
9/20/2018, 6:16:42 PM [P2P] verbose: canceled order from 0235584e2ac9a34a13ce6f6dc9fb8aa1e7918d7701f0b4b69dc002887e6b3fbba3: {"orderId":"2c603fe1-bce8-11e8-bbca-2df4bee4f24d","pairId":"LTC/BTC"}
9/20/2018, 6:16:42 PM [ORDERBOOK] info: order.quantity = 0.001
9/20/2018, 6:16:42 PM [ORDERBOOK] info: quantityToDecrease = undefined
{ AssertionError [ERR_ASSERTION]: order quantity must equal quantityToDecrease
    at OrderBook.removePeerOrder (/Users/admin/github/xud/dist/orderbook/OrderBook.js:261:33)
    at Pool.pool.on.order (/Users/admin/github/xud/dist/orderbook/OrderBook.js:50:72)
    at Pool.emit (events.js:182:13)
    at Pool.<anonymous> (/Users/admin/github/xud/dist/p2p/Pool.js:275:26)
    at Generator.next (<anonymous>)
    at /Users/admin/github/xud/dist/p2p/Pool.js:7:71