OverlayweaverのSelfAddressに関する問題と疑問

OverlayweaverでSelfAddressの扱いが変な気がしてきた。
設定・環境依存な問題かもしれないが。

以下はグローバルIPをホストで直接所持しているノードAとローカルIPを持ちUPnPでルータと会話が出来るノードBでDHTを構成してみた時の記録である。

まず、ノードAで立ち上げる。

java -cp bin ow.tool.dhtshell.Main -t TCP -s 124.32.128.131:9899 --no-up
np
DHT configuration:
  hostname:port:     124x32x128x131.ap124.ftth.ucom.ne.jp/124.32.128.131:9899
  transport type:    TCP
  routing algorithm: Chord
  routing style:     Iterative
  directory type:    VolatileMap
  working directory: .
A DHT started.
Ready.

次に、ノードBからノードAへjoinする。

 java -cp bin:lib/commons-cli-1.1.jar:lib/clink170.jar ow.tool.dhtshell.Main -t TCP  enoki.dokukino.com:9899
DHT configuration:
  hostname:port:     syuu-laptop/127.0.1.1:3997
  transport type:    TCP
  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 : /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 : /ff02:0:0:0:0:0:0:c,/239.255.255.250
2009/05/15 6:21:51 ow.dht.impl.BasicDHTImpl joinOverlay
情報: DHTImpl#joinOverlay: enoki.dokukino.com/124.32.128.131:9899
2009/05/15 6:21:51 ow.messaging.upnp.UPnPManager start
情報: UPnP manager started.
2009/05/15 6:21:51 ow.messaging.tcp.ConnectionPool get
情報: A new Socket created: enoki.dokukino.com/124.32.128.131:9899
2009/05/15 6:21:51 ow.messaging.tcp.TCPMessageSender send
情報: send(enoki.dokukino.com/124.32.128.131:9899, ROUTE_JOIN)
2009/05/15 6:21:51 ow.messaging.Message encode
情報: tag:ROUTE_JOIN # of contents:5
2009/05/15 6:21:51 ow.messaging.timeoutcalc.RTTBasedTimeoutCalculator updateRTT
情報: To enoki.dokukino.com/124.32.128.131:9899: RTT: 141, ave. RTT: 141, mdev: 70, mdev_max: 500, rttvar: 500, timeout: 2141
2009/05/15 6:21:51 ow.messaging.tcp.ConnectionPool get
情報: A Socket found in the hash table: 
2009/05/15 6:21:51 ow.messaging.tcp.TCPMessageSender send
情報: send((not resolved)/124.32.128.131:9899, ADJUST_LAST_HOP_REQ)
2009/05/15 6:21:51 ow.messaging.Message encode
情報: tag:ADJUST_LAST_HOP_REQ # of contents:1
2009/05/15 6:21:51 ow.messaging.timeoutcalc.RTTBasedTimeoutCalculator updateRTT
情報: To (not resolved)/124.32.128.131:9899: RTT: 30, ave. RTT: 127, mdev: 71, mdev_max: 500, rttvar: 500, timeout: 2127
2009/05/15 6:21:51 ow.messaging.tcp.ConnectionPool get
情報: A Socket found in the hash table: 
2009/05/15 6:21:51 ow.messaging.tcp.TCPMessageSender send
情報: send((not resolved)/124.32.128.131:9899, TERMINATE_JOIN)
2009/05/15 6:21:51 ow.messaging.Message encode
情報: tag:TERMINATE_JOIN # of contents:3
2009/05/15 6:21:51 ow.messaging.timeoutcalc.RTTBasedTimeoutCalculator updateRTT
情報: To (not resolved)/124.32.128.131:9899: RTT: 15, ave. RTT: 113, mdev: 72, mdev_max: 500, rttvar: 500, timeout: 2113
2009/05/15 6:21:51 ow.routing.impl.IterativeRoutingDriver$Querier call
情報: Callback result: null
  initial contact:   enoki.dokukino.com:9899
