天泣記

2004/11/06

昨日の build では、次のように失敗していた。

  1) Failure:
test_core_03_notify(Rinda::TupleSpaceProxyTest) [./rinda/test_rinda.rb:269]:
<[0, 3]> expected but was
<[0, 1]>.

  2) Failure:
test_core_03_notify(Rinda::TupleSpaceTest) [./rinda/test_rinda.rb:261]:
<10> expected but was
<2>.

そういえば、以前似た失敗があった。

まぁ、今日のと一昨日のは失敗していないし、コードは変わっていないし、問題が入り込んだわけではなかろう。

でも、このまえ刺さったのも DRb だったし、 DRb は印象が良くない。

2004/11/07

#1

今日の build は timeout していた。

timeout はこの前刺さった経験からいれたもので、これが機能することが確認されたのは喜ばしい。

が、どこで timeout したのか分からないのが問題である。

これは時間が来るといきなり SIGKILL をおくるためで、 backtrace が出る機会がないからである。

SIGKILL を送るのは参考にした debian の timeout パッケージが (デフォルトで) そうしていたからだが、最初は SIGINT あたりにしておくのがよさそうである。死ななければ SIGTERM, SIGKILL と進めていくことにして。

#2

うぅむ。 Gauche の finalizer で Scheme コードを動かすのですか。

Gauche の中身は分かっていないのであまり自信を持って言えることではないのですが、 Ruby における最近の経験からすれば、 GC が起きたときに即座に finalizer を動かすのは良くないと思います。

finalize されるオブジェクトを記録しておいて、後で (Scheme コードが動いてもおかしくないときに) 動かすのならいいのですが。

問題になりそうなものとしては、たとえば crypt(3) を呼び出して、結果を Scheme の文字列にするためにメモリをアロケートするタイミングで GC がおきて finalizer が動いてその中でさらに crypt(3) が呼ばれて、 crypt(3) の結果を保存している静的領域が書き換えられてしまうとか。 [ruby-dev:24347]

signal を受け取ったときに即座に signal handler を動かすのは良くないという事情と少し似ています。

#3

... うぅ、再度よく読んでみると、「VMループの先頭でフラグチェック」などの記述があるので、そのへんは大丈夫そうです。

はやとちりでした。

2004/11/08

#1

timeout はどういうプロセス構成にしたらいいか。

要件:

timeout 対象のコマンドを普通に C-c で止められる
timeout 対象のコマンドを普通に job control できる
指定された時間が経過して timeout したら SIGINT, SIGTERM, SIGKILL の順にシグナルを (プロセスが全部死ぬまで) 時間をおいて送る
プロセスが全部死んでからシェル (呼び出し元) に制御を返す

うぅむ、ひとつひとつの要件は難しくないのだが、ぜんぶ実現しようとすると難しい... とゆーか、そもそも可能なのか?

ふむ。まぁ、可能ではあるか。

要件を実現するためには次の条件を満たせばよい。 (ほかの実現法もあるけれど、ひとつの方法として)

job control や C-c のために、timeout コマンドと対象のコマンドはひとつのプロセスグループに属させておく
timeout コマンドが対象のコマンドを殺すときには、プロセスの生存確認を kill(-pgid, 0) で行うので、確認する timeout プロセスと対象のコマンドのプロセスは別のプロセスグループに属させておく
対象のプロセスが全部死んでからシェルから起動したプロセスは死ぬ

一見、最初のふたつは矛盾するように見える。 timeout コマンドと対象のコマンドはひとつのプロセスグループに属さなければならず、かつ、別のプロセスグループに属さなければならない。これは無理である... もしそれを同時に実現しなければならないならば。

幸いにして、よく検討すると、これらを同時に実現する必要はないことがわかる。 job control は指定した時間が経過するまで効けば良くて、いざ殺す段になったら効く必要はない。したがって、最初はひとつのプロセスグループにしておいて、指定した時間が経過したら timeout コマンドを別のプロセスグループに移せば良い。

