Olivier Langlois [ARCHIVE] on Nostr: 📅 Original date posted:2013-10-02 📝 Original message:On Tue, 2013-10-01 at ...
📅 Original date posted:2013-10-02
📝 Original message:On Tue, 2013-10-01 at 16:17 +0200, Jeff Garzik wrote:
> 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.
>
Jeff,
In your opinion what would be then a reasonable to value for a rpc client? From what you say, 2 seconds is apparently not enough.
For your question, unfortunately or fortunately, not much. The only thing that strike out is that CTxMemPool::accept() seems to be called while the rpc thread is between
jreq.parse() and tableRPC.execute().
Here are the logs surrounding
the 5.99 sec lock wait.
1380610602.706628 : RPC connection closed
Added 1 addresses from 85.202.231.133: 2633 tried, 12769 new
CTxMemPool::accept() : accepted 6191dee582c1c19fd76d6f06a4c594ee1577dbb54b688c5dcc676ebfbc225cda (poolsz 1262)
Added 1 addresses from 217.73.163.131: 2633 tried, 12769 new
CTxMemPool::accept() : accepted 7a482a24d2588a66c6561da6ee29b5adff4e8ba72e58fb360a2c36cd78be3a71 (poolsz 1263)
Added 1 addresses from 24.211.152.165: 2633 tried, 12770 new
received getdata for: tx 3849ab1481c9d8c283e682f2ef8421a8cf01ef228a89d0daf2d5e888e04f45e4
CTxMemPool::accept() : accepted cf34b31f26d3275b66adf081f84fca2d761e8e260b42243ba36638368c1633b1 (poolsz 1264)
CTxMemPool::accept() : accepted 61fc517d9461b79bab972593fbaf8b0be8ed0222c232b2c51eea2a781a44efef (poolsz 1265)
CTxMemPool::accept() : accepted 4a42913c0b956f27cfc72ed44605ef8654ff8720b81e6ef1c7dfab8e300ee9d9 (poolsz 1266)
CTxMemPool::accept() : accepted cec545fca0b4ad6efa44159758dd18b2e3047a1f1783812256a11aba96c32792 (poolsz 1267)
CTxMemPool::accept() : accepted 1ad7ff07ed4b8299af0f5ce61b721f20d984225a4a963174f51d329587eef2e9 (poolsz 1268)
CTxMemPool::accept() : accepted 12f6a6e453f34db7165983def2ecdfef174917194aa1b8f4c4883b02595c043c (poolsz 1269)
CTxMemPool::accept() : accepted 69942aebbf3d3e6b781e56553f0b1e021e07fe1c4d922b221cadabb7eb84abb7 (poolsz 1270)
CTxMemPool::accept() : accepted d7d95a6fc61209c8dbdf4b17a058f4f9c7fa6d6e76b36ca4cf8bb67f288ef3cc (poolsz 1271)
CTxMemPool::accept() : accepted da6c8145c9f506ec0f146b37d57ef423098b584af8dbed9490002ed900228c27 (poolsz 1272)
CTxMemPool::accept() : accepted 46debd7df211ea26060db539a909d7908f1f6fcca8103897909280ab156b8872 (poolsz 1273)
CTxMemPool::accept() : accepted 30f47bae4e485e1129e0598f2264469a4f9186d9a7988debfe7e21f283975c9f (poolsz 1274)
CTxMemPool::accept() : accepted 80848aebe10afda234c42db1ae3a013f873af54906d966afcb42547501d899c4 (poolsz 1275)
CTxMemPool::accept() : accepted faaf9a2b57e80460293f3d53115fc8795bb1357d0ae6400710bc8a6610312b81 (poolsz 1276)
CTxMemPool::accept() : accepted 44f5fc39cde3b35d32f20f8246001f946c9fdc1297ea21fd7400c0c483aceca2 (poolsz 1277)
CTxMemPool::accept() : accepted d92a8389cfa6a8ea98a8103a138f45e56cf229d9b35bd46ac319167d17409edd (poolsz 1278)
CTxMemPool::accept() : accepted 557e88dfed0d2e9cd3c8c1af2eb497ea5c0a888af7417f7b816390af1dd4f38a (poolsz 1279)
CTxMemPool::accept() : accepted 037b48b12209b046bed88806bf5a92e3cc45cc2e30af895b5536fd8ef2ae865f (poolsz 1280)
received getdata for: tx 1ad7ff07ed4b8299af0f5ce61b721f20d984225a4a963174f51d329587eef2e9
CTxMemPool::accept() : accepted cf8149016e4c25b0408a70dbb8f7bc596331de6840b9a3115a6aa5445cc2b3fe (poolsz 1281)
received getdata for: tx 12f6a6e453f34db7165983def2ecdfef174917194aa1b8f4c4883b02595c043c
received getdata for: tx 61fc517d9461b79bab972593fbaf8b0be8ed0222c232b2c51eea2a781a44efef
CTxMemPool::accept() : accepted 890b41943b2cda0b9d7e34ddfcddb490582165c0cedd8fca09df6eec37ad768d (poolsz 1282)
1380610633.387730: POST / HTTP/1.1^M
ThreadRPCServer method=getinfo
CTxMemPool::accept() : accepted dc2941dd69b2f9fa2754f741dfba76489abef706bd237e3bd715181950723e4d (poolsz 1283)
keypool reserve 15
keypool return 15
locktime : 5.996820 calltime : 0.000328 totaltime : 5.997148
📝 Original message:On Tue, 2013-10-01 at 16:17 +0200, Jeff Garzik wrote:
> 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.
>
Jeff,
In your opinion what would be then a reasonable to value for a rpc client? From what you say, 2 seconds is apparently not enough.
For your question, unfortunately or fortunately, not much. The only thing that strike out is that CTxMemPool::accept() seems to be called while the rpc thread is between
jreq.parse() and tableRPC.execute().
Here are the logs surrounding
the 5.99 sec lock wait.
1380610602.706628 : RPC connection closed
Added 1 addresses from 85.202.231.133: 2633 tried, 12769 new
CTxMemPool::accept() : accepted 6191dee582c1c19fd76d6f06a4c594ee1577dbb54b688c5dcc676ebfbc225cda (poolsz 1262)
Added 1 addresses from 217.73.163.131: 2633 tried, 12769 new
CTxMemPool::accept() : accepted 7a482a24d2588a66c6561da6ee29b5adff4e8ba72e58fb360a2c36cd78be3a71 (poolsz 1263)
Added 1 addresses from 24.211.152.165: 2633 tried, 12770 new
received getdata for: tx 3849ab1481c9d8c283e682f2ef8421a8cf01ef228a89d0daf2d5e888e04f45e4
CTxMemPool::accept() : accepted cf34b31f26d3275b66adf081f84fca2d761e8e260b42243ba36638368c1633b1 (poolsz 1264)
CTxMemPool::accept() : accepted 61fc517d9461b79bab972593fbaf8b0be8ed0222c232b2c51eea2a781a44efef (poolsz 1265)
CTxMemPool::accept() : accepted 4a42913c0b956f27cfc72ed44605ef8654ff8720b81e6ef1c7dfab8e300ee9d9 (poolsz 1266)
CTxMemPool::accept() : accepted cec545fca0b4ad6efa44159758dd18b2e3047a1f1783812256a11aba96c32792 (poolsz 1267)
CTxMemPool::accept() : accepted 1ad7ff07ed4b8299af0f5ce61b721f20d984225a4a963174f51d329587eef2e9 (poolsz 1268)
CTxMemPool::accept() : accepted 12f6a6e453f34db7165983def2ecdfef174917194aa1b8f4c4883b02595c043c (poolsz 1269)
CTxMemPool::accept() : accepted 69942aebbf3d3e6b781e56553f0b1e021e07fe1c4d922b221cadabb7eb84abb7 (poolsz 1270)
CTxMemPool::accept() : accepted d7d95a6fc61209c8dbdf4b17a058f4f9c7fa6d6e76b36ca4cf8bb67f288ef3cc (poolsz 1271)
CTxMemPool::accept() : accepted da6c8145c9f506ec0f146b37d57ef423098b584af8dbed9490002ed900228c27 (poolsz 1272)
CTxMemPool::accept() : accepted 46debd7df211ea26060db539a909d7908f1f6fcca8103897909280ab156b8872 (poolsz 1273)
CTxMemPool::accept() : accepted 30f47bae4e485e1129e0598f2264469a4f9186d9a7988debfe7e21f283975c9f (poolsz 1274)
CTxMemPool::accept() : accepted 80848aebe10afda234c42db1ae3a013f873af54906d966afcb42547501d899c4 (poolsz 1275)
CTxMemPool::accept() : accepted faaf9a2b57e80460293f3d53115fc8795bb1357d0ae6400710bc8a6610312b81 (poolsz 1276)
CTxMemPool::accept() : accepted 44f5fc39cde3b35d32f20f8246001f946c9fdc1297ea21fd7400c0c483aceca2 (poolsz 1277)
CTxMemPool::accept() : accepted d92a8389cfa6a8ea98a8103a138f45e56cf229d9b35bd46ac319167d17409edd (poolsz 1278)
CTxMemPool::accept() : accepted 557e88dfed0d2e9cd3c8c1af2eb497ea5c0a888af7417f7b816390af1dd4f38a (poolsz 1279)
CTxMemPool::accept() : accepted 037b48b12209b046bed88806bf5a92e3cc45cc2e30af895b5536fd8ef2ae865f (poolsz 1280)
received getdata for: tx 1ad7ff07ed4b8299af0f5ce61b721f20d984225a4a963174f51d329587eef2e9
CTxMemPool::accept() : accepted cf8149016e4c25b0408a70dbb8f7bc596331de6840b9a3115a6aa5445cc2b3fe (poolsz 1281)
received getdata for: tx 12f6a6e453f34db7165983def2ecdfef174917194aa1b8f4c4883b02595c043c
received getdata for: tx 61fc517d9461b79bab972593fbaf8b0be8ed0222c232b2c51eea2a781a44efef
CTxMemPool::accept() : accepted 890b41943b2cda0b9d7e34ddfcddb490582165c0cedd8fca09df6eec37ad768d (poolsz 1282)
1380610633.387730: POST / HTTP/1.1^M
ThreadRPCServer method=getinfo
CTxMemPool::accept() : accepted dc2941dd69b2f9fa2754f741dfba76489abef706bd237e3bd715181950723e4d (poolsz 1283)
keypool reserve 15
keypool return 15
locktime : 5.996820 calltime : 0.000328 totaltime : 5.997148