[overlayweaver-ja] owdhtshell起動後のget

[etokoji]

はじめまして
構造計画研究所の江藤と申します。

研究プロジェクトで、overlay weaverを使わせていただいています。
現在困っているのが、owdhtshellを起動してから、数十秒しないとget で値が取れないことです。
何かこの時間を短くする方法がないでしょうか。
overlay weaverのバージョンは、0.9.7、CentOS5.1、Java 1.6.0_18の環境で使用しています。
owdhtshellの起動パラメータとしては、--webとコンタクト先のアドレスを指定しているのみです。

何かご助言をいただけると幸いです。
よろしくお願いいたします。

[Kazuyuki Shudo]

江藤さん、首藤です。

数十秒しないと get で値がとれない、というのは、
何をした結果でしょうか。

例えば、シェルから (1ノードを) 起動して put → get する分には、
この通り、スムースです：

% <どこか>/overlayweaver/bin/owdhtshell
DHT configuration:
hostname:port: XXXXXX/XXX.XXX.XXX.XXX:3997
transport type: UDP
routing algorithm: Chord
routing style: Iterative
directory type: VolatileMap
working directory: .
A DHT started.
Ready.
CyberGarage warning : Invalidate Multicast Recieved : /239.255.255.250,/ff02:0:0:0:0:0:0:c
put foo bar
Ready.
get foo
key: 0beec7b5ea3f0fdbc95d0dd47f3c5bc275da8a33
value: bar 10799
Ready.

Kazuyuki Shudo/首藤一幸 私をたばねないで あらせいとうの花のように
20...@shudo.net http://www.shudo.net/


> Message-ID: <0c0d5f09-456a-44ea...@31g2000prc.googlegroups.com>
> From: etokoji <eto...@gmail.com>
> Date: Thu, 6 May 2010 18:46:49 -0700 (PDT)

[Kazuyuki Shudo]

江藤さん、首藤です。

再度起動したノードにて
status コマンドで自ノードの情報しか見えないということは、
オーバレイへの join に失敗しているようです。

join 失敗の理由は、頂いた情報からはわかりません。
コンタクト先は引数で指定しているのですよね...

もし再現する方法がわかったら、教えてください。
宜しくお願いします。

Kazuyuki Shudo/首藤一幸 私をたばねないで あらせいとうの花のように
20...@shudo.net http://www.shudo.net/

> Message-ID: <k2jcc55c1741005062125nf...@mail.gmail.com>
> From: 江藤公二 <eto...@gmail.com>
> Date: Fri, 7 May 2010 13:25:32 +0900

> 江藤です。

> ノード２０台でDHTを構成していて、あるノードを一旦終了して離脱させ
> 再度起動して加入させたときに、すでに他のノードでputしてある値を
> 取得しようとすると時間がかかります。このとき、他のノードで同じ値を
> getするとすぐに値が得られます。statusを実行すると自ノード情報しか
> ない状態でした。
> ノードの数が少ないとき（４，５台）のときは、すぐに取得出来るようです。
>
>
> 2010年5月7日10:51 Kazuyuki Shudo <20...@shudo.net>:

>
>> 江藤さん、首藤です。
>>
>> 数十秒しないと get で値がとれない、というのは、
>> 何をした結果でしょうか。
>>
>> 例えば、シェルから (1ノードを) 起動して put → get する分には、
>> この通り、スムースです：
>>
>> % <どこか>/overlayweaver/bin/owdhtshell
>> DHT configuration:
>> hostname:port: XXXXXX/XXX.XXX.XXX.XXX:3997
>> transport type: UDP
>> routing algorithm: Chord
>> routing style: Iterative
>> directory type: VolatileMap
>> working directory: .
>> A DHT started.
>> Ready.
>> CyberGarage warning : Invalidate Multicast Recieved : /239.255.255.250
>> ,/ff02:0:0:0:0:0:0:c
>> put foo bar
>> Ready.
>> get foo
>> key: 0beec7b5ea3f0fdbc95d0dd47f3c5bc275da8a33
>> value: bar 10799
>> Ready.

