OpenBazaar / OpenBazaar-Server

(Deprecated) OpenBazaar 1.0 Server daemon for communication with OpenBazaar-Client
MIT License
608 stars 173 forks source link

Unhandled error in Deferred #115

Closed JustinDrake closed 8 years ago

JustinDrake commented 8 years ago

Please see the debug log below:

ustins-MacBook-Air:OpenBazaar-Server justin$ python openbazaard.py start --testnet --loglevel debug
________                      __________
\_____  \ ______   ____   ____\______   \_____  _____________  _____ _______
 /   |   \\____ \_/ __ \ /    \|    |  _/\__  \ \___   /\__  \ \__  \\_  __ \
/    |    \  |_> >  ___/|   |  \    |   \ / __ \_/    /  / __ \_/ __ \|  | \/
\_______  /   __/ \___  >___|  /______  /(____  /_____ \(____  (____  /__|
        \/|__|        \/     \/       \/      \/      \/     \/     \/

OpenBazaar Server v0.1 starting...
Exception : No UPnP device discovered
2016-01-05 11:28:53+0000 [OpenBazaard] [INFO] Finding NAT Type...
2016-01-05 11:29:01+0000 [OpenBazaard] [INFO] Symmetric NAT on 94.229.131.5:45990
2016-01-05 11:29:01+0000 [Server] [WARNING] no known neighbors, so not writing to cache.
2016-01-05 11:29:01+0000 [KademliaProtocol] [DEBUG] calling remote function ping on ('205.186.154.163', 28467) (msgid kR/XMjXGhL2Rx5e9OaijjNaInkE=)
2016-01-05 11:29:01+0000 [-] OpenBazaarProtocol starting on 45990
2016-01-05 11:29:01+0000 [-] Starting protocol <net.wireprotocol.OpenBazaarProtocol object at 0x112e510d0>
2016-01-05 11:29:01+0000 [-] WSFactory starting on 18466
2016-01-05 11:29:01+0000 [-] Starting factory <api.ws.WSFactory object at 0x112ea8610>
2016-01-05 11:29:01+0000 [-] Site starting on 18465
2016-01-05 11:29:01+0000 [-] Starting factory <twisted.web.server.Site instance at 0x112eb2320>
2016-01-05 11:29:01+0000 [-] Site starting on 18469
2016-01-05 11:29:01+0000 [-] Starting factory <twisted.web.server.Site instance at 0x112eb2950>
2016-01-05 11:29:01+0000 [OpenBazaard] [INFO] Startup took 12.13 seconds
2016-01-05 11:29:02+0000 [KademliaProtocol] [DEBUG] received response for message id kR/XMjXGhL2Rx5e9OaijjNaInkE= from 205.186.154.163:28467
2016-01-05 11:29:02+0000 [Server] [INFO] bootstrapping with 1 addresses, finding neighbors...
2016-01-05 11:29:02+0000 [KademliaProtocol] [DEBUG] calling remote function ping on (u'205.186.154.163', 28467) (msgid ZvipJjr3VIAslIS9HfRIof4hjFY=)
2016-01-05 11:29:02+0000 [ConnHandler] [INFO] connected to 205.186.154.163:28467
2016-01-05 11:29:02+0000 [KademliaProtocol] [DEBUG] received response for message id ZvipJjr3VIAslIS9HfRIof4hjFY= from 205.186.154.163:28467
2016-01-05 11:29:02+0000 [OpenBazaard] [INFO] bootstrap complete
2016-01-05 11:29:02+0000 [ValueSpiderCrawl] [DEBUG] creating spider with peers: [[180045274968971912973506482994955660460321686267L, u'205.186.154.163', 28467]]
2016-01-05 11:29:02+0000 [ValueSpiderCrawl] [DEBUG] crawling with nearest: ([180045274968971912973506482994955660460321686267L, u'205.186.154.163', 28467],)
2016-01-05 11:29:02+0000 [KademliaProtocol] [DEBUG] calling remote function find_value on (u'205.186.154.163', 28467) (msgid FX/NG0iu80NiuHZk8XI4kboTnPk=)
2016-01-05 11:29:03+0000 [KademliaProtocol] [DEBUG] received response for message id FX/NG0iu80NiuHZk8XI4kboTnPk= from 205.186.154.163:28467
2016-01-05 11:29:03+0000 [Server] [INFO] retrieved 1 message(s) from the dht
2016-01-05 11:29:03+0000 [Server] [DEBUG] deleting '0acde2b6f5718fba7e5d8438e14cff1d93a372cf':'751266f8927fe9b4e764e9c23b9d989b39509b3bf3d4684cc2a4c4dbe5efb40b' from the network
2016-01-05 11:29:03+0000 [NodeSpiderCrawl] [DEBUG] creating spider with peers: [[180045274968971912973506482994955660460321686267L, u'205.186.154.163', 28467]]
2016-01-05 11:29:03+0000 [NodeSpiderCrawl] [DEBUG] crawling with nearest: ([180045274968971912973506482994955660460321686267L, u'205.186.154.163', 28467],)
2016-01-05 11:29:03+0000 [KademliaProtocol] [DEBUG] calling remote function find_node on (u'205.186.154.163', 28467) (msgid bEuI8o3lJHBr5X6jXDPKcE09erM=)
2016-01-05 11:29:03+0000 [KademliaProtocol] [DEBUG] received response for message id bEuI8o3lJHBr5X6jXDPKcE09erM= from 205.186.154.163:28467
2016-01-05 11:29:03+0000 [Server] [DEBUG] deleting '751266f8927fe9b4e764e9c23b9d989b39509b3bf3d4684cc2a4c4dbe5efb40b' on ['205.186.154.163:28467']
2016-01-05 11:29:03+0000 [KademliaProtocol] [DEBUG] calling remote function delete on (u'205.186.154.163', 28467) (msgid Z2wicByrbQAUgD6PqNX3j/X+ijI=)
2016-01-05 11:29:03+0000 [-] [INFO] Libbitcoin server online
2016-01-05 11:29:03+0000 [KademliaProtocol] [DEBUG] received response for message id Z2wicByrbQAUgD6PqNX3j/X+ijI= from 205.186.154.163:28467
2016-01-05 11:29:31+0000 [KademliaProtocol] [DEBUG] calling remote function ping on (u'205.186.154.163', 28467) (msgid r93ItFcyEHv8HRB/xQMp3Qu+zws=)
2016-01-05 11:29:31+0000 [KademliaProtocol] [DEBUG] received response for message id r93ItFcyEHv8HRB/xQMp3Qu+zws= from 205.186.154.163:28467
2016-01-05 11:30:01+0000 [KademliaProtocol] [DEBUG] calling remote function ping on (u'205.186.154.163', 28467) (msgid mwcn6qRbPeiL5fEYUlT6us/SK10=)
2016-01-05 11:30:01+0000 [KademliaProtocol] [DEBUG] received response for message id mwcn6qRbPeiL5fEYUlT6us/SK10= from 205.186.154.163:28467
2016-01-05 11:30:20+0000 [KademliaProtocol] [DEBUG] received request from 205.186.154.163:28467, command HOLE_PUNCH
2016-01-05 11:30:20+0000 [KademliaProtocol] [DEBUG] punching through NAT for 5.196.227.146:28467
2016-01-05 11:30:31+0000 [KademliaProtocol] [DEBUG] calling remote function ping on (u'205.186.154.163', 28467) (msgid LKLqiM01COp99yB1gA3AZFmsa8M=)
2016-01-05 11:30:31+0000 [KademliaProtocol] [DEBUG] received response for message id LKLqiM01COp99yB1gA3AZFmsa8M= from 205.186.154.163:28467
2016-01-05 11:31:01+0000 [KademliaProtocol] [DEBUG] calling remote function ping on (u'205.186.154.163', 28467) (msgid YlfYdvifpdEAXCMbXfhDVJCf2zA=)
2016-01-05 11:31:01+0000 [KademliaProtocol] [DEBUG] received request from 205.186.154.163:28467, command HOLE_PUNCH
2016-01-05 11:31:01+0000 [KademliaProtocol] [DEBUG] punching through NAT for 5.196.227.146:28467
2016-01-05 11:31:01+0000 [KademliaProtocol] [DEBUG] received response for message id YlfYdvifpdEAXCMbXfhDVJCf2zA= from 205.186.154.163:28467
2016-01-05 11:31:31+0000 [KademliaProtocol] [DEBUG] calling remote function ping on (u'205.186.154.163', 28467) (msgid rUhYn9alKOmInuiXMSKRHQ7ffn4=)
2016-01-05 11:31:31+0000 [KademliaProtocol] [DEBUG] received response for message id rUhYn9alKOmInuiXMSKRHQ7ffn4= from 205.186.154.163:28467
2016-01-05 11:31:42+0000 [KademliaProtocol] [DEBUG] received request from 205.186.154.163:28467, command PING
2016-01-05 11:31:42+0000 [KademliaProtocol] [DEBUG] sending response for msg id M7bJDvEmwyKA0gUv7B49qlXwJJI= to 205.186.154.163:28467
2016-01-05 11:32:01+0000 [KademliaProtocol] [DEBUG] calling remote function ping on (u'205.186.154.163', 28467) (msgid azxP2VRdDBOya3AS6IRuxaHUJ0M=)
2016-01-05 11:32:01+0000 [KademliaProtocol] [DEBUG] received response for message id azxP2VRdDBOya3AS6IRuxaHUJ0M= from 205.186.154.163:28467
2016-01-05 11:32:13+0000 [KademliaProtocol] [DEBUG] received request from 205.186.154.163:28467, command HOLE_PUNCH
2016-01-05 11:32:13+0000 [KademliaProtocol] [DEBUG] punching through NAT for 5.196.227.146:28467
2016-01-05 11:32:31+0000 [KademliaProtocol] [DEBUG] calling remote function ping on (u'205.186.154.163', 28467) (msgid vrG0q/GZuYVJQJ2rcXNH6QoRqpk=)
2016-01-05 11:32:31+0000 [KademliaProtocol] [DEBUG] received response for message id vrG0q/GZuYVJQJ2rcXNH6QoRqpk= from 205.186.154.163:28467
2016-01-05 11:33:01+0000 [KademliaProtocol] [DEBUG] calling remote function ping on (u'205.186.154.163', 28467) (msgid HG8NLZiGEYjVDCUZrdukJmDh4oU=)
2016-01-05 11:33:01+0000 [KademliaProtocol] [DEBUG] received response for message id HG8NLZiGEYjVDCUZrdukJmDh4oU= from 205.186.154.163:28467
2016-01-05 11:33:05+0000 [-] [CRITICAL] Libbitcoin server offline
2016-01-05 11:33:11+0000 [KademliaProtocol] [DEBUG] received request from 205.186.154.163:28467, command HOLE_PUNCH
2016-01-05 11:33:11+0000 [KademliaProtocol] [DEBUG] punching through NAT for 5.196.227.146:28467
2016-01-05 11:33:19+0000 [-] Unhandled error in Deferred:
Unhandled error in Deferred:
2016-01-05 11:33:19+0000 [-] Unhandled Error
    Traceback (most recent call last):
      File "/usr/local/lib/python2.7/site-packages/twisted/internet/base.py", line 1192, in run
        self.mainLoop()
      File "/usr/local/lib/python2.7/site-packages/twisted/internet/base.py", line 1201, in mainLoop
        self.runUntilCurrent()
      File "/usr/local/lib/python2.7/site-packages/twisted/internet/base.py", line 824, in runUntilCurrent
        call.func(*call.args, **call.kw)
      File "/usr/local/lib/python2.7/site-packages/twisted/internet/task.py", line 218, in __call__
        d = defer.maybeDeferred(self.f, *self.a, **self.kw)
    --- <exception caught here> ---
      File "/usr/local/lib/python2.7/site-packages/twisted/internet/defer.py", line 139, in maybeDeferred
        result = f(*args, **kw)
      File "/usr/local/lib/python2.7/site-packages/obelisk/zmq_fallback.py", line 31, in poll
        while self.poll_once():
      File "/usr/local/lib/python2.7/site-packages/obelisk/zmq_fallback.py", line 40, in poll_once
        self._cb(data, more)
      File "/usr/local/lib/python2.7/site-packages/obelisk/client.py", line 86, in frame_received
        t.reset(10)
      File "/usr/local/lib/python2.7/site-packages/twisted/internet/base.py", line 109, in reset
        raise error.AlreadyCalled
    twisted.internet.error.AlreadyCalled: Tried to cancel an already-called event.

Unhandled Error
Traceback (most recent call last):
  File "/usr/local/lib/python2.7/site-packages/twisted/internet/base.py", line 1192, in run
    self.mainLoop()
  File "/usr/local/lib/python2.7/site-packages/twisted/internet/base.py", line 1201, in mainLoop
    self.runUntilCurrent()
  File "/usr/local/lib/python2.7/site-packages/twisted/internet/base.py", line 824, in runUntilCurrent
    call.func(*call.args, **call.kw)
  File "/usr/local/lib/python2.7/site-packages/twisted/internet/task.py", line 218, in __call__
    d = defer.maybeDeferred(self.f, *self.a, **self.kw)
--- <exception caught here> ---
  File "/usr/local/lib/python2.7/site-packages/twisted/internet/defer.py", line 139, in maybeDeferred
    result = f(*args, **kw)
  File "/usr/local/lib/python2.7/site-packages/obelisk/zmq_fallback.py", line 31, in poll
    while self.poll_once():
  File "/usr/local/lib/python2.7/site-packages/obelisk/zmq_fallback.py", line 40, in poll_once
    self._cb(data, more)
  File "/usr/local/lib/python2.7/site-packages/obelisk/client.py", line 86, in frame_received
    t.reset(10)
  File "/usr/local/lib/python2.7/site-packages/twisted/internet/base.py", line 109, in reset
    raise error.AlreadyCalled
twisted.internet.error.AlreadyCalled: Tried to cancel an already-called event.
2016-01-05 11:33:31+0000 [KademliaProtocol] [DEBUG] calling remote function ping on (u'205.186.154.163', 28467) (msgid tSjclzs4qsG24xoqAQIoyu4ljfU=)
2016-01-05 11:33:31+0000 [KademliaProtocol] [DEBUG] received response for message id tSjclzs4qsG24xoqAQIoyu4ljfU= from 205.186.154.163:28467
2016-01-05 11:34:01+0000 [KademliaProtocol] [DEBUG] calling remote function ping on (u'205.186.154.163', 28467) (msgid YSqW10U8i3n4uYHDhLf6y2UgjHE=)
2016-01-05 11:34:01+0000 [KademliaProtocol] [DEBUG] received request from 205.186.154.163:28467, command PING
2016-01-05 11:34:01+0000 [KademliaProtocol] [DEBUG] sending response for msg id 6dQZ/dFtSTwVneWw3Ioa5ZoYuUA= to 205.186.154.163:28467
2016-01-05 11:34:01+0000 [KademliaProtocol] [DEBUG] received response for message id YSqW10U8i3n4uYHDhLf6y2UgjHE= from 205.186.154.163:28467
cpacia commented 8 years ago

If you install the version of python-libbitcoinclient in master this should be fixed. I just haven't pushed it to pip yet.