が、ここで、3つめの条件が効いて来る。シェルから起動したプロセスは最後まで死んではならないので、これは対象のコマンドが死ぬことを確認してから死ななければならない。つまりシェルから起動するのは timeout コマンドであるが、これは exec せずに最後まで timeout コマンドでなければならず、そして timeout コマンドは対象のコマンドを殺すときには自らプロセスグループを変更しなければならない。

ところで、対話的シェルから起動したプロセスはプロセスグループリーダで、 pid == pgid である。ここで pgid を変えると pid != pgid になるわけだが、そういう、プロセスグループリーダからそうでないプロセスにするなんていう操作はいままでやったことがない。でも、setpgid を使えば出来るような気がするわけで、やってみると動いているようである。なお、かわりのプロセスグループリーダは fork で作って、 setpgid が終ったら即座に殺しておく。

さて、setpgid のこういう用法は他に用例があるだろうか?

2004/11/09

#1

「刺さる」というのを言い替えるとどうなるだろうか。

もともとは WIDE 用語だったようなのだが、使いたくなる状況は NFS によるものだけではないので、他に適切な言葉があればそっちを使いたい。

プロセスが実行中に処理が進まなくなる (終了するわけではない)
無限ループではなく、CPU 資源は消費しない

よく考えると、CPU 資源を消費せずに処理が進まなくなっているんだから、なんらかの資源の割当待ちになっているわけだ。

とするとデッドロックに近いように思える。実際「デッドロックで刺さった」というのは適切な使い方に感じられる。

でも、刺さるものがすべてデッドロックかというとそうではない。デッドロックは相互に資源を待ち合ってしまうものであるが、 NFS サーバが panic したときには NFS サーバは NFS クライアントの資源を待っているわけではない。

(WIDE 用語集で使われている) 「無反応」というのはどうか考えると、 DRb の場合はシグナルを送れば殺せるので、無反応と言うほど反応がないようには感じない。

「止まる」というのは、プロセスの終了やサスペンドを思わせるものがあるのであまり適切とは感じられない。

うぅむ。あまりいいものが思いつかない。てゆーか、みんな思いつかないから「刺さる」という言葉がよく使われるのだろうか。

「引っかかる」というのはどうだろうかとも思ったが、「刺さる」と同じようなものか。普及していないぶん伝わりにくいし。

「処理が進まなくなる」あたりであきらめるか。

2004/11/10

#1: ジョエル・オン・ソフトウェアをすこし読み直してみる。

2004/11/11

#1

そういえば、「無限ループ」というのも気になる。

プログラムが予期した時間で終らないからといって、無限に終らないといってしまっていいものだろうか。

もちろん、ソースを見て無限にループすると確認した場合は問題ないのだけれど。

2004/11/12

#1: ふと、はてなダイアリーの「Ruby」を含む日記で reload を繰り返すと、他のキーワードが出て来ることがあることに気がつく。

2004/11/14

#1

ワインバーグの「ソフトウェア文化を創る」4部作は、第3部の途中で投げ出してしまっていたのだが、続きを読んでみようかという気分になり、段ボール箱から取り出してみる。

#2

% google-count {IE}{SN}{TF}{JP}
17000   ENFJ
36000   ENFP
17400   ENTJ
87000   ENTP
15400   ESFJ
20100   ESFP
25900   ESTJ
46300   ESTP
55800   INFJ
87700   INFP
65800   INTJ
127000  INTP
18800   ISFJ
27600   ISFP
43300   ISTJ
237000  ISTP

2004/11/17

#1

自動 build のスクリプトを書き換えて、結果を HTML に変換するようにした。

http://www.rubyist.net/~akr/autobuild/latest.html

title にテスト失敗の数をいれるので、 title を自動的に取り込むアンテナ (五月雨とか) で見張れば、実際にテストのページを見なくても結果がわかる。

ちなみに今日は 3F47E だった。

2004/11/19

#1

