Received: from sog-mx-1.v43.ch3.sourceforge.com ([172.29.43.191]
helo=mx.sourceforge.net)
by sfs-ml-4.v29.ch3.sourceforge.com with esmtp (Exim 4.76)
(envelope-from <olivier@trillion01.com>) id 1VQuW5-0001KS-Aw
for bitcoin-development@lists.sourceforge.net;
Tue, 01 Oct 2013 07:37:09 +0000
Received-SPF: neutral (sog-mx-1.v43.ch3.sourceforge.com: 74.220.216.66 is
neither permitted nor denied by domain of trillion01.com)
client-ip=74.220.216.66; envelope-from=olivier@trillion01.com;
helo=oproxy4-pub.mail.unifiedlayer.com;
Received: from oproxy4-pub.mail.unifiedlayer.com ([74.220.216.66])
by sog-mx-1.v43.ch3.sourceforge.com with smtp (Exim 4.76)
id 1VQuW3-0000wK-Ee for bitcoin-development@lists.sourceforge.net;
Tue, 01 Oct 2013 07:37:09 +0000
Received: (qmail 29465 invoked by uid 0); 1 Oct 2013 07:10:19 -0000
Received: from unknown (HELO box610.bluehost.com) (70.40.220.110)
by oproxy4.mail.unifiedlayer.com with SMTP; 1 Oct 2013 07:10:19 -0000
Received: from [173.179.63.169] (port=41659 helo=[192.168.1.104])
by box610.bluehost.com with esmtpsa (TLSv1:RC4-SHA:128) (Exim 4.80)
(envelope-from <olivier@trillion01.com>)
id 1VQu67-0001K2-KV; Tue, 01 Oct 2013 01:10:19 -0600
Message-ID: <1380611418.932.31.camel@Wailaba2>
From: Olivier Langlois <olivier@trillion01.com>
To: slush <slush@centrum.cz>
Date: Tue, 01 Oct 2013 03:10:18 -0400
In-Reply-To: <1380600219.932.21.camel@Wailaba2>
References: <CAJna-Hi+eyRnZUtHpfvod_uRCmjPOL5HS3ZZpr54yzbKRRT9-w@mail.gmail.com>
<1380600219.932.21.camel@Wailaba2>
Organization: Trillion01 Inc
Content-Type: text/plain; charset="ISO-8859-1"
X-Mailer: Evolution 3.8.5
Mime-Version: 1.0
Content-Transfer-Encoding: 7bit
X-Identified-User: {5686:box610.bluehost.com:olivierl:trillion01.com}
{sentby:smtp auth 173.179.63.169 authed with
olivier@trillion01.com}
X-Spam-Score: 0.7 (/)
X-Spam-Report: Spam Filtering performed by mx.sourceforge.net.
See http://spamassassin.org/tag/ for more details.
0.7 SPF_NEUTRAL SPF: sender does not match SPF record (neutral)
X-Headers-End: 1VQuW3-0000wK-Ee
Cc: "bitcoin-development@lists.sourceforge.net"
<bitcoin-development@lists.sourceforge.net>
Subject: Re: [Bitcoin-development] bitcoind stops responding
X-BeenThere: bitcoin-development@lists.sourceforge.net
X-Mailman-Version: 2.1.9
Precedence: list
List-Id: <bitcoin-development.lists.sourceforge.net>
List-Unsubscribe: <https://lists.sourceforge.net/lists/listinfo/bitcoin-development>,
<mailto:bitcoin-development-request@lists.sourceforge.net?subject=unsubscribe>
List-Archive: <http://sourceforge.net/mailarchive/forum.php?forum_name=bitcoin-development>
List-Post: <mailto:bitcoin-development@lists.sourceforge.net>
List-Help: <mailto:bitcoin-development-request@lists.sourceforge.net?subject=help>
List-Subscribe: <https://lists.sourceforge.net/lists/listinfo/bitcoin-development>,
<mailto:bitcoin-development-request@lists.sourceforge.net?subject=subscribe>
X-List-Received-Date: Tue, 01 Oct 2013 07:37:09 -0000
>
> Not sure yet exactly where the problem is but my current #1 suspect is:
>
> LOCK2(cs_main, pwalletMain->cs_wallet);
>
> with some kind of lock contention with the other threads.
>
I was right. It took more than 6 seconds to acquire the locks
I did modify bitcoinrpc.cpp:
namespace {
struct timeval difftv( const struct timeval &tv1, const struct timeval
&tv2 )
{
struct timeval res;
res.tv_sec = tv1.tv_sec - tv2.tv_sec;
if (tv2.tv_usec > tv1.tv_usec) {
res.tv_sec--;
res.tv_usec = 1000000;
} else
res.tv_usec = 0;
res.tv_usec += tv1.tv_usec;
res.tv_usec -= tv2.tv_usec;
return res;
}
void printExecTimes( const struct timeval &tv1,
const struct timeval &tv2,
const struct timeval &tv3 )
{
struct timeval lockTime = difftv(tv2,tv1);
struct timeval callTime = difftv(tv3,tv2);
struct timeval totalTime = difftv(tv3,tv1);
printf( "locktime : %ld.%06ld calltime : %ld.%06ld totaltime : %
ld.%06ld\n",
lockTime.tv_sec,lockTime.tv_usec,callTime.tv_sec,callTime.tv_usec,
totalTime.tv_sec,totalTime.tv_usec);
}
}
json_spirit::Value CRPCTable::execute(const std::string &strMethod,
const json_spirit::Array ¶ms) const
{
// Find method
const CRPCCommand *pcmd = tableRPC[strMethod];
if (!pcmd)
throw JSONRPCError(RPC_METHOD_NOT_FOUND, "Method not found");
// Observe safe mode
string strWarning = GetWarnings("rpc");
if (strWarning != "" && !GetBoolArg("-disablesafemode") &&
!pcmd->okSafeMode)
throw JSONRPCError(RPC_FORBIDDEN_BY_SAFE_MODE, string("Safe
mode: ") + strWarning);
try
{
// Execute
Value result;
{
if (pcmd->threadSafe)
result = pcmd->actor(params, false);
else {
struct timeval tv1,tv2,tv3;
gettimeofday(&tv1,NULL); {
LOCK2(cs_main, pwalletMain->cs_wallet);
gettimeofday(&tv2,NULL);
result = pcmd->actor(params, false); }
gettimeofday(&tv3,NULL);
printExecTimes(tv1,tv2,tv3);
}
}
return result;
}
catch (std::exception& e)
{
throw JSONRPCError(RPC_MISC_ERROR, e.what());
}
}
locktime : 0.000001 calltime : 0.000153 totaltime : 0.000154
locktime : 0.000000 calltime : 0.000011 totaltime : 0.000011
locktime : 0.000000 calltime : 0.000451 totaltime : 0.000451
locktime : 0.000000 calltime : 0.000313 totaltime : 0.000313
locktime : 0.000000 calltime : 0.000011 totaltime : 0.000011
locktime : 0.051574 calltime : 0.000377 totaltime : 0.051951
locktime : 0.000000 calltime : 0.000222 totaltime : 0.000222
locktime : 0.000000 calltime : 0.000011 totaltime : 0.000011
locktime : 0.121106 calltime : 0.000471 totaltime : 0.121577
locktime : 0.078093 calltime : 0.000451 totaltime : 0.078544
locktime : 0.101185 calltime : 0.000021 totaltime : 0.101206
locktime : 0.000000 calltime : 0.000476 totaltime : 0.000476
locktime : 0.000001 calltime : 0.000291 totaltime : 0.000292
locktime : 0.000000 calltime : 0.000017 totaltime : 0.000017
locktime : 0.003025 calltime : 0.000036 totaltime : 0.003061
locktime : 0.000000 calltime : 0.000383 totaltime : 0.000383
locktime : 0.000000 calltime : 0.000210 totaltime : 0.000210
locktime : 0.000000 calltime : 0.000016 totaltime : 0.000016
locktime : 0.000000 calltime : 0.000470 totaltime : 0.000470
locktime : 0.000000 calltime : 0.000295 totaltime : 0.000295
locktime : 0.000000 calltime : 0.000020 totaltime : 0.000020
locktime : 0.000001 calltime : 0.000385 totaltime : 0.000386
locktime : 0.000000 calltime : 0.000241 totaltime : 0.000241
locktime : 0.000000 calltime : 0.000017 totaltime : 0.000017
locktime : 0.000001 calltime : 0.000308 totaltime : 0.000309
locktime : 0.000000 calltime : 0.000164 totaltime : 0.000164
locktime : 0.000000 calltime : 0.000017 totaltime : 0.000017
locktime : 0.000000 calltime : 0.000376 totaltime : 0.000376
locktime : 0.000000 calltime : 0.000356 totaltime : 0.000356
locktime : 0.000000 calltime : 0.000021 totaltime : 0.000021
locktime : 0.000000 calltime : 0.000496 totaltime : 0.000496
locktime : 0.000001 calltime : 0.000201 totaltime : 0.000202
locktime : 0.000001 calltime : 0.000017 totaltime : 0.000018
locktime : 0.000000 calltime : 0.000301 totaltime : 0.000301
locktime : 0.000000 calltime : 0.000180 totaltime : 0.000180
locktime : 0.000000 calltime : 0.000016 totaltime : 0.000016
locktime : 0.000001 calltime : 0.000359 totaltime : 0.000360
locktime : 0.000000 calltime : 0.000265 totaltime : 0.000265
locktime : 0.000000 calltime : 0.000017 totaltime : 0.000017
locktime : 0.000001 calltime : 0.000488 totaltime : 0.000489
locktime : 0.000000 calltime : 0.000226 totaltime : 0.000226
locktime : 0.000000 calltime : 0.000025 totaltime : 0.000025
locktime : 0.000000 calltime : 0.000369 totaltime : 0.000369
locktime : 0.000000 calltime : 0.000262 totaltime : 0.000262
locktime : 0.000000 calltime : 0.000017 totaltime : 0.000017
locktime : 0.000000 calltime : 0.000459 totaltime : 0.000459
locktime : 0.000000 calltime : 0.000260 totaltime : 0.000260
locktime : 0.000000 calltime : 0.000017 totaltime : 0.000017
locktime : 0.000000 calltime : 0.000330 totaltime : 0.000330
locktime : 0.000000 calltime : 0.000223 totaltime : 0.000223
locktime : 0.000000 calltime : 0.000014 totaltime : 0.000014
locktime : 0.000001 calltime : 0.000449 totaltime : 0.000450
locktime : 0.000001 calltime : 0.000248 totaltime : 0.000249
locktime : 0.000000 calltime : 0.000017 totaltime : 0.000017
locktime : 0.000000 calltime : 0.000327 totaltime : 0.000327
locktime : 0.000000 calltime : 0.000196 totaltime : 0.000196
locktime : 0.000000 calltime : 0.000016 totaltime : 0.000016
locktime : 0.121170 calltime : 0.000408 totaltime : 0.121578
locktime : 0.004912 calltime : 0.000278 totaltime : 0.005190
locktime : 0.000000 calltime : 0.000016 totaltime : 0.000016
locktime : 5.996820 calltime : 0.000328 totaltime : 5.997148