search

ExchangeUnion / xud

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

Errors when starting XUD with a new database #415

Closed offerm closed 6 years ago

offerm commented 6 years ago

Starting XUD (master). Letting XUD to create the database:

8/28/2018, 11:05:11 PM [GLOBAL] info: config loaded
8/28/2018, 11:05:11 PM [GLOBAL] info: Local nodePubKey is 03e12d9dc27f966d0e02ab242912ddd088d86247bd8d22887ffcf496cc57709bda
8/28/2018, 11:05:12 PM [LND] info: LndClient status: DISCONNECTED
8/28/2018, 11:05:12 PM [LND] info: trying to verify connection to lnd with uri: localhost:10002
8/28/2018, 11:05:12 PM [LND] info: LndClient status: DISCONNECTED
8/28/2018, 11:05:12 PM [LND] info: trying to verify connection to lnd with uri: localhost:10001
(node:75395) [DEP0005] DeprecationWarning: Buffer() is deprecated due to security and usability issues. Please use the Buffer.alloc(), Buffer.allocUnsafe(), or Buffer.from() methods instead.
8/28/2018, 11:05:12 PM [LND] info: LndClient status: CONNECTION_VERIFIED
8/28/2018, 11:05:12 PM [LND] info: LndClient status: CONNECTION_VERIFIED
8/28/2018, 11:05:12 PM [P2P] info: retrieved external IP: 84.111.139.147
8/28/2018, 11:05:12 PM [P2P] info: Connecting to known / previously connected peers
8/28/2018, 11:05:12 PM [P2P] info: p2p server listening on 0.0.0.0:8885
8/28/2018, 11:05:12 PM [RPC] info: gRPC server listening on localhost:7001
8/28/2018, 11:05:12 PM [P2P] debug: Connected pre-handshake to peer xud1.test.exchangeunion.com:8885
8/28/2018, 11:05:12 PM [P2P] debug: Connected pre-handshake to peer xud2.test.exchangeunion.com:8885
8/28/2018, 11:05:12 PM [P2P] debug: Connected pre-handshake to peer xud3.test.exchangeunion.com:8885
8/28/2018, 11:05:13 PM [P2P] info: Completed start-up connections to known peers.
8/28/2018, 11:05:13 PM [P2P] verbose: received 0 orders from 02b66438730d1fcdf4a4ae5d3d73e847a272f160fee2938e132b52cab0a0d9cfc6
8/28/2018, 11:05:13 PM [P2P] info: Node 03fd337659e99e628d0487e4f87acf93e353db06f754dccc402f2de1b857a319d0 at (35.229.81.83) already connected
8/28/2018, 11:05:13 PM [P2P] info: Node 028599d05b18c0c3f8028915a17d603416f7276c822b6b2d20e71a3502bd0f9e0a at (35.231.171.148) already connected
8/28/2018, 11:05:13 PM [P2P] debug: Connected pre-handshake to peer 127.0.0.1:63151
8/28/2018, 11:05:13 PM [P2P] debug: Connected pre-handshake to peer localhost:8885
8/28/2018, 11:05:13 PM [P2P] warn: error while opening connection to peer 03f20a33e4c2b6d384bcd1a0859d0eada2a387f94396235674548e9c0cd4c9d7a6: connect ECONNREFUSED 127.0.0.1:9090
8/28/2018, 11:05:13 PM [P2P] warn: error while opening connection to peer 0284643297670606e6f381b8dff161254a8ea1db927eed6c2d33c2015ab4b4dbd6: Node at localhost:8885 sent pub key 03e12d9dc27f966d0e02ab242912ddd088d86247bd8d22887ffcf496cc57709bda, expected 0284643297670606e6f381b8dff161254a8ea1db927eed6c2d33c2015ab4b4dbd6
8/28/2018, 11:05:13 PM [P2P] verbose: received 0 orders from 03e12d9dc27f966d0e02ab242912ddd088d86247bd8d22887ffcf496cc57709bda
8/28/2018, 11:05:13 PM [P2P] info: Node 02b66438730d1fcdf4a4ae5d3d73e847a272f160fee2938e132b52cab0a0d9cfc6 at (35.196.118.79) already connected
8/28/2018, 11:05:13 PM [P2P] info: Node 03fd337659e99e628d0487e4f87acf93e353db06f754dccc402f2de1b857a319d0 at (35.229.81.83) already connected
8/28/2018, 11:05:13 PM [P2P] info: Node 028599d05b18c0c3f8028915a17d603416f7276c822b6b2d20e71a3502bd0f9e0a at (35.231.171.148) already connected
8/28/2018, 11:05:13 PM [P2P] info: Peer 03e12d9dc27f966d0e02ab242912ddd088d86247bd8d22887ffcf496cc57709bda socket closed
8/28/2018, 11:05:13 PM [P2P] verbose: received 0 orders from 03fd337659e99e628d0487e4f87acf93e353db06f754dccc402f2de1b857a319d0
8/28/2018, 11:05:13 PM [P2P] info: Node 02b66438730d1fcdf4a4ae5d3d73e847a272f160fee2938e132b52cab0a0d9cfc6 at (35.196.118.79) already connected
8/28/2018, 11:05:13 PM [P2P] info: Node 028599d05b18c0c3f8028915a17d603416f7276c822b6b2d20e71a3502bd0f9e0a at (35.231.171.148) already connected
8/28/2018, 11:05:13 PM [P2P] info: Node 03fd337659e99e628d0487e4f87acf93e353db06f754dccc402f2de1b857a319d0 at (35.229.81.83) already connected
8/28/2018, 11:05:13 PM [P2P] verbose: received 0 orders from 028599d05b18c0c3f8028915a17d603416f7276c822b6b2d20e71a3502bd0f9e0a
8/28/2018, 11:05:13 PM [P2P] info: Node 02b66438730d1fcdf4a4ae5d3d73e847a272f160fee2938e132b52cab0a0d9cfc6 at (35.196.118.79) already connected
8/28/2018, 11:05:13 PM [P2P] info: Node 03fd337659e99e628d0487e4f87acf93e353db06f754dccc402f2de1b857a319d0 at (35.229.81.83) already connected
8/28/2018, 11:05:13 PM [P2P] info: Node 028599d05b18c0c3f8028915a17d603416f7276c822b6b2d20e71a3502bd0f9e0a at (35.231.171.148) already connected
8/28/2018, 11:05:13 PM [P2P] debug: Connected pre-handshake to peer 127.0.0.1:63167
8/28/2018, 11:05:13 PM [P2P] warn: error while opening connection to peer 03f20a33e4c2b6d384bcd1a0859d0eada2a387f94396235674548e9c0cd4c9d7a6: connect ECONNREFUSED 127.0.0.1:9090
8/28/2018, 11:05:13 PM [P2P] debug: Connected pre-handshake to peer localhost:8885
8/28/2018, 11:05:13 PM [P2P] debug: Connected pre-handshake to peer 127.0.0.1:63181
8/28/2018, 11:05:13 PM [P2P] debug: Connected pre-handshake to peer localhost:8885
8/28/2018, 11:05:13 PM [P2P] warn: error while opening connection to peer 03f20a33e4c2b6d384bcd1a0859d0eada2a387f94396235674548e9c0cd4c9d7a6: connect ECONNREFUSED 127.0.0.1:9090
8/28/2018, 11:05:13 PM [P2P] warn: error while opening connection to peer 0284643297670606e6f381b8dff161254a8ea1db927eed6c2d33c2015ab4b4dbd6: Node at localhost:8885 sent pub key 03e12d9dc27f966d0e02ab242912ddd088d86247bd8d22887ffcf496cc57709bda, expected 0284643297670606e6f381b8dff161254a8ea1db927eed6c2d33c2015ab4b4dbd6
8/28/2018, 11:05:13 PM [P2P] verbose: received 0 orders from 03e12d9dc27f966d0e02ab242912ddd088d86247bd8d22887ffcf496cc57709bda
8/28/2018, 11:05:13 PM [P2P] info: Node 02b66438730d1fcdf4a4ae5d3d73e847a272f160fee2938e132b52cab0a0d9cfc6 at (35.196.118.79) already connected
8/28/2018, 11:05:13 PM [P2P] info: Node 03fd337659e99e628d0487e4f87acf93e353db06f754dccc402f2de1b857a319d0 at (35.229.81.83) already connected
8/28/2018, 11:05:13 PM [P2P] info: Node 028599d05b18c0c3f8028915a17d603416f7276c822b6b2d20e71a3502bd0f9e0a at (35.231.171.148) already connected
8/28/2018, 11:05:13 PM [P2P] warn: error while opening connection to peer 0284643297670606e6f381b8dff161254a8ea1db927eed6c2d33c2015ab4b4dbd6: Node at localhost:8885 sent pub key 03e12d9dc27f966d0e02ab242912ddd088d86247bd8d22887ffcf496cc57709bda, expected 0284643297670606e6f381b8dff161254a8ea1db927eed6c2d33c2015ab4b4dbd6
8/28/2018, 11:05:13 PM [P2P] verbose: received 0 orders from 03e12d9dc27f966d0e02ab242912ddd088d86247bd8d22887ffcf496cc57709bda
8/28/2018, 11:05:13 PM [P2P] info: Node 02b66438730d1fcdf4a4ae5d3d73e847a272f160fee2938e132b52cab0a0d9cfc6 at (35.196.118.79) already connected
8/28/2018, 11:05:13 PM [P2P] info: Node 03fd337659e99e628d0487e4f87acf93e353db06f754dccc402f2de1b857a319d0 at (35.229.81.83) already connected
8/28/2018, 11:05:13 PM [P2P] info: Node 028599d05b18c0c3f8028915a17d603416f7276c822b6b2d20e71a3502bd0f9e0a at (35.231.171.148) already connected
8/28/2018, 11:05:13 PM [P2P] info: Peer 03e12d9dc27f966d0e02ab242912ddd088d86247bd8d22887ffcf496cc57709bda socket closed
{ SequelizeUniqueConstraintError: Validation error
    at Query.formatError (/Users/admin/github/xud/node_modules/sequelize/lib/dialects/mysql/query.js:226:16)
    at Query.handler [as onResult] (/Users/admin/github/xud/node_modules/sequelize/lib/dialects/mysql/query.js:68:23)
    at Query.Command.execute (/Users/admin/github/xud/node_modules/mysql2/lib/commands/command.js:30:12)
    at Connection.handlePacket (/Users/admin/github/xud/node_modules/mysql2/lib/connection.js:502:28)
    at PacketParser.onPacket (/Users/admin/github/xud/node_modules/mysql2/lib/connection.js:81:16)
    at PacketParser.executeStart (/Users/admin/github/xud/node_modules/mysql2/lib/packet_parser.js:77:14)
    at Socket.<anonymous> (/Users/admin/github/xud/node_modules/mysql2/lib/connection.js:89:29)
    at Socket.emit (events.js:182:13)
    at addChunk (_stream_readable.js:283:12)
    at readableAddChunk (_stream_readable.js:264:11)
    at Socket.Readable.push (_stream_readable.js:219:10)
    at TCP.onread (net.js:639:20)
  name: 'SequelizeUniqueConstraintError',
  errors:
   [ ValidationErrorItem {
       message: 'nodePubKey must be unique',
       type: 'unique violation',
       path: 'nodePubKey',
       value:
        '03e12d9dc27f966d0e02ab242912ddd088d86247bd8d22887ffcf496cc57709b',
       origin: 'DB',
       instance: [Node],
       validatorKey: 'not_unique',
       validatorName: null,
       validatorArgs: [] } ],
  fields:
   { nodePubKey:
      '03e12d9dc27f966d0e02ab242912ddd088d86247bd8d22887ffcf496cc57709b' },
  parent:
   { Error: Duplicate entry '03e12d9dc27f966d0e02ab242912ddd088d86247bd8d22887ffcf496cc57709b' for key 'nodePubKey'
       at Packet.asError (/Users/admin/github/xud/node_modules/mysql2/lib/packets/packet.js:716:13)
       at Query.Command.execute (/Users/admin/github/xud/node_modules/mysql2/lib/commands/command.js:28:22)
       at Connection.handlePacket (/Users/admin/github/xud/node_modules/mysql2/lib/connection.js:502:28)
       at PacketParser.onPacket (/Users/admin/github/xud/node_modules/mysql2/lib/connection.js:81:16)
       at PacketParser.executeStart (/Users/admin/github/xud/node_modules/mysql2/lib/packet_parser.js:77:14)
       at Socket.<anonymous> (/Users/admin/github/xud/node_modules/mysql2/lib/connection.js:89:29)
       at Socket.emit (events.js:182:13)
       at addChunk (_stream_readable.js:283:12)
       at readableAddChunk (_stream_readable.js:264:11)
       at Socket.Readable.push (_stream_readable.js:219:10)
       at TCP.onread (net.js:639:20)
     code: 'ER_DUP_ENTRY',
     errno: 1062,
     sqlState: '23000',
     sqlMessage:
      'Duplicate entry \'03e12d9dc27f966d0e02ab242912ddd088d86247bd8d22887ffcf496cc57709b\' for key \'nodePubKey\'',
     sql:
      'INSERT INTO `nodes` (`id`,`nodePubKey`,`addressesText`,`createdAt`,`updatedAt`) VALUES (DEFAULT,\'03e12d9dc27f966d0e02ab242912ddd088d86247bd8d22887ffcf496cc57709bda\',\'[{\\"host\\":\\"84.111.139.147\\",\\"port\\":8885}]\',\'2018-08-28 20:05:13\',\'2018-08-28 20:05:13\');' },
  original:
   { Error: Duplicate entry '03e12d9dc27f966d0e02ab242912ddd088d86247bd8d22887ffcf496cc57709b' for key 'nodePubKey'
       at Packet.asError (/Users/admin/github/xud/node_modules/mysql2/lib/packets/packet.js:716:13)
       at Query.Command.execute (/Users/admin/github/xud/node_modules/mysql2/lib/commands/command.js:28:22)
       at Connection.handlePacket (/Users/admin/github/xud/node_modules/mysql2/lib/connection.js:502:28)
       at PacketParser.onPacket (/Users/admin/github/xud/node_modules/mysql2/lib/connection.js:81:16)
       at PacketParser.executeStart (/Users/admin/github/xud/node_modules/mysql2/lib/packet_parser.js:77:14)
       at Socket.<anonymous> (/Users/admin/github/xud/node_modules/mysql2/lib/connection.js:89:29)
       at Socket.emit (events.js:182:13)
       at addChunk (_stream_readable.js:283:12)
       at readableAddChunk (_stream_readable.js:264:11)
       at Socket.Readable.push (_stream_readable.js:219:10)
       at TCP.onread (net.js:639:20)
     code: 'ER_DUP_ENTRY',
     errno: 1062,
     sqlState: '23000',
     sqlMessage:
      'Duplicate entry \'03e12d9dc27f966d0e02ab242912ddd088d86247bd8d22887ffcf496cc57709b\' for key \'nodePubKey\'',
     sql:
      'INSERT INTO `nodes` (`id`,`nodePubKey`,`addressesText`,`createdAt`,`updatedAt`) VALUES (DEFAULT,\'03e12d9dc27f966d0e02ab242912ddd088d86247bd8d22887ffcf496cc57709bda\',\'[{\\"host\\":\\"84.111.139.147\\",\\"port\\":8885}]\',\'2018-08-28 20:05:13\',\'2018-08-28 20:05:13\');' },
  sql:
   'INSERT INTO `nodes` (`id`,`nodePubKey`,`addressesText`,`createdAt`,`updatedAt`) VALUES (DEFAULT,\'03e12d9dc27f966d0e02ab242912ddd088d86247bd8d22887ffcf496cc57709bda\',\'[{\\"host\\":\\"84.111.139.147\\",\\"port\\":8885}]\',\'2018-08-28 20:05:13\',\'2018-08-28 20:05:13\');' }