[etokoji]

首藤さん
江藤です。

owdhtshellはこちらで作成したプログラムを介して起動しているので、手動での
再現は未確認ですが、私の方で行っている手順は、以下の通りです。

(1) ノード１を単独で起動。
(2) ノード１をコンタクト先として、他の１９台を起動。
(3) ノード１以外のノードで値をput
(4) ノード１を停止
(5) ノード１を２番目に起動したノードをコンタクト先として起動
(6) ノード１で(3)で登録した値をgetしても、数十秒間は値が取得できない。


(5)での出力を以下に添付します。

hostname:port: 10.4.0.11/10.4.0.11:3997

transport type: UDP
routing algorithm: Chord
routing style: Iterative
directory type: VolatileMap
working directory: .

CyberGarage warning : Invalidate Multicast Recieved : /
239.255.255.250,/ff02:0:0:0:0:0:0:c
CyberGarage warning : Invalidate Multicast Recieved : /
239.255.255.250,/ff02:0:0:0:0:0:0:c
CyberGarage warning : Invalidate Multicast Recieved : /

ff02:0:0:0:0:0:0:c,/239.255.255.250

CyberGarage warning : Invalidate Multicast Recieved : /

ff02:0:0:0:0:0:0:c,/239.255.255.250

CyberGarage warning : Invalidate Multicast Recieved : /
239.255.255.250,/ff02:0:0:0:0:0:0:c
CyberGarage warning : Invalidate Multicast Recieved : /
239.255.255.250,/ff02:0:0:0:0:0:0:c
CyberGarage warning : Invalidate Multicast Recieved : /

ff02:0:0:0:0:0:0:c,/239.255.255.250

CyberGarage warning : Invalidate Multicast Recieved : /

