filecoin-shipyard / browser-retrieval

A p2p network of Filecoin content retrievers
21 stars 8 forks source link

Browser-to-browser transfers not working for me #184

Closed ghost closed 3 years ago

ghost commented 3 years ago

Browser-to-browser transfers aren't working for me. They freeze at the point where the provider side should be updating the chain with the signed voucher. (Full log from client side below.)

Steps to reproduce:

  1. Browse to https://fil-retrieve.market/
  2. Query for bafk2bzacebhlhbcnhmvover42qq5bx773c522skieho6nhtbz7d2ow3f4sw24
  3. Pick offer from QmbizjoNQ3xrEDUqhamoWeoPXmCXvSjaa4YgtDiVpW8srT for 3776 attofil
  4. Everything looks fine in the client log until the first voucher is sent. Can't see what's happening on Provider, but it never responds and completes the transfer.
  5. Client is left stuck in this stage:
Screen Shot 2020-12-08 at 10 56 35 AM

Log on Client:

DEBUG: OperationsQueue.initializeActionsQueue()
DEBUG: Node.initialize(): creating peer id
DEBUG: Node.initialize(): our peer id is QmdXCsjxnB2gTY7yypV4mUZQPEhNGywnzXjzCgeszSSYSy
DEBUG: Node.initialize(): creating libp2p node
DEBUG: Node.initialize(): creating lotus client
DEBUG: Node.initialize(): creating datastore
DEBUG: creating retrieval market client
DEBUG: Client.constructor()
DEBUG: Node.initialize(): creating Provider.js (retrieval market provider)
DEBUG: Provider.initialize()
DEBUG: Provider.updateOptions()
DEBUG: Node.initialize(): creating SocketClient.js (Socket connection)
DEBUG: Node.initialize(): starting libp2p node
DEBUG: Node.initialize(): adding listeners to node
DEBUG: Node.initialize(): getting node info
DEBUG: Node.initialize(): node created
DEBUG: querying peers for bafk2bzacebhlhbcnhmvover42qq5bx773c522skieho6nhtbz7d2ow3f4sw24
DEBUG: publishing message {"messageType":"RetrievalQuery","cid":"bafk2bzacebhlhbcnhmvover42qq5bx773c522skieho6nhtbz7d2ow3f4sw24","peerId":"QmdXCsjxnB2gTY7yypV4mUZQPEhNGywnzXjzCgeszSSYSy"}
DEBUG: received message {"peerId":"QmdXCsjxnB2gTY7yypV4mUZQPEhNGywnzXjzCgeszSSYSy","messageType":"RetrievalQueryResponse","cid":"bafk2bzacebhlhbcnhmvover42qq5bx773c522skieho6nhtbz7d2ow3f4sw24","multiaddrs":["/dns4/webrtc-star-1.browser-retrieval.filecoin.io/tcp/443/wss/p2p-webrtc-star/p2p/QmbizjoNQ3xrEDUqhamoWeoPXmCXvSjaa4YgtDiVpW8srT"],"params":{"wallet":"f1if5yzf6lkmpbd5jmysolhquqwekryxqdna637hq","size":3776,"pricePerByte":1,"paymentInterval":"1048576","paymentIntervalIncrease":"1048576"}}
DEBUG: handleMessage > queryResponse
DEBUG: received message {"peerId":"QmdXCsjxnB2gTY7yypV4mUZQPEhNGywnzXjzCgeszSSYSy","messageType":"RetrievalQueryResponse","cid":"bafk2bzacebhlhbcnhmvover42qq5bx773c522skieho6nhtbz7d2ow3f4sw24","multiaddrs":["/dns4/webrtc-star-1.browser-retrieval.filecoin.io/tcp/443/wss/p2p-webrtc-star/p2p/QmctgsL3Z6oaBEQ6zv3Dc4ZuQLpFfhmtZ2wi9K8B1vTR6v"],"params":{"wallet":"f1cmcxmjlejjusnxs5f3xip47ovpuv7crgv7t7a4i","size":3776,"pricePerByte":1000,"paymentInterval":"1048576","paymentIntervalIncrease":"1048576"}}
DEBUG: handleMessage > queryResponse
DEBUG: received message {"peerId":"QmdXCsjxnB2gTY7yypV4mUZQPEhNGywnzXjzCgeszSSYSy","messageType":"RetrievalQueryResponse","cid":"bafk2bzacebhlhbcnhmvover42qq5bx773c522skieho6nhtbz7d2ow3f4sw24","multiaddrs":["/dns4/webrtc-star-1.browser-retrieval.filecoin.io/tcp/443/wss/p2p-webrtc-star/p2p/QmPTMBWMZsS92xBzetS7GBFSSnyr25RPcH9Svh9cUVAWNV"],"params":{"wallet":"f1w46i6fahlop267vmsy7kvmtps7cgve73duciuqa","size":3776,"pricePerByte":1000,"paymentInterval":"1048576","paymentIntervalIncrease":"1048576"}}
DEBUG: handleMessage > queryResponse
DEBUG:  Node.downloadFile:
  cid:'bafk2bzacebhlhbcnhmvover42qq5bx773c522skieho6nhtbz7d2ow3f4sw24'
  offer={ address: '/dns4/webrtc-star-1.browser-retrieval.filecoin.io/tcp/443/wss/p2p-webrtc-star/p2p/QmbizjoNQ3xrEDUqhamoWeoPXmCXvSjaa4YgtDiVpW8srT',
  price: 3776,
  params: 
   { wallet: 'f1if5yzf6lkmpbd5jmysolhquqwekryxqdna637hq',
     size: 3776,
     pricePerByte: 1,
     paymentInterval: '1048576',
     paymentIntervalIncrease: '1048576' } }