A DHT started.
Ready.
2009/05/15 6:21:51 ow.messaging.tcp.ConnectionPool get
情報: A Socket found in the hash table: 
2009/05/15 6:21:51 ow.messaging.tcp.TCPMessageSender send
情報: send((not resolved)/124.32.128.131:9899, REQ_CONNECT)
2009/05/15 6:21:51 ow.messaging.Message encode
情報: tag:REQ_CONNECT # of contents:1
2009/05/15 6:21:51 ow.messaging.timeoutcalc.RTTBasedTimeoutCalculator updateRTT
情報: To 124x32x128x131.ap124.ftth.ucom.ne.jp/124.32.128.131:9899: RTT: 18, ave. RTT: 101, mdev: 72, mdev_max: 500, rttvar: 500, timeout: 2101
2009/05/15 6:21:51 ow.messaging.tcp.TCPMessageSender adjustLoopbackAddress
情報: destination is loopback address and adjusted to (not resolved)/127.0.1.1:3997
2009/05/15 6:21:51 ow.messaging.tcp.TCPMessageSender adjustLoopbackAddress
情報: destination is loopback address and adjusted to (not resolved)/127.0.1.1:3997
2009/05/15 6:21:51 ow.messaging.tcp.ConnectionPool get
情報: A Socket found in the hash table: 
2009/05/15 6:21:51 ow.messaging.tcp.TCPMessageSender send
情報: send(124x32x128x131.ap124.ftth.ucom.ne.jp/124.32.128.131:9899, TERMINATE_NONE)
2009/05/15 6:21:51 ow.messaging.Message encode
情報: tag:TERMINATE_NONE # of contents:2
2009/05/15 6:21:51 ow.messaging.timeoutcalc.RTTBasedTimeoutCalculator updateRTT
情報: To 124x32x128x131.ap124.ftth.ucom.ne.jp/124.32.128.131:9899: RTT: 14, ave. RTT: 90, mdev: 72, mdev_max: 500, rttvar: 500, timeout: 2090
2009/05/15 6:21:51 ow.routing.impl.IterativeRoutingDriver$Querier call
情報: Callback result: null
2009/05/15 6:21:51 ow.routing.chord.FingerTable put
情報: FingerTable#put: 0238b5ce1e19fe1fc9cf33a0f2e2e3c40125fd5d:124x32x128x131.ap124.ftth.ucom.ne.jp/124.32.128.131:9899 from 159 to 1
2009/05/15 6:21:51 ow.routing.chord.Chord$FingerTableFixer run
情報: An entry incorporated to finger table: 0238b5ce1e19fe1fc9cf33a0f2e2e3c40125fd5d:124x32x128x131.ap124.ftth.ucom.ne.jp/124.32.128.131:9899
2009/05/15 6:21:51 ow.messaging.upnp.UPnPManager$DevChgListener deviceAdded
情報: UPnP device found: WLBAR-54GT
2009/05/15 6:21:51 ow.messaging.tcp.ConnectionPool get
情報: A Socket found in the hash table: 
2009/05/15 6:21:51 ow.messaging.tcp.TCPMessageSender send
情報: send(124x32x128x131.ap124.ftth.ucom.ne.jp/124.32.128.131:9899, REQ_CONNECT)
2009/05/15 6:21:51 ow.messaging.Message encode
情報: tag:REQ_CONNECT # of contents:1
2009/05/15 6:21:51 ow.messaging.timeoutcalc.RTTBasedTimeoutCalculator updateRTT
情報: To 124x32x128x131.ap124.ftth.ucom.ne.jp/124.32.128.131:9899: RTT: 15, ave. RTT: 80, mdev: 72, mdev_max: 500, rttvar: 500, timeout: 2080
2009/05/15 6:21:51 ow.messaging.upnp.UPnPManager addMapping
情報: UPnP address port mapping succeeded: ext port 3997, internal port 3997
2009/05/15 6:21:52 ow.messaging.tcp.ConnectionPool get
情報: A Socket found in the hash table: 
2009/05/15 6:21:52 ow.messaging.tcp.TCPMessageSender send
情報: send(124x32x128x131.ap124.ftth.ucom.ne.jp/124.32.128.131:9899, REQ_CONNECT)
2009/05/15 6:21:52 ow.messaging.Message encode
情報: tag:REQ_CONNECT # of contents:1
2009/05/15 6:21:52 ow.messaging.timeoutcalc.RTTBasedTimeoutCalculator updateRTT
情報: To 124x32x128x131.ap124.ftth.ucom.ne.jp/124.32.128.131:9899: RTT: 24, ave. RTT: 73, mdev: 71, mdev_max: 500, rttvar: 500, timeout: 2073
2009/05/15 6:21:53 ow.messaging.tcp.ConnectionPool get
情報: A Socket found in the hash table: 
2009/05/15 6:21:53 ow.messaging.tcp.TCPMessageSender send
情報: send(124x32x128x131.ap124.ftth.ucom.ne.jp/124.32.128.131:9899, REQ_CONNECT)
2009/05/15 6:21:53 ow.messaging.Message encode
情報: tag:REQ_CONNECT # of contents:1
2009/05/15 6:21:53 ow.messaging.timeoutcalc.RTTBasedTimeoutCalculator updateRTT
情報: To 124x32x128x131.ap124.ftth.ucom.ne.jp/124.32.128.131:9899: RTT: 21, ave. RTT: 66, mdev: 70, mdev_max: 500, rttvar: 500, timeout: 2066
2009/05/15 6:21:55 ow.messaging.tcp.ConnectionPool get
情報: A Socket found in the hash table: 
2009/05/15 6:21:55 ow.messaging.tcp.TCPMessageSender send
情報: send(124x32x128x131.ap124.ftth.ucom.ne.jp/124.32.128.131:9899, REQ_CONNECT)
2009/05/15 6:21:55 ow.messaging.Message encode
情報: tag:REQ_CONNECT # of contents:1
2009/05/15 6:21:55 ow.messaging.timeoutcalc.RTTBasedTimeoutCalculator updateRTT
情報: To 124x32x128x131.ap124.ftth.ucom.ne.jp/124.32.128.131:9899: RTT: 24, ave. RTT: 60, mdev: 69, mdev_max: 500, rttvar: 500, timeout: 2060
2009/05/15 6:21:59 ow.messaging.tcp.ConnectionPool get
情報: A Socket found in the hash table: 
2009/05/15 6:21:59 ow.messaging.tcp.TCPMessageSender send
情報: send(124x32x128x131.ap124.ftth.ucom.ne.jp/124.32.128.131:9899, REQ_CONNECT)
2009/05/15 6:21:59 ow.messaging.Message encode
情報: tag:REQ_CONNECT # of contents:1
2009/05/15 6:21:59 ow.messaging.timeoutcalc.RTTBasedTimeoutCalculator updateRTT
情報: To 124x32x128x131.ap124.ftth.ucom.ne.jp/124.32.128.131:9899: RTT: 21, ave. RTT: 55, mdev: 68, mdev_max: 500, rttvar: 500, timeout: 2055
2009/05/15 6:22:07 ow.messaging.tcp.ConnectionPool get
情報: A Socket found in the hash table: 
2009/05/15 6:22:07 ow.messaging.tcp.TCPMessageSender send
情報: send(124x32x128x131.ap124.ftth.ucom.ne.jp/124.32.128.131:9899, REQ_CONNECT)
2009/05/15 6:22:07 ow.messaging.Message encode
情報: tag:REQ_CONNECT # of contents:1
2009/05/15 6:22:07 ow.messaging.timeoutcalc.RTTBasedTimeoutCalculator updateRTT
情報: To 124x32x128x131.ap124.ftth.ucom.ne.jp/124.32.128.131:9899: RTT: 81, ave. RTT: 58, mdev: 57, mdev_max: 500, rttvar: 500, timeout: 2058
2009/05/15 6:22:26 ow.messaging.tcp.ConnectionPool get
情報: A Socket found in the hash table: 
2009/05/15 6:22:26 ow.messaging.tcp.TCPMessageSender send
情報: send(124x32x128x131.ap124.ftth.ucom.ne.jp/124.32.128.131:9899, REQ_CONNECT)
2009/05/15 6:22:26 ow.messaging.Message encode
情報: tag:REQ_CONNECT # of contents:1
2009/05/15 6:22:26 ow.messaging.timeoutcalc.RTTBasedTimeoutCalculator updateRTT
情報: To 124x32x128x131.ap124.ftth.ucom.ne.jp/124.32.128.131:9899: RTT: 23, ave. RTT: 53, mdev: 56, mdev_max: 500, rttvar: 500, timeout: 2053
2009/05/15 6:22:35 ow.routing.chord.Chord stop
情報: Chord#stop() called.
2009/05/15 6:22:35 ow.routing.impl.IterativeRoutingDriver$Querier call
情報: Callback result: null
2009/05/15 6:22:35 ow.routing.chord.Chord$FingerTableFixer run
情報: An entry incorporated to finger table: 533625ce0dfd53ad9dc9ccc7c8d372a286938488:i121-117-87-218.s05.a013.ap.plala.or.jp/121.117.87.218:3997