/Users/admin/github/xud/dist/bootstrap.js:13
        throw err;
        ^

SequelizeUniqueConstraintError: Validation error
    at Query.formatError (/Users/admin/github/xud/node_modules/sequelize/lib/dialects/mysql/query.js:226:16)
    at Query.handler [as onResult] (/Users/admin/github/xud/node_modules/sequelize/lib/dialects/mysql/query.js:68:23)
    at Query.Command.execute (/Users/admin/github/xud/node_modules/mysql2/lib/commands/command.js:30:12)
    at Connection.handlePacket (/Users/admin/github/xud/node_modules/mysql2/lib/connection.js:502:28)
    at PacketParser.onPacket (/Users/admin/github/xud/node_modules/mysql2/lib/connection.js:81:16)
    at PacketParser.executeStart (/Users/admin/github/xud/node_modules/mysql2/lib/packet_parser.js:77:14)
    at Socket.<anonymous> (/Users/admin/github/xud/node_modules/mysql2/lib/connection.js:89:29)
    at Socket.emit (events.js:182:13)
    at addChunk (_stream_readable.js:283:12)
    at readableAddChunk (_stream_readable.js:264:11)
    at Socket.Readable.push (_stream_readable.js:219:10)
    at TCP.onread (net.js:639:20)
admins-MacBook-Pro-2:resolver admin$
sangaman commented 6 years ago