DEBUG: Node._downloadFromPeer: starting
DEBUG: Node._downloadFromPeer:  offer={"address":"/dns4/webrtc-star-1.browser-retrieval.filecoin.io/tcp/443/wss/p2p-webrtc-star/p2p/QmbizjoNQ3xrEDUqhamoWeoPXmCXvSjaa4YgtDiVpW8srT","price":3776,"params":{"wallet":"f1if5yzf6lkmpbd5jmysolhquqwekryxqdna637hq","size":3776,"pricePerByte":1,"paymentInterval":"1048576","paymentIntervalIncrease":"1048576"}}
DEBUG: Node._downloadFromPeer:
  CID: bafk2bzacebhlhbcnhmvover42qq5bx773c522skieho6nhtbz7d2ow3f4sw24
  from: /dns4/webrtc-star-1.browser-retrieval.filecoin.io/tcp/443/wss/p2p-webrtc-star/p2p/QmbizjoNQ3xrEDUqhamoWeoPXmCXvSjaa4YgtDiVpW8srT
  price: 3776 attoFil
DEBUG: Client.retrieve()
DEBUG: MIKE: retrieve called with
  cid='bafk2bzacebhlhbcnhmvover42qq5bx773c522skieho6nhtbz7d2ow3f4sw24'
  dealParams='{ wallet: 'f1if5yzf6lkmpbd5jmysolhquqwekryxqdna637hq',
  size: 3776,
  pricePerByte: 1,
  paymentInterval: '1048576',
  paymentIntervalIncrease: '1048576' }'
  peerMultiaddr=/dns4/webrtc-star-1.browser-retrieval.filecoin.io/tcp/443/wss/p2p-webrtc-star/p2p/QmbizjoNQ3xrEDUqhamoWeoPXmCXvSjaa4YgtDiVpW8srT
  peerWallet=undefined
DEBUG: dialing peer /dns4/webrtc-star-1.browser-retrieval.filecoin.io/tcp/443/wss/p2p-webrtc-star/p2p/QmbizjoNQ3xrEDUqhamoWeoPXmCXvSjaa4YgtDiVpW8srT
DEBUG: Datastore.putContent:  options=undefined
DEBUG: Client.sendDealProposal: sending deal proposal 1773841126910239
DEBUG: Client.handleMessage(): message: { dealId: '1773841126910239', status: 'DealStatusAccepted' }
DEBUG: Client.handleMessage(): case dealStatuses.accepted
DEBUG: Client.setupPaymentChannel(): setting up payment channel 1773841126910239
DEBUG: Client.setupPaymentChannel(): PCH creation parameters:
  pchAmount='3776'
  toAddr='f1if5yzf6lkmpbd5jmysolhquqwekryxqdna637hq'
