OS: Ubuntu 18.04.4 LTS Bigchaindb ver: 2.0.0 Tendermint ver: 0.31.5-d2eab536
Setup: 1 node bigchaindb+tendermint - running as a docker container
Problem: Bigchaindb starts fine and tendermint connects successfully to it. However, when transactions are committed, the commit fails with errors logged in bigchaindb.log mentioning unable to connect to localhost:26657. netstat command doesn't show any process listening on 26657. Moreover, tendermint.out.log shows:
E[2020-05-03|19:19:48.586] abci.socketClient failed to connect to tcp://127.0.0.1:26658. Retrying... module=abci-client connection=query err="dial tcp 127.0.0.1:26658: conn
ect: connection refused"
However, as in the below netstat output, the port is in listen mode and bigchaindb.log shows tendermint as conncted:
[2020-05-03 19:19:51] [INFO] (abci.app) ABCIServer started on port: 26658 (MainProcess - pid: 35)
[2020-05-03 19:19:51] [INFO] (abci.app) ... connection from Tendermint: 127.0.0.1:59392 ... (MainProcess - pid: 35)
[2020-05-03 19:19:51] [INFO] (abci.app) ... connection from Tendermint: 127.0.0.1:59394 ... (MainProcess - pid: 35)
[2020-05-03 19:19:51] [INFO] (abci.app) ... connection from Tendermint: 127.0.0.1:59396 ... (MainProcess - pid: 35)
[2020-05-03 19:19:51] [INFO] (bigchaindb.core) Tendermint version: 0.31.5-d2eab536 (MainProcess - pid: 35)
Output of netstat:
bash-5.0# netstat -anp
Active Internet connections (servers and established)
Proto Recv-Q Send-Q Local Address Foreign Address State PID/Program name
tcp 0 0 0.0.0.0:2812 0.0.0.0:* LISTEN 32/monit
tcp 0 0 0.0.0.0:9984 0.0.0.0:* LISTEN 48/gunicorn: master
tcp 0 0 0.0.0.0:9985 0.0.0.0:* LISTEN 54/bigchaindb_ws
tcp 0 0 0.0.0.0:26658 0.0.0.0:* LISTEN 35/bigchaindb
tcp 0 0 127.0.0.1:26658 127.0.0.1:59394 ESTABLISHED 35/bigchaindb
tcp 0 0 127.0.0.1:59394 127.0.0.1:26658 ESTABLISHED 37/tendermint
tcp 0 0 127.0.0.1:26658 127.0.0.1:59392 ESTABLISHED 35/bigchaindb
tcp 0 0 172.17.0.2:33424 172.31.28.97:27017 ESTABLISHED 35/bigchaindb
tcp 0 0 172.17.0.2:33426 172.31.28.97:27017 ESTABLISHED 35/bigchaindb
tcp 0 0 127.0.0.1:59392 127.0.0.1:26658 ESTABLISHED 37/tendermint
tcp 0 6 127.0.0.1:26658 127.0.0.1:59396 ESTABLISHED 35/bigchaindb
tcp 0 0 172.17.0.2:34490 172.31.28.97:27017 ESTABLISHED 53/gunicorn: worker
tcp 0 0 127.0.0.1:59396 127.0.0.1:26658 ESTABLISHED 37/tendermint
tcp 0 0 172.17.0.2:34488 172.31.28.97:27017 ESTABLISHED 53/gunicorn: worker
tcp 0 0 :::2812 :::* LISTEN 32/monit
Active UNIX domain sockets (servers and established)
Proto RefCnt Flags Type State I-Node PID/Program name Path
unix 3 [ ] STREAM CONNECTED 3426959421 54/bigchaindb_ws
unix 3 [ ] STREAM CONNECTED 3426959420 54/bigchaindb_ws
The problem is random. Sometimes, it gets connected magically and tendermint rpc process listens to 26657 port.
Stacktrace from bigchaindb.log:
[2020-05-03 19:29:12] [ERROR] (bigchaindb.web.server) Exception on /api/v1/transactions/ [POST] (bigchaindb_webapi - pid: 53)
Traceback (most recent call last):
File "/usr/lib/python3.7/site-packages/urllib3/connection.py", line 157, in _new_conn
(self._dns_host, self.port), self.timeout, **extra_kw
File "/usr/lib/python3.7/site-packages/urllib3/util/connection.py", line 84, in create_connection
raise err
File "/usr/lib/python3.7/site-packages/urllib3/util/connection.py", line 74, in create_connection
sock.connect(sa)
ConnectionRefusedError: [Errno 111] Connection refused
During handling of the above exception, another exception occurred:
Traceback (most recent call last):
File "/usr/lib/python3.7/site-packages/urllib3/connectionpool.py", line 672, in urlopen
chunked=chunked,
File "/usr/lib/python3.7/site-packages/urllib3/connectionpool.py", line 387, in _make_request
conn.request(method, url, **httplib_request_kw)
File "/usr/lib/python3.7/http/client.py", line 1252, in request
self._send_request(method, url, body, headers, encode_chunked)
File "/usr/lib/python3.7/http/client.py", line 1298, in _send_request
self.endheaders(body, encode_chunked=encode_chunked)
File "/usr/lib/python3.7/http/client.py", line 1247, in endheaders
self._send_output(message_body, encode_chunked=encode_chunked)
File "/usr/lib/python3.7/http/client.py", line 1026, in _send_output
self.send(msg)
File "/usr/lib/python3.7/http/client.py", line 966, in send
self.connect()
File "/usr/lib/python3.7/site-packages/urllib3/connection.py", line 184, in connect
conn = self._new_conn()
File "/usr/lib/python3.7/site-packages/urllib3/connection.py", line 169, in _new_conn
self, "Failed to establish a new connection: %s" % e
urllib3.exceptions.NewConnectionError: <urllib3.connection.HTTPConnection object at 0x7f3fa4a31a90>: Failed to establish a new connection: [Errno 111] Connection refused
During handling of the above exception, another exception occurred:
Traceback (most recent call last):
File "/usr/lib/python3.7/site-packages/requests/adapters.py", line 449, in send
timeout=timeout
File "/usr/lib/python3.7/site-packages/urllib3/connectionpool.py", line 720, in urlopen
method, url, error=e, _pool=self, _stacktrace=sys.exc_info()[2]
File "/usr/lib/python3.7/site-packages/urllib3/util/retry.py", line 436, in increment
raise MaxRetryError(_pool, url, error or ResponseError(cause))
urllib3.exceptions.MaxRetryError: HTTPConnectionPool(host='localhost', port=26657): Max retries exceeded with url: / (Caused by NewConnectionError('<urllib3.connection.HTTPC
During handling of the above exception, another exception occurred:
Traceback (most recent call last):
File "/usr/lib/python3.7/site-packages/flask/app.py", line 1949, in full_dispatch_request
rv = self.dispatch_request()
File "/usr/lib/python3.7/site-packages/flask/app.py", line 1935, in dispatch_request
return self.view_functions[rule.endpoint](**req.view_args)
File "/usr/lib/python3.7/site-packages/flask_restful/__init__.py", line 458, in wrapper
resp = resource(*args, **kwargs)
File "/usr/lib/python3.7/site-packages/flask/views.py", line 89, in view
return self.dispatch_request(*args, **kwargs)
File "/usr/lib/python3.7/site-packages/flask_restful/__init__.py", line 573, in dispatch_request
resp = meth(*args, **kwargs)
File "/usr/src/app/bigchaindb/web/views/transactions.py", line 99, in post
status_code, message = bigchain.write_transaction(tx_obj, mode)
File "/usr/src/app/bigchaindb/lib.py", line 100, in write_transaction
response = self.post_transaction(transaction, mode)
File "/usr/src/app/bigchaindb/lib.py", line 95, in post_transaction
return requests.post(self.endpoint, json=payload)
File "/usr/lib/python3.7/site-packages/requests/api.py", line 116, in post
return request('post', url, data=data, json=json, **kwargs)
File "/usr/lib/python3.7/site-packages/requests/api.py", line 60, in request
return session.request(method=method, url=url, **kwargs)
File "/usr/lib/python3.7/site-packages/requests/sessions.py", line 533, in request
resp = self.send(prep, **send_kwargs)
File "/usr/lib/python3.7/site-packages/requests/sessions.py", line 646, in send
r = adapter.send(request, **kwargs)
File "/usr/lib/python3.7/site-packages/requests/adapters.py", line 516, in send
raise ConnectionError(e, request=request)
requests.exceptions.ConnectionError: HTTPConnectionPool(host='localhost', port=26657): Max retries exceeded with url: / (Caused by NewConnectionError('<urllib3.connection.HT
How do I troubleshoot this?
Internet references:
1) Issue: https://github.com/bigchaindb/bigchaindb-driver/issues/499 2) Tried steps mentioned in: https://github.com/bigchaindb/bigchaindb/issues/2581#issuecomment-455952861
Thanks in advance.
EDIT: Sample code that used to test: (copied from https://github.com/bigchaindb/bigchaindb/issues/2581#issuecomment-455958416 )
Note: localhost:10001 is mapped to 0.0.0.0:9984 of the respective container.
from bigchaindb_driver import BigchainDB
from bigchaindb_driver.crypto import generate_keypair
bdb_root_url = 'http://localhost:10001'
bdb = BigchainDB(bdb_root_url)
msg = 'Varadhan test message for bigchaindb'
alice = generate_keypair()
tx = bdb.transactions.prepare(
operation='CREATE',
signers=alice.public_key,
asset={'data': {'message': msg}})
signed_tx = bdb.transactions.fulfill(
tx,
private_keys=alice.private_key)
bdb.transactions.send_commit(signed_tx) # write
block_height = bdb.blocks.get(txid=signed_tx['id'])
block = bdb.blocks.retrieve(str(block_height)) # read
print(block)
EDIT-2: I tried running tendermint with log level set to debug and got:
bash-5.0# tendermint node --rpc.laddr "tcp://0.0.0.0:26657" --log_level="*:debug"
I[2020-05-06|18:40:05.136] Starting multiAppConn module=proxy impl=multiAppConn
I[2020-05-06|18:40:05.137] Starting socketClient module=abci-client connection=query impl=socketClient
I[2020-05-06|18:40:05.138] Starting socketClient module=abci-client connection=mempool impl=socketClient
I[2020-05-06|18:40:05.139] Starting socketClient module=abci-client connection=consensus impl=socketClient
I[2020-05-06|18:40:05.139] Starting EventBus module=events impl=EventBus
I[2020-05-06|18:40:05.140] Starting PubSub module=pubsub impl=PubSub
I[2020-05-06|18:40:05.151] Starting IndexerService module=txindex impl=IndexerService
I[2020-05-06|18:40:05.231] ABCI Handshake App Info module=consensus height=355 hash= software-version= protocol-version=0
I[2020-05-06|18:40:05.233] ABCI Replay Blocks module=consensus appHeight=355 storeHeight=2760414 stateHeight=2760413
I[2020-05-06|18:40:05.233] Applying block module=consensus height=356
I[2020-05-06|18:40:05.315] Executed block module=consensus height=356 validTxs=0 invalidTxs=0
I[2020-05-06|18:40:05.395] Applying block module=consensus height=357
I[2020-05-06|18:40:05.519] Executed block module=consensus height=357 validTxs=0 invalidTxs=0
I[2020-05-06|18:40:05.599] Applying block module=consensus height=358
I[2020-05-06|18:40:05.723] Executed block module=consensus height=358 validTxs=0 invalidTxs=0
I[2020-05-06|18:40:05.803] Applying block module=consensus height=359
I[2020-05-06|18:40:05.927] Executed block module=consensus height=359 validTxs=0 invalidTxs=0
I[2020-05-06|18:40:06.007] Applying block module=consensus height=360
I[2020-05-06|18:40:06.131] Executed block module=consensus height=360 validTxs=0 invalidTxs=0
As can be seen, RPC server module is not loaded at all. Is there more debugging options available to see why RPC server module is not loaded?