自動 build の記録を読み込むのが遅いので、gzip 圧縮してみた。

1/10 強に圧縮されて、転送が速くなった。

2004/11/21

#1: ワインバーグのをのんびりと読んでいる。いろいろと示唆に富む記述があり、自分の行動に照らし合わせると、考えさせられるところがある。

2004/11/22

#1

amd64 なマシンをちょっといじる。

とりあえず Debian を install してみた。 (pure64)

#2

default branch と -D の相性が悪いことに気がつく。

これは default branch の実害だな。

cvs import を何回か行った後、 cvs commit を何回か行ったとする。その場合、最初に 1.1 と 1.1.1.1 が一度にできて、その後は import のたびに 1.1.1.x ができ、 commit のたびに 1.x ができる。 default branch は最初 1.1.1 になり、最初に commit したときに消える。

import          1.1, 1.1.1.1      default branch は 1.1.1 になる
import          1.1.1.2
import          1.1.1.3
import          1.1.1.4           ここまで default branch は 1.1.1
commit          1.2               ここで default branch は消える
commit          1.3
commit          1.4
commit          1.5

checkout は (-r や -D が指定されていなければ) 幹の先頭を取り出す。ここで、「幹」というのは default branch がついているかどうかで異なる。 default branch が指定されているときには default branch が幹である。上記の例でいえば 1.1.1.1 から 1.1.1.4 が幹となる。 default branch が指定されていなければ、1.1 から 1.5 までが幹となる。

したがって、default branch が指定されている 1.1.1.4 以前では 1.1.1.{1,2,3,4} のうちの一番新しいものが取り出され、 default branch が指定されていない 1.2 以降では 1.{2,3,4,5} のうちの一番新しいものが取り出される。つまり、結果的にいえば、1.1.1.{1,2,3,4}, 1.{2,3,4,5} のうち、一番新しいものが取り出されるというごく当り前の結果となる。

さて、-D は、幹をたどって指定された時刻かその直前の版を取り出す。一見これは問題ないように思える。しかし、default branch は版管理されておらず、つねに最新の指定しか記録されていないというところに問題がある。指定された時刻の default branch の指定ではなく、現在の指定が使われるため、その違いが問題となる。

たとえば、1.5 まで進んだ後に -D で時刻を指定した場合、 default branch はすでに指定されていないので、どんな時刻を指定しても 1.1.1.2, 1.1.1.3, 1.1.1.4 は取り出せない。 checkout したら 1.1.1.2, 1.1.1.3, 1.1.1.4 が出て来たはずの時刻を指定した場合、かわりに 1.1 が出て来る。

このように 1.1.1.2 から 1.1.1.4 のころの版は時刻を -D で指定するだけでは取り出せないため、一般には -D で「ある時刻に checkout/update で得られたもの」を再現することはできない。

根本的には、ある時刻に default branch がなんだったか記録されていないので、再現するには情報が足りないという問題である。 (さらに根本的には、default branch という機構自体が不適切だという問題かもしれない)

とはいえ、この情報はヒューリスティクスを使えば補完できなくもない。普通 default branch は 1.1.1 だし、 default branch が消えるタイミングは 1.2 が commit されたときなのだから。

2004/11/23

#1

実際に再現するかどうか試す。

#!/bin/sh

TZ=GMT
export TZ

mkdir /tmp/tst$$
cd /tmp/tst$$

CVSROOT=/tmp/tst$$/cvsroot
export CVSROOT
cvs init

(
  mkdir src1
  cd src1
  echo 1 > txt
  cvs import -m 'import 1' mod vendor rel_1
)

sleep 2

(
  mkdir src2
  cd src2
  echo 2 > txt
  cvs import -m 'import 2' mod vendor rel_2
)

cvs co -d co2 mod

sleep 2
date2=`date`
sleep 2

(
  cvs co -d co3 mod
  cd co3
  echo 3 > txt
  cvs commit -m 'commit 3'
)

cvs co -d co2-D -D"$date2" mod 