ff02:0:0:0:0:0:0:c,/239.255.255.250
2010/05/07 18:23:58 ow.routing.impl.IterativeRoutingDriver$Querier
call
警告: Target of the terminating msg is not responsible for 5d85...
adjusted from 10.27.0.11/10.27.0.11:3997 (663d) to (not resolved)/
10.4.0.11:3997 (5d85).
2010/05/07 18:23:58 ow.routing.impl.IterativeRoutingDriver$Querier
call
警告: Target of the terminating msg is not responsible for 5d85...
adjusted from 10.9.0.11/10.9.0.11:3997 (764e) to (not resolved)/
10.27.0.11:3997 (663d).
2010/05/07 18:23:58 ow.routing.impl.IterativeRoutingDriver$Querier
call
警告: Target of the terminating msg is not responsible for 5d85...
adjusted from 10.27.0.11/10.27.0.11:3997 (663d) to (not resolved)/
10.4.0.11:3997 (5d85).
2010/05/07 18:23:58 ow.routing.impl.IterativeRoutingDriver$Querier
call
警告: Target of the terminating msg is not responsible for 5d85...
adjusted from 10.8.1.11/10.8.1.11:3997 (8b64) to (not resolved)/
10.9.0.11:3997 (764e).
2010/05/07 18:23:58 ow.routing.impl.IterativeRoutingDriver$Querier
call
警告: Target of the terminating msg is not responsible for 5d85...
adjusted from 10.9.0.11/10.9.0.11:3997 (764e) to (not resolved)/
10.27.0.11:3997 (663d).
2010/05/07 18:23:58 ow.routing.impl.IterativeRoutingDriver$Querier
call
警告: Target of the terminating msg is not responsible for 5d85...
adjusted from 10.27.0.11/10.27.0.11:3997 (663d) to (not resolved)/
10.4.0.11:3997 (5d85).
2010/05/07 18:23:58 ow.routing.impl.IterativeRoutingDriver$Querier
call
警告: Target of the terminating msg is not responsible for 5d85...
adjusted from 10.20.0.11/10.20.0.11:3997 (aae3) to (not resolved)/
10.8.1.11:3997 (8b64).
2010/05/07 18:23:58 ow.routing.impl.IterativeRoutingDriver$Querier
call
警告: Target of the terminating msg is not responsible for 5d85...
adjusted from 10.8.1.11/10.8.1.11:3997 (8b64) to (not resolved)/
10.9.0.11:3997 (764e).
2010/05/07 18:23:58 ow.routing.impl.IterativeRoutingDriver$Querier
call
警告: Target of the terminating msg is not responsible for 5d85...
adjusted from 10.9.0.11/10.9.0.11:3997 (764e) to (not resolved)/
10.27.0.11:3997 (663d).
2010/05/07 18:23:58 ow.routing.impl.IterativeRoutingDriver$Querier
call
警告: Target of the terminating msg is not responsible for 5d85...
adjusted from 10.27.0.11/10.27.0.11:3997 (663d) to (not resolved)/
10.4.0.11:3997 (5d85).
2010/05/07 18:23:58 ow.routing.impl.IterativeRoutingDriver$Querier
call
警告: Target of the terminating msg is not responsible for 5d85...
adjusted from 10.11.0.11/10.11.0.11:3997 (b255) to (not resolved)/
10.20.0.11:3997 (aae3).
2010/05/07 18:23:58 ow.routing.impl.IterativeRoutingDriver$Querier
call
警告: Target of the terminating msg is not responsible for 5d85...
adjusted from 10.20.0.11/10.20.0.11:3997 (aae3) to
10.8.1.11/10.8.1.11:3997 (8b64).
2010/05/07 18:23:58 ow.routing.impl.IterativeRoutingDriver$Querier
call
警告: Target of the terminating msg is not responsible for 5d85...
adjusted from 10.8.1.11/10.8.1.11:3997 (8b64) to
10.9.0.11/10.9.0.11:3997 (764e).
2010/05/07 18:23:58 ow.routing.impl.IterativeRoutingDriver$Querier
call
警告: Target of the terminating msg is not responsible for 5d85...
adjusted from 10.9.0.11/10.9.0.11:3997 (764e) to
10.27.0.11/10.27.0.11:3997 (663d).
2010/05/07 18:23:58 ow.routing.impl.IterativeRoutingDriver$Querier
call
警告: Target of the terminating msg is not responsible for 5d85...
adjusted from 10.27.0.11/10.27.0.11:3997 (663d) to
10.4.0.11/10.4.0.11:3997 (5d85).
2010/05/07 18:23:59 ow.routing.impl.IterativeRoutingDriver$Querier
call
警告: Target of the terminating msg is not responsible for 5d85...
adjusted from 10.17.0.11/10.17.0.11:3997 (c9e9) to
10.11.0.11/10.11.0.11:3997 (b255).
2010/05/07 18:23:59 ow.routing.impl.IterativeRoutingDriver$Querier
call
警告: Target of the terminating msg is not responsible for 5d85...
adjusted from 10.11.0.11/10.11.0.11:3997 (b255) to
10.20.0.11/10.20.0.11:3997 (aae3).
2010/05/07 18:23:59 ow.routing.impl.IterativeRoutingDriver$Querier
call
警告: Target of the terminating msg is not responsible for 5d85...
adjusted from 10.20.0.11/10.20.0.11:3997 (aae3) to
10.8.1.11/10.8.1.11:3997 (8b64).
2010/05/07 18:23:59 ow.routing.impl.IterativeRoutingDriver$Querier
call
警告: Target of the terminating msg is not responsible for 5d85...
adjusted from 10.8.1.11/10.8.1.11:3997 (8b64) to (not resolved)/
10.9.0.11:3997 (764e).
2010/05/07 18:23:59 ow.routing.impl.IterativeRoutingDriver$Querier
call
警告: Target of the terminating msg is not responsible for 5d85...
adjusted from 10.9.0.11/10.9.0.11:3997 (764e) to
10.27.0.11/10.27.0.11:3997 (663d).
2010/05/07 18:23:59 ow.routing.impl.IterativeRoutingDriver$Querier
call
警告: Target of the terminating msg is not responsible for 5d85...
adjusted from 10.27.0.11/10.27.0.11:3997 (663d) to
10.4.0.11/10.4.0.11:3997 (5d85).
2010/05/07 18:23:59 ow.routing.impl.IterativeRoutingDriver$Querier
call
警告: Target of the terminating msg is not responsible for 5d85...
adjusted from 10.12.1.11/10.12.1.11:3997 (d7ff) to
10.17.0.11/10.17.0.11:3997 (c9e9).
2010/05/07 18:23:59 ow.routing.impl.IterativeRoutingDriver$Querier
call
警告: Target of the terminating msg is not responsible for 5d85...
adjusted from 10.17.0.11/10.17.0.11:3997 (c9e9) to
10.11.0.11/10.11.0.11:3997 (b255).
2010/05/07 18:23:59 ow.routing.impl.IterativeRoutingDriver$Querier
call
警告: Target of the terminating msg is not responsible for 5d85...
adjusted from 10.11.0.11/10.11.0.11:3997 (b255) to
10.20.0.11/10.20.0.11:3997 (aae3).
2010/05/07 18:23:59 ow.routing.impl.IterativeRoutingDriver$Querier
call
警告: Target of the terminating msg is not responsible for 5d85...
adjusted from 10.20.0.11/10.20.0.11:3997 (aae3) to
10.8.1.11/10.8.1.11:3997 (8b64).
2010/05/07 18:23:59 ow.routing.impl.IterativeRoutingDriver$Querier
call
警告: Target of the terminating msg is not responsible for 5d85...
adjusted from 10.8.1.11/10.8.1.11:3997 (8b64) to
10.9.0.11/10.9.0.11:3997 (764e).
2010/05/07 18:23:59 ow.routing.impl.IterativeRoutingDriver$Querier
call
警告: Target of the terminating msg is not responsible for 5d85...
adjusted from 10.9.0.11/10.9.0.11:3997 (764e) to
10.27.0.11/10.27.0.11:3997 (663d).
2010/05/07 18:23:59 ow.routing.impl.IterativeRoutingDriver$Querier
call
警告: Target of the terminating msg is not responsible for 5d85...
adjusted from 10.27.0.11/10.27.0.11:3997 (663d) to
10.4.0.11/10.4.0.11:3997 (5d85).
initial contact: 10.7.0.11:3997
A DHT started.
2010-05-07 18:23:59.585:INFO::Logging to StdErrLog::DEBUG=false via
org.eclipse.jetty.util.log.StdErrLog
2010-05-07 18:23:59.614:INFO::jetty-7.0.0.v20091005
2010-05-07 18:23:59.762:INFO::Started
SelectChann...@0.0.0.0:3998
Web and XML-RPC server: http://10.4.0.11:3998/
Ready.
get 22.0.0.11
key: 70b69e4c532ee99e328d7a290576fcd0f3de6e61
value:
Ready.
status
ID and address:
5d85272d001ad20306a792b800041184ccc7ad71:10.4.0.11/10.4.0.11:3997
Routing table:
predecessor:
5d85272d001ad20306a792b800041184ccc7ad71:10.4.0.11/10.4.0.11:3997
successor list: [
5d85272d001ad20306a792b800041184ccc7ad71:10.4.0.11/10.4.0.11:3997
]
finger table: [
1: 5d85272d001ad20306a792b800041184ccc7ad71:10.4.0.11/10.4.0.11:3997
]
Last keys & routes:
number of messages: 0 -> 0
key[0]: 70b69e4c532ee99e328d7a290576fcd0f3de6e61
route[0] (length: 0): [
5d85272d001ad20306a792b800041184ccc7ad71:10.4.0.11/10.4.0.11:3997 (0)
]
root candidates[0]: [
5d85272d001ad20306a792b800041184ccc7ad71:10.4.0.11/10.4.0.11:3997
]
Ready.