エラーを起こしてChord#stop()を呼んでいるように見える。
上記のログでも127.0.1.1なるアドレスが出てきてアレ？と思う所だが、ノードAの方でstatusコマンドを実行するとはっきりと分かる：

status
ID and address: 0238b5ce1e19fe1fc9cf33a0f2e2e3c40125fd5d:124x32x128x131.ap124.ftth.ucom.ne.jp/124.32.128.131:9899
Routing table:
predecessor:
 b43afcaa4ece03612efd123c880fbeaaf604bfd3:127.0.1.1/127.0.1.1:3997
successor list: [
 b43afcaa4ece03612efd123c880fbeaaf604bfd3:127.0.1.1/127.0.1.1:3997
 0238b5ce1e19fe1fc9cf33a0f2e2e3c40125fd5d:124x32x128x131.ap124.ftth.ucom.ne.jp/124.32.128.131:9899
]
finger table: [
 1: b43afcaa4ece03612efd123c880fbeaaf604bfd3:127.0.1.1/127.0.1.1:3997
]
Ready.

finger tableに127.0.1.1が登録されてる。

netstatでも。

netstat -nap|grep 3397
(一部のプロセスが識別されますが, 所有していないプロセスの情報は
表示されません。それら全てを見るにはルートになる必要があります.)
tcp6       0      0 127.0.1.1:3397          :::*                    LISTEN      25189/java

