Quote from: -ck on March 23, 2015, 08:51:26 AM

Quote from: zefir on March 23, 2015, 08:48:02 AM

With the latest builds of bitcoind

Anything obviously wrong? I'll debug and report back if not, just to be sure it is not some silly mistake at my side.

bitcoind rpc allow command changed

Ok, did some tracing to narrow down the issue. First off, it is not a bitcoind misconfiguration problem, since localhost always works (double checked using RPC interface over curl).

I observe that in function read_socket_line() in line ckpool.c:455 the recv() function returns 0 when 'validateaddress' is called after 'getblocktemplate' returned a very large response over the socket.

Following manpage, a return value of 0 for recv() has to be interpreted as 'peer has performed an orderly shutdown' which is not handled in read_socket_line(). Question remains why bitcoind is closing the socket, but at least this has to be handled accordingly by ckpool.

This is my debug log:

Code:

[2015-03-24 23:40:56] Opening /tmp/ckpool/generator
[2015-03-24 23:40:56] Unlinked /tmp/ckpool/generator to recreate socket
[2015-03-24 23:40:56] Opened server path /tmp/ckpool/generator successfully on socket 5
[2015-03-24 23:40:56] File /tmp/ckpool/generator.pid exists
[2015-03-24 23:40:56] Opening /tmp/ckpool/stratifier
[2015-03-24 23:40:56] Unlinked /tmp/ckpool/stratifier to recreate socket
[2015-03-24 23:40:56] Opened server path /tmp/ckpool/stratifier successfully on socket 7
[2015-03-24 23:40:56] File /tmp/ckpool/stratifier.pid exists
[2015-03-24 23:40:56] Opening /tmp/ckpool/connector
[2015-03-24 23:40:56] Unlinked /tmp/ckpool/connector to recreate socket
[2015-03-24 23:40:56] Opened server path /tmp/ckpool/connector successfully on socket 8
[2015-03-24 23:40:56] File /tmp/ckpool/connector.pid exists
[2015-03-24 23:40:56] ckpool stratifier starting
[2015-03-24 23:40:56] Opened client path /tmp/ckpool/listener successfully on socket 6
[2015-03-24 23:40:56] Listener received ping request
[2015-03-24 23:40:56] ckpool generator starting
[2015-03-24 23:40:56] Closing file handle 6
[2015-03-24 23:40:56] Attempting to connect to bitcoind
[2015-03-24 23:40:56] Listener received ping request
[2015-03-24 23:40:56] Opened client path /tmp/ckpool/listener successfully on socket 6
[2015-03-24 23:40:56] Closing file handle 6
[2015-03-24 23:40:56] Closing file handle 6
[2015-03-24 23:40:56] Opened client path /tmp/ckpool/generator successfully on socket 6
[2015-03-24 23:40:56] Closing file handle 6
[2015-03-24 23:40:56] ckpool connector starting
[2015-03-24 23:40:56] Succeeded delayed connect
[2015-03-24 23:40:56] json_rpc_call: REQ: {"method": "getblocktemplate", "params": [{"capabilities": ["coinbasetxn", "workid", "coinbase/append"]}]}

[2015-03-24 23:40:57] json_rpc_call: RESP: OK
[2015-03-24 23:40:57] Discarding:
[2015-03-24 23:40:57] MH0 dba90ae1e4c98ae65e07baa18c5735015a3850ea2db3771a71f193647966e278
[2015-03-24 23:40:57] MH1 928e668d417d547bbfc3237e727abdb5f81ff5a1d9a587afa7500697720f5917
[2015-03-24 23:40:57] MH2 23f8815bcb4b8275b0242b6cca6d844daa2e2398cbfb8c2fa721ac23197846ec
[2015-03-24 23:40:57] MH3 357c2632b29c0a71845aa3aed3c74f907a797095b1229957dbce378753c8db5c
[2015-03-24 23:40:57] MH4 d962fe3ba85ef5b919c90ceb9c5fb898e78f1f5df025ed280666dedd6c03f94f
[2015-03-24 23:40:57] MH5 0f3b07341144ef4290d0bbe8170fa45cc975a091a2816fa9fdb30367dd25634f
[2015-03-24 23:40:57] MH6 116582e86cae9fbf0df80bf929bce816743f05a9984389d8908eb2ca71e6f7f5
[2015-03-24 23:40:57] MH7 1a25a3929cdab41e9be026884027dec5835bbe4780f61810073d7fdacf8a9cf2
[2015-03-24 23:40:57] MH8 3175f8961f699a1f160497568cb86960d6d3ea30c346b777da9506b48cbdc0d9
[2015-03-24 23:40:57] MH9 5ea864a0f2a6752e545e05388ebd63664a592a770455340b0264905dd35635c2
[2015-03-24 23:40:57] Stored 540 transactions
[2015-03-24 23:40:57] json_rpc_call: REQ: {"method": "validateaddress", "params": ["14BMjogz69qe8hk9thyzbmR5pg34mVKB1e"]}

[2015-03-24 23:40:57] Failed to recv in read_socket_line: 0/0/Success
[2015-03-24 23:40:57] Closing file handle 6
[2015-03-24 23:40:57] Failed to read socket line in json_rpc_call
[2015-03-24 23:40:57] Reopening socket to 192.168.0.14:8332
[2015-03-24 23:40:57] Succeeded delayed connect
[2015-03-24 23:40:57] Failed to get valid json response to validate_address with errno 115: Operation now in progress
[2015-03-24 23:40:57] Invalid btcaddress: 14BMjogz69qe8hk9thyzbmR5pg34mVKB1e !
[2015-03-24 23:40:57] Closing file handle 6
[2015-03-24 23:40:57] CRITICAL: No bitcoinds active!

The modified error message gives ret/errno/strerror(errno), added with

Code:

diff --git a/src/ckpool.c b/src/ckpool.c
index 1ffe45f..4df333a 100644
--- a/src/ckpool.c
+++ b/src/ckpool.c
@@ -457,7 +457,7 @@ int read_socket_line(connsock_t *cs, const int timeout)
/* Closed socket after valid message */
if (eom)
break;
- LOGERR("Failed to recv in read_socket_line");
+ LOGERR("Failed to recv in read_socket_line: %d/%d/%s", ret, errno, strerror(errno));
ret = -1;
goto out;
}
@@ -678,6 +678,7 @@ json_t *json_rpc_call(connsock_t *cs, const char *rpc_req)
json_t *val = NULL;
int len, ret;

+ LOGDEBUG("json_rpc_call: REQ: %s", rpc_req);
if (unlikely(cs->fd < 0)) {
LOGWARNING("FD %d invalid in json_rpc_call", cs->fd);
goto out;
@@ -738,6 +739,9 @@ json_t *json_rpc_call(connsock_t *cs, const char *rpc_req)
val = json_loads(cs->buf, 0, &err_val);
if (!val)
LOGWARNING("JSON decode failed(%d): %s", err_val.line, err_val.text);
+ else
+ LOGDEBUG("json_rpc_call: RESP: OK");
+
out_empty:
empty_socket(cs->fd);
empty_buffer(cs);

Will dig deeper tomorrow, just to leave here as probable bug report.