DEBUG: Lotus.createPaymentChannel: [from:f1jej4xfb2347wwy53mg3i3usje3exrp7mjk7i57a, fromKey:*******************, to:f1if5yzf6lkmpbd5jmysolhquqwekryxqdna637hq, amount:3776]
DEBUG: entering Lotus.getNonce
DEBUG: Lotus.getNonce:
  addr=f1jej4xfb2347wwy53mg3i3usje3exrp7mjk7i57a
  this.headers={ Authorization: 'Bearer eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJBbGxvdyI6WyJyZWFkIiwid3JpdGUiLCJzaWduIiwiYWRtaW4iXX0.jtLE4n-cWr1lzvFVDj9wupSHqDJgvQFIRP2takFTbAo' }
  this.lotusEndpoint=https://cloud-lotus-1.browser-retrieval.filecoin.io/rpc/v0
INFO: Nonce (f1jej4xfb2347wwy53mg3i3usje3exrp7mjk7i57a) = 123
DEBUG: leaving Lotus.getNonce (ret = 123)
DEBUG: Lotus.getNonce => 123
DEBUG: Lotus.createPaymentChannel: nonce=123
DEBUG: entering Lotus.gesGasEstimation
DEBUG: Lotus.gesGasEstimation:
  message={ to: 'f01',
  from: 'f1jej4xfb2347wwy53mg3i3usje3exrp7mjk7i57a',
  nonce: 123,
  value: '3776',
  gaslimit: 10000000,
  gasfeecap: '16251176117',
  gaspremium: '140625002',
  method: 2,
  params: 'gtgqWBkAAVUAFGZpbC8yL3BheW1lbnRjaGFubmVsWC2CVQFJE8uUOt8/a2O7YbaN0kkmyXi/7FUBQXuMl8tTHhH1LMScs8KQsRUcXgM=' }
  this.headers={ Authorization: 'Bearer eyJhbGciOiJIUzI1NiIsInR5cCI6IkpXVCJ9.eyJBbGxvdyI6WyJyZWFkIiwid3JpdGUiLCJzaWduIiwiYWRtaW4iXX0.jtLE4n-cWr1lzvFVDj9wupSHqDJgvQFIRP2takFTbAo' }
  this.lotusEndpoint=https://cloud-lotus-1.browser-retrieval.filecoin.io/rpc/v0
DEBUG: leaving Lotus.gasEstimation (returned message= { to: 'f01',
  from: 'f1jej4xfb2347wwy53mg3i3usje3exrp7mjk7i57a',
  nonce: 123,
  value: '3776',
  gaslimit: 20000000,
  gasfeecap: '10000000000',
  gaspremium: '140625002',
  method: 2,
  params: 'gtgqWBkAAVUAFGZpbC8yL3BheW1lbnRjaGFubmVsWC2CVQFJE8uUOt8/a2O7YbaN0kkmyXi/7FUBQXuMl8tTHhH1LMScs8KQsRUcXgM=' })
DEBUG: Lotus.createPaymentChannel: signedCreateMessage={ Message: 
   { From: 'f1jej4xfb2347wwy53mg3i3usje3exrp7mjk7i57a',
     GasFeeCap: '10000000000',
     GasLimit: 20000000,
     GasPremium: '140625002',
     Method: 2,
     Nonce: 123,
     Params: 'gtgqWBkAAVUAFGZpbC8yL3BheW1lbnRjaGFubmVsWC2CVQFJE8uUOt8/a2O7YbaN0kkmyXi/7FUBQXuMl8tTHhH1LMScs8KQsRUcXgM=',
     To: 'f01',
     Value: '3776' },
  Signature: 
   { Data: 'U3JNkbde8LFA29V+aWIeTC6Y2wjqJWjIflrHTj/hl9ZFu7q4uPDrwOYTXzsONtd8EvFiL8ptaizbCEjEnpGd2wA=',
     Type: 1 } }