On May 7, 1:56 pm, Kazuyuki Shudo <2...@shudo.net> wrote:
> 江藤さん、首藤です。
>
> 再度起動したノードにて
> status コマンドで自ノードの情報しか見えないということは、
> オーバレイへの join に失敗しているようです。
>
> join 失敗の理由は、頂いた情報からはわかりません。
> コンタクト先は引数で指定しているのですよね...
>
> もし再現する方法がわかったら、教えてください。
> 宜しくお願いします。
>
> Kazuyuki Shudo/首藤一幸 私をたばねないで あらせいとうの花のように

> 2...@shudo.net http://www.shudo.net/
>
>
>
> > Message-ID: <k2jcc55c1741005062125nf49a61b4kcb2acd501bb78...@mail.gmail.com>
> > From: 江藤公二 <etok...@gmail.com>

> > Date: Fri, 7 May 2010 13:25:32 +0900
> > 江藤です。
> > ノード２０台でDHTを構成していて、あるノードを一旦終了して離脱させ
> > 再度起動して加入させたときに、すでに他のノードでputしてある値を
> > 取得しようとすると時間がかかります。このとき、他のノードで同じ値を
> > getするとすぐに値が得られます。statusを実行すると自ノード情報しか
> > ない状態でした。
> > ノードの数が少ないとき（４，５台）のときは、すぐに取得出来るようです。
>