I've seen this same thing recently I believe but haven't fully gotten to the bottom of it. It seems to happen only when you've configured a localhost listening address, and the result is a connection attempt to yourself. I couldn't see why exactly connections were even being attempted to oneself - debugging the connectNodes sequence looked like we never attempted a connection to ourselves, but nevertheless I'd see an incoming connection with our own nodepubkey. #400 adds a check on incoming connections that they don't use our own nodepubkey which should fix this, but it doesn't explain why this came up in the first place.

offerm commented 6 years ago

Nothing to do with localhost. IMHO this has to do with the response we are getting from the bootstrap servers. I'm sure I'm listed there with a different pubkey

sangaman commented 6 years ago

OK, might not be related to localhost, but I'd be interested to recheck this after #400 is merged either way.

sangaman commented 6 years ago

This error doesn't seem to be happening with recent changes, can we close it? @offerm

offerm commented 6 years ago

Yep

On Fri, 5 Oct 2018 at 18:53 Daniel McNally notifications@github.com wrote:

This error doesn't seem to be happening with recent changes, can we close it? @offerm https://github.com/offerm

— You are receiving this because you were mentioned.

Reply to this email directly, view it on GitHub https://github.com/ExchangeUnion/xud/issues/415#issuecomment-427413272, or mute the thread https://github.com/notifications/unsubscribe-auth/AJQ0cgWANbzH4hwPDAO-RFSdY8TaFv-wks5uh4CLgaJpZM4WQTvi .