DEBUG: entering Lotus.mpoolPush (signedMessage={ Message: 
   { From: 'f1jej4xfb2347wwy53mg3i3usje3exrp7mjk7i57a',
     GasFeeCap: '10000000000',
     GasLimit: 20000000,
     GasPremium: '140625002',
     Method: 2,
     Nonce: 123,
     Params: 'gtgqWBkAAVUAFGZpbC8yL3BheW1lbnRjaGFubmVsWC2CVQFJE8uUOt8/a2O7YbaN0kkmyXi/7FUBQXuMl8tTHhH1LMScs8KQsRUcXgM=',
     To: 'f01',
     Value: '3776' },
  Signature: 
   { Data: 'U3JNkbde8LFA29V+aWIeTC6Y2wjqJWjIflrHTj/hl9ZFu7q4uPDrwOYTXzsONtd8EvFiL8ptaizbCEjEnpGd2wA=',
     Type: 1 } })
DEBUG: Lotus.mpoolPush: response.data = { jsonrpc: '2.0',
  result: { '/': 'bafy2bzacedohibn2jcrl4fekj6hgl4m4yy6tnu6ot75rlj54zfeo5msyleasa' },
  id: 1 }
DEBUG: leaving Lotus.mpoolPush => { '/': 'bafy2bzacedohibn2jcrl4fekj6hgl4m4yy6tnu6ot75rlj54zfeo5msyleasa' }
DEBUG: Lotus.mpoolPush => { '/': 'bafy2bzacedohibn2jcrl4fekj6hgl4m4yy6tnu6ot75rlj54zfeo5msyleasa' }
INFO: msgCid = { '/': 'bafy2bzacedohibn2jcrl4fekj6hgl4m4yy6tnu6ot75rlj54zfeo5msyleasa' }
DEBUG: entering Lotus.stateWaitMsg(cid='[object Object]')
INFO: begining StateWaitMsg. This will take a while...
DEBUG: Lotus.stateWaitMsg => { jsonrpc: '2.0',
  result: 
   { Message: { '/': 'bafy2bzacedohibn2jcrl4fekj6hgl4m4yy6tnu6ot75rlj54zfeo5msyleasa' },
     Receipt: 
      { ExitCode: 0,
        Return: 'gkQA2IkGVQLae1/t835rEPmYnElKeZNH9esbhQ==',
        GasUsed: 10925737 },
     ReturnDec: 
      { IDAddress: 'f099544',
        RobustAddress: 'f23j5v73ptpzvrb6mytreuu6mti726wg4fm5oylti' },
     TipSet: [ [Object] ],
     Height: 304685 },
  id: 1 } ; { Message: { '/': 'bafy2bzacedohibn2jcrl4fekj6hgl4m4yy6tnu6ot75rlj54zfeo5msyleasa' },
  Receipt: 
   { ExitCode: 0,
     Return: 'gkQA2IkGVQLae1/t835rEPmYnElKeZNH9esbhQ==',
     GasUsed: 10925737 },
  ReturnDec: 
   { IDAddress: 'f099544',
     RobustAddress: 'f23j5v73ptpzvrb6mytreuu6mti726wg4fm5oylti' },
  TipSet: [ { '/': 'bafy2bzacebdbk7nzegnl5fklbpe43nlu5k4uak3l5wskijl6ot7e3yml2ps5a' } ],
  Height: 304685 }
DEBUG: Lotus.createPaymentChannel: response.data.result: { Message: { '/': 'bafy2bzacedohibn2jcrl4fekj6hgl4m4yy6tnu6ot75rlj54zfeo5msyleasa' },
  Receipt: 
   { ExitCode: 0,
     Return: 'gkQA2IkGVQLae1/t835rEPmYnElKeZNH9esbhQ==',
     GasUsed: 10925737 },
  ReturnDec: 
   { IDAddress: 'f099544',
     RobustAddress: 'f23j5v73ptpzvrb6mytreuu6mti726wg4fm5oylti' },
  TipSet: [ { '/': 'bafy2bzacebdbk7nzegnl5fklbpe43nlu5k4uak3l5wskijl6ot7e3yml2ps5a' } ],
  Height: 304685 }