> > 2010年5月7日10:51 Kazuyuki Shudo <2...@shudo.net>:

>
> >> 江藤さん、首藤です。
>
> >> 数十秒しないと get で値がとれない、というのは、
> >> 何をした結果でしょうか。
>
> >> 例えば、シェルから (1ノードを) 起動して put → get する分には、
> >> この通り、スムースです：
>
> >> % <どこか>/overlayweaver/bin/owdhtshell
> >> DHT configuration:
> >> hostname:port: XXXXXX/XXX.XXX.XXX.XXX:3997
> >> transport type: UDP
> >> routing algorithm: Chord
> >> routing style: Iterative
> >> directory type: VolatileMap
> >> working directory: .
> >> A DHT started.
> >> Ready.
> >> CyberGarage warning : Invalidate Multicast Recieved : /239.255.255.250
> >> ,/ff02:0:0:0:0:0:0:c
> >> put foo bar
> >> Ready.
> >> get foo
> >> key: 0beec7b5ea3f0fdbc95d0dd47f3c5bc275da8a33
> >> value: bar 10799
> >> Ready.

> >> > Message-ID: <0c0d5f09-456a-44ea-9bfe-28118d20f...@31g2000prc.googlegroups.com>
> >> > From: etokoji <etok...@gmail.com>

[Kazuyuki Shudo]

江藤さん、首藤です。

おそらく江藤さんが遭ってる問題を再現することができました。
修正できました。
ありがとうございます。

Overlay Weaver 0.9.9 へのパッチを添付します。
0.9.7 にも当たると思います。

近いうちに次の版を出します。

バグの詳細と、問題の再現方法は次の通りです：
オーバレイへの join 時にはルーティングを行うわけですが、
join しようとしているノード自身は経路に含めない、
つまり次ホップとしない、ということが必要で、行っています。
この除外処理に甘いところが残っていました。
オーバレイから離脱したノードを、
そのノードの情報が他のノードの経路表に残っているうちに
再度 join させると、この問題が起きました。
join 処理なのに join しようとしているノード自身に辿り着いてしまい、
結局 join できない、という。

Kazuyuki Shudo/首藤一幸 私をたばねないで あらせいとうの花のように
20...@shudo.net http://www.shudo.net/

> Message-ID: <0fcfb226-fa70-493b...@u20g2000pru.googlegroups.com>
> From: etokoji <eto...@gmail.com>
> Date: Fri, 7 May 2010 02:49:21 -0700 (PDT)