で、こうなる原因はJavaのAPIからローカルアドレスを取得した際に自分のホスト名からIPを引いたからだと思う。ちゃんとSelfAddressのホスト名はhostnameのホスト名と同じだし。

$ grep syuu /etc/hosts
127.0.1.1	syuu-laptop
$ hostname
syuu-laptop

これじゃ困る。じゃあ、ノードB側でSelfAddressにローカルIPを正しく入力してはどうか。
これは恐らくhostnameで取れる名前を解決するとローカルIPになる場合と等価なはず。

java -cp bin:lib/commons-cli-1.1.jar:lib/clink170.jar ow.tool.dhtshell.Main -t TCP -s192.168.1.11:3397 enoki.dokukino.com:9899
＊画面省略＊

で、ノードA側でstatus。

status
ID and address: 0238b5ce1e19fe1fc9cf33a0f2e2e3c40125fd5d:124x32x128x131.ap124.ftth.ucom.ne.jp/124.32.128.131:9899
Routing table:
predecessor:
 85bb4b24773bcfb0a8397ed14aac6abdbca7c584:192.168.1.11/192.168.1.11:3397
successor list: [
 85bb4b24773bcfb0a8397ed14aac6abdbca7c584:192.168.1.11/192.168.1.11:3397
 0238b5ce1e19fe1fc9cf33a0f2e2e3c40125fd5d:124x32x128x131.ap124.ftth.ucom.ne.jp/124.32.128.131:9899
]
finger table: [
 1: 85bb4b24773bcfb0a8397ed14aac6abdbca7c584:192.168.1.11/192.168.1.11:3397
]
Ready.

やはりSelfAddressがそのまま渡ってくる。これじゃ通信出来ないだろう。
netstatは正しい感じなのだが。

netstat -nap|grep java
(一部のプロセスが識別されますが, 所有していないプロセスの情報は
表示されません。それら全てを見るにはルートになる必要があります.)
tcp6       0      0 192.168.1.11:3397       :::*                    LISTEN      25480/java

では、ノードBでルータの持つグローバルアドレスをSelfAdressとして渡してみてはどうか。

java -cp bin:lib/commons-cli-1.1.jar:lib/clink170.jar ow.tool.dhtshell.Main -t TCP -s121.117.87.218:3397 enoki.dokukino.com:9899
＊ログ省略＊

ノードAで再びstatus。

status
ID and address: 0238b5ce1e19fe1fc9cf33a0f2e2e3c40125fd5d:124x32x128x131.ap124.ftth.ucom.ne.jp/124.32.128.131:9899
Routing table:
predecessor:
 4870c55c89cfc253ac55ffa8c3992a3d2d65cbd7:i121-117-87-218.s05.a013.ap.plala.or.jp/121.117.87.218:3397
successor list: [
 4870c55c89cfc253ac55ffa8c3992a3d2d65cbd7:i121-117-87-218.s05.a013.ap.plala.or.jp/121.117.87.218:3397
 0238b5ce1e19fe1fc9cf33a0f2e2e3c40125fd5d:124x32x128x131.ap124.ftth.ucom.ne.jp/124.32.128.131:9899
]
finger table: [
 1: 4870c55c89cfc253ac55ffa8c3992a3d2d65cbd7:i121-117-87-218.s05.a013.ap.plala.or.jp/121.117.87.218:3397
 160: 0238b5ce1e19fe1fc9cf33a0f2e2e3c40125fd5d:124x32x128x131.ap124.ftth.ucom.ne.jp/124.32.128.131:9899
]
Ready.
||
これは正しい。
が、、、、listenするポートは誤っている。
>|text|
netstat -nap|grep java
(一部のプロセスが識別されますが, 所有していないプロセスの情報は
表示されません。それら全てを見るにはルートになる必要があります.)
tcp6       0      0 127.0.1.1:3397          :::*                    LISTEN      25590/java

挙動としては、単に

SelfAddressへbindしている
SelfAddressをsuccessorへ伝えている

という事のようだ。
UPnPで取得したグローバルIPは使われておらず、手動で指定する事も出来ない。

この問題を解決するにはSelfAddressではなくANYアドレスでbindを行い、SelfAddressはグローバルIPを指すものとすれば良いように思う。
UPnPが有る場合は手動でグローバルIPを指定するのではなく、UPnP経由でグローバルIPを取得する。
これはポートマッピングと共にDHT立ち上げ前に終わっているべき。

ってな訳で、Overlayweaverにまた手を加える必要がありそうだが、念のためにCVSからHEADを落として再度試してからにしようかな。