Received: from sog-mx-1.v43.ch3.sourceforge.com ([172.29.43.191] helo=mx.sourceforge.net) by sfs-ml-2.v29.ch3.sourceforge.com with esmtp (Exim 4.76) (envelope-from ) id 1VR0lt-0006Sj-8m for bitcoin-development@lists.sourceforge.net; Tue, 01 Oct 2013 14:17:53 +0000 Received-SPF: pass (sog-mx-1.v43.ch3.sourceforge.com: domain of bitpay.com designates 74.125.82.172 as permitted sender) client-ip=74.125.82.172; envelope-from=jgarzik@bitpay.com; helo=mail-we0-f172.google.com; Received: from mail-we0-f172.google.com ([74.125.82.172]) by sog-mx-1.v43.ch3.sourceforge.com with esmtps (TLSv1:RC4-SHA:128) (Exim 4.76) id 1VR0lq-0000Q8-2r for bitcoin-development@lists.sourceforge.net; Tue, 01 Oct 2013 14:17:53 +0000 Received: by mail-we0-f172.google.com with SMTP id w61so7283597wes.17 for ; Tue, 01 Oct 2013 07:17:43 -0700 (PDT) X-Google-DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=1e100.net; s=20130820; h=x-gm-message-state:mime-version:in-reply-to:references:date :message-id:subject:from:to:cc:content-type; bh=V2JFFGbikT7SzfYTtwVgz/SdTb3YIVEkL5PaSVLz1mg=; b=Ff01y6TBOGlMqrsFSjHFjaHV4GErr+2rSRUvcLwwktResXUSV4dFWCZ+j5dDVqiwWQ lax+oXpqdcgyE95DrPR9MLWowdILIqDl8BmvJ7ZpLC+fV7wWGqsyA05J8ZrsyM6n/G2w 86EdX34XVIFpSYqZLdRzOxgkl7L4mGBi9pQ+jYdiuGi4Wopv0xjrc3s1QmEb+aecNHOe NY4ytieV8EwbNY6dntRhzr/s00xky/v0S1NjPFxJyvPZaaPMPmOaEDnBX7tDFRGMRXL+ w0XXJ6V7gZpzbNXZVrkId1TUTyqBTaTCKT3TVLBYEP/ZiD/NRoHED43UqYp4ibb13Tcm WvsA== X-Gm-Message-State: ALoCoQntA2McgUoNG8Y49YevnRXB9klUSvKNA0Vjrv7bDYx/2x57Gs8/TEOowlGJKCNJhI4C05ly MIME-Version: 1.0 X-Received: by 10.194.77.2 with SMTP id o2mr1718774wjw.57.1380637063808; Tue, 01 Oct 2013 07:17:43 -0700 (PDT) Received: by 10.194.236.69 with HTTP; Tue, 1 Oct 2013 07:17:43 -0700 (PDT) In-Reply-To: <1380611418.932.31.camel@Wailaba2> References: <1380600219.932.21.camel@Wailaba2> <1380611418.932.31.camel@Wailaba2> Date: Tue, 1 Oct 2013 16:17:43 +0200 Message-ID: From: Jeff Garzik To: Olivier Langlois Content-Type: text/plain; charset=ISO-8859-1 X-Spam-Score: -1.6 (-) X-Spam-Report: Spam Filtering performed by mx.sourceforge.net. See http://spamassassin.org/tag/ for more details. 0.0 URIBL_BLOCKED ADMINISTRATOR NOTICE: The query to URIBL was blocked. See http://wiki.apache.org/spamassassin/DnsBlocklists#dnsbl-block for more information. [URIs: doubleclick.net] -1.5 SPF_CHECK_PASS SPF reports sender host as permitted sender for sender-domain -0.0 SPF_PASS SPF: sender matches SPF record -0.1 DKIM_VALID_AU Message has a valid DKIM or DK signature from author's domain 0.1 DKIM_SIGNED Message has a DKIM or DK signature, not necessarily valid -0.1 DKIM_VALID Message has at least one valid DKIM or DK signature X-Headers-End: 1VR0lq-0000Q8-2r Cc: "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: List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Tue, 01 Oct 2013 14:17:53 -0000 Olivier, What network activity was going on, during this test? i.e. during the call with 5.99 locktime, was bitcoind processing a block or sending a large transaction? There are plenty of valid reasons -- sadly -- that the locks are held for a long time, during random network events. On Tue, Oct 1, 2013 at 9:10 AM, Olivier Langlois wrote: > >> >> 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 > > > > ------------------------------------------------------------------------------ > October Webinars: Code for Performance > Free Intel webinars can help you accelerate application performance. > Explore tips for MPI, OpenMP, advanced profiling, and more. Get the most from > the latest Intel processors and coprocessors. See abstracts and register > > http://pubads.g.doubleclick.net/gampad/clk?id=60134791&iu=/4140/ostg.clktrk > _______________________________________________ > Bitcoin-development mailing list > Bitcoin-development@lists.sourceforge.net > https://lists.sourceforge.net/lists/listinfo/bitcoin-development -- Jeff Garzik Senior Software Engineer and open source evangelist BitPay, Inc. https://bitpay.com/