[Bamboo-Users] long latency (>5000ms) for BetterGetPutTest

Fri Nov 2 21:32:28 UTC 2007

Ok, after 2 day's of debugging, I found the "culprit" is in the
configuration:

In Network stage, the drop_prob is set to 0.1 (this is the
bamboo/test/location-test-node.cfg that comes with March code)

It actually means drop messages at 10%.... so that explains why I am
seeing 5000ms GETS at about 10% of all GETS.

After I set the drop_prob is 0.0, the GETS are all good.

And sure enough, after I search the mail archive on "drop_prob", I found
somebody already has the answer back in Feb 2007.

Just want to share this again, in case people are stuck.

Haijun

------------------------------------------------------------------------
--
Date: Thu, 1 Nov 2007 19:59:38 -0400
From: "Haijun Cao" <Haijun at projectrialto.com>
Subject: [Bamboo-Users] long latency (>5000ms) for BetterGetPutTest
To: <bamboo-users at bamboo-dht.org>
Message-ID:

<C001E847C1FD4248A7D6537643690E2116738F at mse16be2.mse16.exchange.ms>
Content-Type: text/plain; charset="iso-8859-1"

Sean,

I tried the bamboo march 2006 code (latest release), started 2 dht nodes
@ localhost, one "BetterGetPutTest" client node @localhost too.

I see occasional long latency such as 5004 ms for get (for a real key).

All nodes are up and looks fine. I can reproduce the long latency get
within 1 min of the test.

For the same (real) key, most of the gets has short latency, but a few
with long latency.

After digging thru logs, I found the long latency happens in Dht.java
between:

"local read done" and "got new recur get resp"

The condition is:

if a new "get req" comes in between the above two:

bamboo at haijun-linux:/tmp$ grep 4117322052515304435
experiment-12141-172.22.34.148-3630.log

2007-11-01 12:49:45,072 INFO  bamboo.dht.Gateway: get req
client=127.0.0.1:45497
 client_library="bamboo.dht.GatewayClient $Revision: 1.16 $"
application="bamboo
.dht.BetterPutGetTest $Revision: 1.4 $" xact_id=0xe3379169
key=0x914f884b maxval
s=1744895999 placemark=(NONE)
2007-11-01 12:49:45,072 DEBUG bamboo.dht.Dht: got (Dht.GetReq
key=914f884b maxva
ls=1744895999 all=true placemark=null)
2007-11-01 12:49:45,072 INFO  bamboo.dht.Dht: upcall for get req
key=0x914f884b return addr=172.22.34.148:3630 seq=4117322052515304435
reached replica, new recur style, replicas=[172.22.34.148:3633,
172.22.34.148:3630], synced=[172.22.34.148:3633]
...

2007-11-01 12:49:45,074 INFO  bamboo.dht.Dht: local read done for new
style recur get req seq=4117322052515304435
2007-11-01 12:49:45,112 INFO  bamboo.dht.Gateway: get req
client=127.0.0.1:45497
 client_library="bamboo.dht.GatewayClient $Revision: 1.16 $"
application="bamboo
.dht.BetterPutGetTest $Revision: 1.4 $" xact_id=0xe337916a
key=0xba12b9bb maxval
s=671154175 placemark=(NONE)
2007-11-01 12:49:45,112 DEBUG bamboo.dht.Dht: got (Dht.GetReq
key=ba12b9bb maxva
ls=671154175 all=true placemark=null)
2007-11-01 12:49:45,112 INFO  bamboo.dht.Dht: upcall for get req
key=0xba12b9bb
return addr=172.22.34.148:3630 seq=4117322052515304436 reached replica,
new recu
r style, replicas=[172.22.34.148:3633, 172.22.34.148:3630],
synced=[172.22.34.14
8:3633]

....
....
.... (long latency for seq 4117322052515304435)
....
....