diff -u co2/txt co2-D/txt

実行してみると... 再現しない。

いくつか試してみると、Debian sarge の cvs 1.12.9 では再現せず、 Debian woody の 1.11.1p1 では再現することがわかった。

うぅむ。新しいのではこの状況も扱うようになっていたか。

#2

ふと手元に build 済みの cvs-1.11.16 があったことを思いだし、試してみると、これも再現しない。

ふむ。

2004/11/26

#1: 調子が悪いので休む。

2004/11/28

#1

TCP で、でかいデータを write して、受取側アプリケーションが受け取らずに終了してしまった場合、 partial write になることに気がつく。

うぅむ。nonblocking mode 以外で partial write が起こる具体的な状況ははじめて知った。

#2

pipe でも起こせるか。

% ruby -e '
r, w = IO.pipe
fork {      
  w.close
  r.sysread(8000)
}
r.close
p w.syswrite("a" * 20000)
'
8192

#3

とはいえ、これらはそれ以上書き込めないという状況だから、 nonblocking なときの partial write のように続きをやってもしょうがないかも知れない。

あとで続きを write すると成功するという状況はないだろうか。

... disk full で途中で止まって、続きを write しようとしたときには、すでに他のファイルが消えて容量が空いているとか?

割り込み?

送信中に ifconfig down して、続きをするまえに ifconfig up するのはどうか?

#4

とりあえず割り込みで実現できた。

% ./ruby -e '
r, w = IO.pipe
pid = fork {
  w.close
  sleep 1
  Process.kill("USR1", Process.ppid)
  print r.read
}
r.close
trap("USR1") { STDERR.print "usr1\n" }
STDERR.print "#{w.syswrite("a" * 8000)}\n"
STDERR.print "#{w.syswrite("b" * 8000)}\n"
w.close
Process.wait pid
'|od -c
usr1
4096
8000
0000000   a   a   a   a   a   a   a   a   a   a   a   a   a   a   a   a
*
0010000   b   b   b   b   b   b   b   b   b   b   b   b   b   b   b   b
*
0027500

つまり、write で確実に書き込みたいなら、たとえ blocking mode でも、 partial write に対する処置は必須ということになる。

#5

そーいや、このあたりでシステムコールが再起動するという話がなかったっけか。試してみる。

% ruby -ve '
r, w = IO.pipe
pid = fork {
  r.close
  sleep 1
  Process.kill("USR1", Process.ppid)
  sleep 1
  w.syswrite "a"
}
w.close
trap("USR1") { STDERR.print "usr1\n" }
p r.sysread(8000)
Process.wait pid'
ruby 1.9.0 (2004-11-28) [i686-linux]
usr1
"a"

signal handler が起動した後に read が再起動している。

この挙動は POSIX 準拠じゃない (と思う) のだが、 EINTR になる OS にはなにがあるだろうか。

#6

... ぬぅ。これは Ruby コードが signal handler から直接動いているのか?

2004/11/29

#1

stdio での nonblocking mode の話を調べていて、 comp.unix.programmer のとあるスレッドを見つける。

なんとも興味深い。

まず、R. Stevens が UNIX Network Programming Vol1, p.399 で "using standard I/O with nonblocking descriptors [is] a recipe for disaster" と述べている、とある。 (邦訳では、p.387 に「破滅の処方 (recipe for disaster) である非ブロッキングディスクリプタに対する標準 I/O の使用」とある。)

また、スレッドの最後に「一番大きな問題は flush したときに EWOULDBLOCK で失敗したときだ」という発言がある。

これは私の認識と一致する。

あまりに我が意を得たりという感じで心を動かされたので、その発言をした Andrew Gierth という人を調べてみると、 comp.unix.programmer で活発に発言していて、 UNIX Socket FAQ とかにも貢献している人らしい。

#2

recipe for disaster というのは慣用句なのだろうか。

% google-count 'recipe for disaster' 
192000  recipe for disaster
% google-count 破滅の処方
0       破滅の処方