> 江藤です。
>
> owdhtshellはこちらで作成したプログラムを介して起動しているので、手動での
> 再現は未確認ですが、私の方で行っている手順は、以下の通りです。
>
> (1) ノード１を単独で起動。
> (2) ノード１をコンタクト先として、他の１９台を起動。
> (3) ノード１以外のノードで値をput
> (4) ノード１を停止
> (5) ノード１を２番目に起動したノードをコンタクト先として起動
> (6) ノード１で(3)で登録した値をgetしても、数十秒間は値が取得できない。

> On May 7, 1:56 pm, Kazuyuki Shudo <2...@shudo.net> wrote:
>> 江藤さん、首藤です。
>>
>> 再度起動したノードにて
>> status コマンドで自ノードの情報しか見えないということは、
>> オーバレイへの join に失敗しているようです。

>> > Message-ID: <k2jcc55c1741005062125nf49a61b4kcb2acd501bb78...@mail.gmail.com>
>> > From: 江藤公二 <etok...@gmail.com>
>> > Date: Fri, 7 May 2010 13:25:32 +0900

>> > 江藤です。
>> > ノード２０台でDHTを構成していて、あるノードを一旦終了して離脱させ
>> > 再度起動して加入させたときに、すでに他のノードでputしてある値を
>> > 取得しようとすると時間がかかります。このとき、他のノードで同じ値を
>> > getするとすぐに値が得られます。statusを実行すると自ノード情報しか
>> > ない状態でした。
>> > ノードの数が少ないとき（４，５台）のときは、すぐに取得出来るようです。


>> > 2010年5月7日10:51 Kazuyuki Shudo <2...@shudo.net>:
>>
>> >> 江藤さん、首藤です。
>>
>> >> 数十秒しないと get で値がとれない、というのは、
>> >> 何をした結果でしょうか。

[etokoji]

首藤さん
江藤です。

早速の調査と対処ありがとうございます。
たまたま問題になるケースを実行してしまっていたんでしょうね。
overlay weaverのバグ退治に貢献できてうれしいです。
月曜日にいただいたパッチを当てて確認してみます。

On 5月8日, 午前4:18, Kazuyuki Shudo <2...@shudo.net> wrote:
> 江藤さん、首藤です。
>

> おそらく江藤さんが遭ってる問題を再現することができました。
> 修正できました。
> ありがとうございます。
>
> Overlay Weaver 0.9.9 へのパッチを添付します。
> 0.9.7 にも当たると思います。
>
> 近いうちに次の版を出します。
>
> バグの詳細と、問題の再現方法は次の通りです：
> オーバレイへの join 時にはルーティングを行うわけですが、
> join しようとしているノード自身は経路に含めない、
> つまり次ホップとしない、ということが必要で、行っています。
> この除外処理に甘いところが残っていました。
> オーバレイから離脱したノードを、
> そのノードの情報が他のノードの経路表に残っているうちに
> 再度 join させると、この問題が起きました。
> join 処理なのに join しようとしているノード自身に辿り着いてしまい、
> 結局 join できない、という。
>
> Kazuyuki Shudo/首藤一幸 私をたばねないで あらせいとうの花のように

> 2...@shudo.net http://www.shudo.net/
>
>
>
> > Message-ID: <0fcfb226-fa70-493b-aa3a-42fedb1f4...@u20g2000pru.googlegroups.com>
> > From: etokoji <etok...@gmail.com>

> overlayweaver-0.9.9-20100507.diff
> 4K表示ダウンロード

[etokoji]

首藤さん
江藤です。

いただいたパッチを当てて、確認したところ、長くまたされることなく、
値が取れるようになりました。
ありがとうございました。

[Kazuyuki Shudo]

江藤さん、首藤です。

修正を含めた 0.9.10 をリリース致しました。
今回は御連絡ありがとうございました。

Kazuyuki Shudo/首藤一幸 私をたばねないで あらせいとうの花のように
20...@shudo.net http://www.shudo.net/

> Message-ID: <f11cb3d4-f37f-4eee...@n37g2000prc.googlegroups.com>
> From: etokoji <eto...@gmail.com>
> Date: Sun, 9 May 2010 19:56:05 -0700 (PDT)