DEBUG: Lotus.createPaymentChannel: PCH Addresses = {id address:f099544,robust:f23j5v73ptpzvrb6mytreuu6mti726wg4fm5oylti}
DEBUG: Lotus.createPaymentChannel: leaving => f23j5v73ptpzvrb6mytreuu6mti726wg4fm5oylti
DEBUG: Client.setupPaymentChannel(): paymentChannel: f23j5v73ptpzvrb6mytreuu6mti726wg4fm5oylti
DEBUG: Client.setupPaymentChannel(): sending payment channel ready (pchAddr='undefined') for dealId='1773841126910239'
DEBUG: Client.setupPaymentChannel(): done
DEBUG: Client.handleMessage(): message: { dealId: '1773841126910239',
  status: 'DealStatusFundsNeededLastPayment',
  blocks: [ { type: 'Buffer', data: [Object] } ] }
DEBUG: Client.handleMessage(): case dealStatuses.fundsNeededLastPayment
DEBUG: Client.receiveBlocks(): received 1 blocks deal id: 1773841126910239
DEBUG: Client.finishImport(): finishing import 1773841126910239
DEBUG: Datastore.putContent.put writing CID: QmSvuhdF4uM3cwXcHd8XrpbdHVPNkhQZiXk91nLb5ihoRp
DEBUG: Datastore.putContent:  returning {cid:{ version: 0,
  codec: 'dag-pb',
  multihash: 
   { '0': 18,
     '1': 32,
     '2': 68,
     '3': 53,
     '4': 114,
     '5': 70,
     '6': 189,
     '7': 149,
     '8': 219,
     '9': 172,
     '10': 198,
     '11': 170,
     '12': 69,
     '13': 57,
     '14': 158,
     '15': 117,
     '16': 26,
     '17': 121,
     '18': 229,
     '19': 169,
     '20': 16,
     '21': 14,
     '22': 150,
     '23': 87,
     '24': 174,
     '25': 161,
     '26': 185,
     '27': 100,
     '28': 224,
     '29': 144,
     '30': 62,
     '31': 80,
     '32': 231,
     '33': 103 },
  multibaseName: 'base58btc' }, size:3776
DEBUG: Client.sendPayment(): sending payment 1773841126910239 (isLastVoucher=true)
DEBUG: Lotus.createSignedVoucher: args: pch='f23j5v73ptpzvrb6mytreuu6mti726wg4fm5oylti', amountAttoFil='3776', nonce='1'
DEBUG: Lotus.createSignedVoucher: returning signedVoucher = ''i1UC2ntf7fN+axD5mJxJSnmTR/XrG4UAAED2AAFDAA7AAIBYQgFch21j3sLyCYWqq3WrhVitdr0RCNTejHJccBl6bjJ7UF1qurJoZvlWv+jvFj32vADTTfJjBi+c1zhcwKJizOV1AA==''
DEBUG: Client.sendPayment(): sv = 'i1UC2ntf7fN+axD5mJxJSnmTR/XrG4UAAED2AAFDAA7AAIBYQgFch21j3sLyCYWqq3WrhVitdr0RCNTejHJccBl6bjJ7UF1qurJoZvlWv+jvFj32vADTTfJjBi+c1zhcwKJizOV1AA=='
DEBUG: Client.sendPayment() message:
{
  "dealId": "1773841126910239",
  "status": "DealStatusLastPaymentSent",
  "paymentChannel": "f23j5v73ptpzvrb6mytreuu6mti726wg4fm5oylti",
  "signedVoucher": "i1UC2ntf7fN+axD5mJxJSnmTR/XrG4UAAED2AAFDAA7AAIBYQgFch21j3sLyCYWqq3WrhVitdr0RCNTejHJccBl6bjJ7UF1qurJoZvlWv+jvFj32vADTTfJjBi+c1zhcwKJizOV1AA=="
}
ghost commented 3 years ago

Caused by #183?