#3

TCP で両側から active open できることを思い出して試してみる。

freebsd49% ./ruby -rsocket -e '              
s1 = Socket.new(Socket::AF_INET, Socket::SOCK_STREAM, 0)
s2 = Socket.new(Socket::AF_INET, Socket::SOCK_STREAM, 0)
s1.bind(Socket.sockaddr_in(0, "127.0.0.1"))
s2.bind(Socket.sockaddr_in(0, "127.0.0.1"))
pid = fork { s1.connect(s2.getsockname) }
s2.connect(s1.getsockname)
Process.wait pid
s1 << "a"
p s2.read(1)
s2 << "b"
p s1.read(1)
'
"a"
"b"

でも、Linux では動かない?

2004/11/30

#1

EINTR の場合に (EAGAIN と同様に) fflush で data が lost するか試す。

% cat t.c
#include <stdio.h>
#include <string.h>
#include <signal.h>
#include <sys/types.h>
#include <unistd.h>

void handler(int signum)
{
}

int main()
{
  char buf1[4096];
  char buf2[4096];
  long r;

  struct sigaction sa;

  sa.sa_handler = handler;
  memset(&sa.sa_mask, 0, sizeof(sa.sa_mask));
  sa.sa_flags = 0; // SA_RESTART
  sa.sa_restorer = 0;

  memset(buf1, 'a', 4096);
  memset(buf2, 'b', 4096);

  fprintf(stderr, "pid:%d\n", (int)getpid());

  sigaction(SIGUSR1, &sa, NULL);

  r = fwrite(buf1, 1, 4095, stdout);
  fprintf(stderr, "A %d\n", r);
  r = fwrite(buf2, 1, 4095, stdout);
  fprintf(stderr, "B %d\n", r);
  r = fflush(stdout);
  fprintf(stderr, "C %d\n", r);
  clearerr(stdout);
  r = fflush(stdout);
  fprintf(stderr, "D %d\n", r);
}
% strace -o /tmp/zz ./a.out|(sleep 60; od -c) &
[1] 3751 3753
% pid:3752
A 4095
B 4095

% kill -USR1 3752
% C -1
D 0

% 0000000   a   a   a   a   a   a   a   a   a   a   a   a   a   a   a   a
*
0007760   a   a   a   a   a   a   a   a   a   a   a   a   a   a   a   b
0010000

