Ruby で net/ftp.rb を使った ftp アップローダを書いてみたが、ファイルの転送が始まるまでが異常に遅い。CPU を食いつぶしてるわけでも、ディスクが遅いわけでも、帯域が足りないわけでもない。どうも、コネクションの生成あたりで時間がかかっているようなのだ。

- 環境

OS は Windows2000 SP4。あとは以下の通り。

$ uname -a
CYGWIN_NT-5.0 s 1.5.5(0.94/3/2) (2003-09-20) 16:31 i686 unknown unknown Cygwin

$ ruby -v
ruby 1.8.1 (2003-12-25) [i386-cygwin]

- net/ftp.rb を追跡

printf("%s: %s: %d\n", Time.now - start, __FILE__, __LINE__) をftp アップロードスクリプトの至る所に仕掛け、表示される時間をチェックしていく。

start = Time.now
printf("%s: %s: %d\n", Time.now - start, __FILE__, __LINE__)
何らかの処理
printf("%s: %s: %d\n", Time.now - start, __FILE__, __LINE__)

チェックの結果、net/ftp の putbinaryfile メソッドの呼び出しに時間がかかっていることがわかった。さらに以下のようにして net/ftp.rb のメソッドを追跡していったところ af = (@sock.peeraddr)[0] が遅いことがわかった。

def sendport(host, port)
  start = Time.now
  printf("%s: %s: %d\n", Time.now - start, __FILE__, __LINE__)
  af = (@sock.peeraddr)[0]
  printf("%s: %s: %d\n", Time.now - start, __FILE__, __LINE__)

- Google に聞いてみる

Google で ruby peeraddr 遅い を検索するとヒット。
[ruby-list:24928] Re: win32 版でのTCPServer#addr, peeraddr の挙動
http://blade.nagaokaut.ac.jp/cgi-bin/scat.rb/ruby/ruby-list/ ...

その，i386-mswin32版のRuby 1.4.5を落としてWindows 98で使って
みましたが，まったく問題ありませんでした．

単に名前解決に時間がかかっているだけだと思います．
つまり，ネットワークの環境と設定の問題と考えられます．

telnetで接続した直後にnetstat -aを実行してみて出力がひっかからずに
スムーズに表示されますか？

どこかでひっかかるようなら，表示が遅い行のIPアドレスの逆引きが
うまくいっていないということなので，DNSかWINSかhostsの設定を
確認してみてください．

うーん、WINS なんて使ってないし・・・。ipconfig で確かめてみるか。

$ ipconfig /all

Windows 2000 IP Configuration

        Host Name . . . . . . . . . . . . : s
        Primary DNS Suffix  . . . . . . . :
        Node Type . . . . . . . . . . . . : Hybrid
        IP Routing Enabled. . . . . . . . : No
        WINS Proxy Enabled. . . . . . . . : No
        DNS Suffix Search List. . . . . . : ***.**.jp

Ethernet adapter ローカル エリア接続 2:

        Connection-specific DNS Suffix  . : ***.**.jp
        Description . . . . . . . . . . . : 3Com EtherLink XL 10/100 PCI TX NIC (3C905B-TX)
        Physical Address. . . . . . . . . : 00-**-**-**-**-**
        DHCP Enabled. . . . . . . . . . . : Yes
        Autoconfiguration Enabled . . . . : Yes
        IP Address. . . . . . . . . . . . : 192.168.0.2
        Subnet Mask . . . . . . . . . . . : 255.255.255.0
        Default Gateway . . . . . . . . . : 192.168.0.1
        DHCP Server . . . . . . . . . . . : 192.168.0.1
        DNS Servers . . . . . . . . . . . : ***.**.1.3
        Primary WINS Server . . . . . . . : 192.168.0.200
        Lease Obtained. . . . . . . . . . : 2004年2月3日 1:00:13
        Lease Expires . . . . . . . . . . : 2004年2月4日 1:00:13

・・・? あれ? Primary WINS Server に 192.168.0.200 が指定されてるぞ? これが原因? うーん、プロバイダに問い合わせてみるか・・・。でも、perl だと問題なくて Ruby だと問題あるんだよなあ。私の設定が悪いのかなあ。現象を再現できる最小の ruby のコードと、他の言語で類似のコードを書いて、原因を絞り込んでみよう。

- ruby でのテストコード

#!/usr/local/bin/ruby -l
require 'socket'

sock = TCPSocket.open('www.google.co.jp', '80')
p sock.peeraddr

上記のコードを実行すると、以下のようになる。なんで5秒もかかるんだろう?

$ time script/mftp.rb -w
["AF_INET", 80, "216.239.57.104", "216.239.57.104"]

real    0m5.535s
user    0m0.200s
sys    0m0.130s

ちなみに、

sock = TCPSocket.open('216.239.57.104', '80')

と IP アドレスで指定しても5秒かかる。OS 付属の nslookup だとなぜか一瞬で終わる。

$ time nslookup www.google.co.jp
Server:  dns1.****.**.jp
Address:  ***.**.1.3

Non-authoritative answer:
Name:    www.google.akadns.net
Addresses:  216.239.57.104, 216.239.57.99
Aliases:  www.google.co.jp, www.google.com


real    0m0.545s
user    0m0.010s
sys    0m0.030s

他の言語でも遅いのかを調べるために、perl でテストコードを書いてみた。

#!/usr/bin/perl
use Socket;

my ($host, $port, $ip, $sockaddr, $buf);
$host = 'www.google.co.jp';
$port = 80;

# ソケットの生成
$ip = inet_aton($host) || die "host($host) not found.\n";
$sockaddr = pack_sockaddr_in($port, $ip);
socket(SOCKET, PF_INET, SOCK_STREAM, 0) || die "socket error.\n";

# ソケットの接続
connect(SOCKET, $sockaddr) || die "connect $host $port error.\n";

# 終了処理
close(SOCKET);

やっぱり一瞬で終わる。

$ time script/perlsock.pl

real    0m0.992s
user    0m0.240s
sys    0m0.180s

続きは明日 2004-02-04 にやろう。

自分好みの書式で日付と時刻を挿入できる。以下を .xyzzy か siteinit.l に記述。

(defun insert-my-date-string()
  (interactive)
  (insert (format-date-string "%Y-%m-%d %H:%M:%S")))
(global-set-key '(#\C-x #\t #\d) 'insert-my-date-string)

CTRL + x t d で、

2004-02-03 12:39:43

を挿入できる。

- 参考

xyzzy の音 - 編集
http://hie.3.pro.tok2.com/xyzzy/note/edit.html#insert-date

- おまけ

レイストーム好きなら、以下の書式がいいだろう。

(defun insert-my-raystorm-date-string()
  (interactive)
  (insert (format-date-string "%b. %m, %Y \nAlbion D.U. Earth")))
(global-set-key '(#\C-x #\t #\r) 'insert-my-raystorm-date-string)

実行結果。

Feb. 02, 2004
Albion D.U. Earth

2219年8月4日まで待ってから使おう。