2007-11-01 12:49:50,078 INFO  bamboo.dht.Dht: got new recur get resp
key=0x914f884b return addr=172.22.34.148:3630 seq=4117322052515304435
from 172.22.34.148:3630 replicas=[172.22.34.148:3633,
172.22.34.148:3630] synced=[172.22.34.148:3633]
2007-11-01 12:49:50,078 INFO  bamboo.dht.Dht:  iterative get req
key=0x914f884b return addr=172.22.34.148:3630 seq=4117322052515304435
done
2007-11-01 12:49:50,078 DEBUG bamboo.dht.Dht: enqueuing (Dht.GetResp
values.size
 ()=1 placemark=key=0x00000000 secret_hash=0x00000000
data_hash=0x00000000 time_
usec=0x0 ttl=0 client_id=0.0.0.0)
2007-11-01 12:49:50,078 INFO  bamboo.dht.Gateway: get resp
client=127.0.0.1:4549
7 client_library="bamboo.dht.GatewayClient $Revision: 1.16 $"
application="bambo
o.dht.BetterPutGetTest $Revision: 1.4 $" xact_id=0xe3379169
key=0x914f884b maxva
ls=2021720063 req placemark=(NONE) values=[(32, SHA 0x00000000,
0x229c5ba0, 6047
93)] resp placemark=(NONE) lat=5005 ms

Is this "long latency" possibly a bug? Can I have some pointer on how to
debug this further? 

I've attached cfg files for all nodes (server and client), log files.

Thanks in advance for looking into this.

Haijun
-------------- next part --------------
An HTML attachment was scrubbed...
URL:
http://bamboo-dht.org/pipermail/bamboo-users/attachments/20071101/663969
2a/attachment.htm 
-------------- next part --------------
A non-text attachment was scrubbed...
Name: better-12141.log
Type: application/octet-stream
Size: 252100 bytes
Desc: better-12141.log
Url :
http://bamboo-dht.org/pipermail/bamboo-users/attachments/20071101/663969
2a/attachment.obj 
-------------- next part --------------
A non-text attachment was scrubbed...
Name: better.cfg
Type: application/octet-stream
Size: 853 bytes
Desc: better.cfg
Url :
http://bamboo-dht.org/pipermail/bamboo-users/attachments/20071101/663969
2a/attachment-0001.obj 
-------------- next part --------------
A non-text attachment was scrubbed...
Name: experiment-12141-172.22.34.148-3630.log
Type: application/octet-stream
Size: 3088981 bytes
Desc: experiment-12141-172.22.34.148-3630.log
Url :
http://bamboo-dht.org/pipermail/bamboo-users/attachments/20071101/663969
2a/attachment-0002.obj 
-------------- next part --------------
A non-text attachment was scrubbed...
Name: experiment-12141-172.22.34.148-3630.cfg
Type: application/octet-stream
Size: 2429 bytes
Desc: experiment-12141-172.22.34.148-3630.cfg
Url :
http://bamboo-dht.org/pipermail/bamboo-users/attachments/20071101/663969
2a/attachment-0003.obj 
-------------- next part --------------
A non-text attachment was scrubbed...
Name: experiment-12141-172.22.34.148-3633.log
Type: application/octet-stream
Size: 587296 bytes
Desc: experiment-12141-172.22.34.148-3633.log
Url :
http://bamboo-dht.org/pipermail/bamboo-users/attachments/20071101/663969
2a/attachment-0004.obj 
-------------- next part --------------
A non-text attachment was scrubbed...
Name: experiment-12141-172.22.34.148-3633.cfg
Type: application/octet-stream
Size: 2429 bytes
Desc: experiment-12141-172.22.34.148-3633.cfg
Url :
http://bamboo-dht.org/pipermail/bamboo-users/attachments/20071101/663969
2a/attachment-0005.obj 

------------------------------

_______________________________________________
Bamboo-Users mailing list
Bamboo-Users at bamboo-dht.org
http://bamboo-dht.org/cgi-bin/mailman/listinfo/bamboo-users

End of Bamboo-Users Digest, Vol 17, Issue 2
*******************************************