[1]  + done       strace -o /tmp/zz ./a.out | (; sleep 60; od -c; )
% tail -30 /tmp/zz
access("/etc/ld.so.nohwcap", F_OK)      = -1 ENOENT (No such file or directory)
open("/etc/ld.so.preload", O_RDONLY)    = -1 ENOENT (No such file or directory)
open("/etc/ld.so.cache", O_RDONLY)      = 5
fstat64(5, {st_mode=S_IFREG|0644, st_size=37898, ...}) = 0
old_mmap(NULL, 37898, PROT_READ, MAP_PRIVATE, 5, 0) = 0x40018000
close(5)                                = 0
access("/etc/ld.so.nohwcap", F_OK)      = -1 ENOENT (No such file or directory)
open("/lib/libc.so.6", O_RDONLY)        = 5
read(5, "\177ELF\1\1\1\0\0\0\0\0\0\0\0\0\3\0\3\0\1\0\0\0\200^\1"..., 512) = 512
fstat64(5, {st_mode=S_IFREG|0644, st_size=1244080, ...}) = 0
old_mmap(NULL, 1254244, PROT_READ|PROT_EXEC, MAP_PRIVATE, 5, 0) = 0x40022000
old_mmap(0x4014a000, 32768, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED, 5, 0x127000) = 0x4014a000
old_mmap(0x40152000, 9060, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x40152000
close(5)                                = 0
munmap(0x40018000, 37898)               = 0
getpid()                                = 3752
write(2, "pid:3752\n", 9)               = 9
rt_sigaction(SIGUSR1, {0x8048514, [], SA_RESTORER, 0x4004b5e8}, NULL, 8) = 0
fstat64(1, {st_mode=S_IFIFO|0600, st_size=0, ...}) = 0
old_mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x40018000
write(2, "A 4095\n", 7)                 = 7
write(1, "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa"..., 4096) = 4096
write(2, "B 4095\n", 7)                 = 7
write(1, "bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb"..., 4094) = ? ERESTARTSYS (To be restarted)
--- SIGUSR1 (User defined signal 1) @ 0 (0) ---
sigreturn()                             = ? (mask now [])
write(2, "C -1\n", 5)                   = 5
write(2, "D 0\n", 4)                    = 4
munmap(0x40018000, 4096)                = 0
exit_group(4)                           = ?
%

やっぱ lost する。

とすると、stdio を使う限りは SA_RESTART するのが適切か。

SA_RESTART にすると、lost しない。まぁ、stdio から割り込みが見えなくなるのでこれは当然だけど。

% strace -o /tmp/zzr ./a.out|(sleep 60; od -c) &
[1] 3832 3834
% pid:3833
A 4095
B 4095
kill -USR1 3833
% 0000000   a   a   a   a   a   a   a   a   a   a   a   a   a   a   a   a
*
0007760   a   a   a   a   a   a   a   a   a   a   a   a   a   a   a   b
0010000   b   b   b   b   b   b   b   b   b   b   b   b   b   b   b   b
*
C 0
D 0
0017760   b   b   b   b   b   b   b   b   b   b   b   b   b   b
0017776

[1]  + done       strace -o /tmp/zzr ./a.out | (; sleep 60; od -c; )
% tail -30 /tmp/zzr
open("/etc/ld.so.preload", O_RDONLY)    = -1 ENOENT (No such file or directory)
open("/etc/ld.so.cache", O_RDONLY)      = 5
fstat64(5, {st_mode=S_IFREG|0644, st_size=37898, ...}) = 0
old_mmap(NULL, 37898, PROT_READ, MAP_PRIVATE, 5, 0) = 0x40018000
close(5)                                = 0
access("/etc/ld.so.nohwcap", F_OK)      = -1 ENOENT (No such file or directory)
open("/lib/libc.so.6", O_RDONLY)        = 5
read(5, "\177ELF\1\1\1\0\0\0\0\0\0\0\0\0\3\0\3\0\1\0\0\0\200^\1"..., 512) = 512
fstat64(5, {st_mode=S_IFREG|0644, st_size=1244080, ...}) = 0
old_mmap(NULL, 1254244, PROT_READ|PROT_EXEC, MAP_PRIVATE, 5, 0) = 0x40022000
old_mmap(0x4014a000, 32768, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED, 5, 0x127000) = 0x4014a000
old_mmap(0x40152000, 9060, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, -1, 0) = 0x40152000
close(5)                                = 0
munmap(0x40018000, 37898)               = 0
getpid()                                = 3833
write(2, "pid:3833\n", 9)               = 9
rt_sigaction(SIGUSR1, {0x8048514, [], SA_RESTORER|SA_RESTART, 0x4004b5e8}, NULL, 8) = 0
fstat64(1, {st_mode=S_IFIFO|0600, st_size=0, ...}) = 0
old_mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) = 0x40018000
write(2, "A 4095\n", 7)                 = 7
write(1, "aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa"..., 4096) = 4096
write(2, "B 4095\n", 7)                 = 7
write(1, "bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb"..., 4094) = ? ERESTARTSYS (To be restarted)
--- SIGUSR1 (User defined signal 1) @ 0 (0) ---
sigreturn()                             = ? (mask now [])
write(1, "bbbbbbbbbbbbbbbbbbbbbbbbbbbbbbbb"..., 4094) = 4094
write(2, "C 0\n", 4)                    = 4
write(2, "D 0\n", 4)                    = 4
munmap(0x40018000, 4096)                = 0
exit_group(4)                           = ?
%

[latest]

田中哲