天泣記

2009-02-06 (Fri)

#1

boron で、IPv6 の connect がブロックする

boron% uname -a
Linux boron 2.6.18-6-686 #1 SMP Fri Dec 12 16:48:28 UTC 2008 i686 GNU/Linux
boron% ./ruby -v -rsocket -e '
s = Socket.new(:INET6, :STREAM)
s.bind(Socket.sockaddr_in(0, "::"))
s.listen(5)
c = Socket.new(:INET6, :STREAM)
c.connect(Socket.sockaddr_in(s.local_address.ip_port, "::1"))'
ruby 1.9.2dev (2009-02-06 trunk 22083) [i686-linux]
終わらない

strace すると、connect でブロックしてるのがわかる

...
socket(PF_INET6, SOCK_STREAM, IPPROTO_IP) = 3
bind(3, {sa_family=AF_INET6, sin6_port=htons(0), inet_pton(AF_INET6, "::", &sin6_addr), sin6_flowinfo=0, sin6_scope_id=0}, 28) = 0
listen(3, 5)                            = 0
socket(PF_INET6, SOCK_STREAM, IPPROTO_IP) = 4
getsockname(3, {sa_family=AF_INET6, sin6_port=htons(40590), inet_pton(AF_INET6, "::", &sin6_addr), sin6_flowinfo=0, sin6_scope_id=0}, [28]) = 0
getsockopt(3, SOL_SOCKET, SO_TYPE, [1], [4]) = 0
connect(4, {sa_family=AF_INET6, sin6_port=htons(40590), inet_pton(AF_INET6, "::1", &sin6_addr), sin6_flowinfo=0, sin6_scope_id=0}, 28

手元とかではとくに問題なく動く

nute% uname -a
Linux nute 2.6.18-6-486 #1 Fri Dec 12 16:18:30 UTC 2008 i686 GNU/Linux
nute% ./ruby -v -rsocket -e '
s = Socket.new(:INET6, :STREAM)
s.bind(Socket.sockaddr_in(0, "::"))
s.listen(5)
c = Socket.new(:INET6, :STREAM)
c.connect(Socket.sockaddr_in(s.local_address.ip_port, "::1"))'
ruby 1.9.2dev (2009-02-06 trunk 22083) [i686-linux]
すぐ終わる

どっちも Debian GNU/Linux (etch) で、uname を見る限り違うのは SMP かどうかくらい?

なんでこんな違いが出るのかなぁ

#2

いちおう古い ruby でも試してみるが、やはりブロックする

% ruby -v -rsocket -e '
s = Socket.new(Socket::PF_INET6, Socket::SOCK_STREAM, 0)
s.bind(Socket.sockaddr_in(0, "::"))
s.listen(5)
c = Socket.new(Socket::PF_INET6, Socket::SOCK_STREAM, 0)
c.connect(Socket.sockaddr_in(Socket.unpack_sockaddr_in(s.getsockname)[0], "::1"))'
ruby 1.8.5 (2006-08-25) [i486-linux]
(終わらない)

strace はちょっと違う。1.8 では nonblocking connect で、select でブロックしてる

...
connect(4, {sa_family=AF_INET6, sin6_port=htons(46087), inet_pton(AF_INET6, "::1", &sin6_addr), sin6_flowinfo=0, sin6_scope_id=0}, 28) = -1 EINPROGRESS (Operation now in progress)
select(5, NULL, [4], [4], NULL

connect がうまくいかないという意味では同じ

2009-02-08 (Sun)

#1

Programming UNIX Sockets in C - Frequently Asked Questions に、「4.12 マルチホームのサーバを書くにはどうすればよいですか」というすばらしい項目があることに気がつく。

うぅむ。broadcast を扱うには broadcast address に bind するのか。

しかし、IP_PKTINFO だと interface index が得られるから、最後の「あるパケットの宛先が INADDR_BROADCAST であれば、そのパケットがどちらのサブネットから来たものかを知ることはできない」っていう問題もないし、素直だよな。

2009-02-09 (Mon)

#1

FreeBSD の LOCAL_PEERCRED はどう使うのが正しいか。

<URL:http://www.google.com/codesearch?hl=ja&lr=&q=getsockopt+LOCAL_PEERCRED>

検索すると

getsockopt(s, LOCAL_PEERCRED, 1, buf, len)
getsockopt(s, 0, LOCAL_PEERCRED, buf, len)

という 2種類がみられる。

LOCAL_PEERCRED は 1 なので、展開すると

getsockopt(s, 1, 1, buf, len)
getsockopt(s, 0, 1, buf, len)

である。

<URL:http://www.FreeBSD.org/cgi/cvsweb.cgi/src/lib/libc/gen/getpeereid.c?rev=1.6>

getpeereid の実装をみると、後者が正しいようだ。

#2

getsockopt(s, 0, LOCAL_PEERCRED, buf, len) というのは、getsockopt の第2引数 level の意味がどういう文脈で解釈されるか、という点について示唆をあたえてくれる。

ふつう level には、SOL_SOCKET とか、IPPROTO_XXX とかを与える。そして、IPPROTO_IP は 0 である。

では、LOCAL_PEERCRED のときの 0 は IPPROTO_IP なのかというと、そうではなさそうである。

というのは、LOCAL_PEERCRED は Unix domain socket の機能で、IP とは関係ないからである。

歴史的に、Unix domain socket の機能は SOL_SOCKET で扱う慣習があるが、その慣習から脱して Unix domain socket のための level を考えるのはありうる話である。

そして、SOL_SOCKET 以外の level はひとつで十分だとすれば、とりあえず 0 を使えば十分だ、ということだろうか。LOCALPROTO_LOCAL とかにしておけばいいのに、と思わないでもないが。

#3

探してみると、DECnet の例が見つかった。

getsockopt(s, DNPROTO_NSP, SO_CONACCESS, &accessdata, &len)

意味は分からないが、IPPROTO_XXX とは別系列の何かが存在するということはわかる。

2009-02-11 (Wed)

#1

socket option と ancillary data は似た位置づけにある。

socket option は level と optname で選び、ancillary data は cmsg_level と cmsg_type で選ぶ。

SOL_SOCKET や IPPROTO_XXX はどちらの level にも使う。また、optname と cmsg_type は IPv6 (RFC 3542) では意図的に同じ定数を使う。

そうすると、当然、ancillary data も (socket option と同様に) family に依存していると推測される。

たとえば、IPPROTO_XXX は UNIX domain socket には適用できないであろう。

では、IPPROTO_XXX ではない別系列の定数が cmsg_level に使われることはあるか?

なお、UNIX domain socket に特有の fd passing は (おそらく歴史的経緯により) SOL_SOCKET なので、求めている例にはならない。

RFC 3542 によれば、cmsg は OSI で使われていたらしい (というか、cmsg は OSI のために 4.3BSD Reno で導入されたらしい) ので、4.3BSD Reno を探してみると、以下のようなコードが見付かる。

./src/netiso/cisink.c
  cbuf.cm.cmhdr.cmsg_level = SOL_TRANSPORT;
  cbuf.cm.cmhdr.cmsg_type = TPOPT_CFRM_DATA;

うぅむ。OSIPROTO_XXX ってわけじゃないのか。

2009-02-16 (Mon)

#1

以前から、五月雨を動かしているときに、rb_thread_schedule と rb_thread_execute_interrupts が相互再帰しまくって SEGV という症状がまれにある。

起きないときはぜんぜん起きないのだが、起きるときはそれなりに起こる。去年の 10/12 には 33回、12/22 に2回、12/24 に2回起きた。そして、今年になって 2/13 に 2回起きた。

最新のふたつをちょっとみてみよう。

#0  rb_thread_execute_interrupts (th=0x8ca3910) at thread.c:1232
1232                    rb_thread_schedule();
#0  rb_thread_execute_interrupts (th=0x8ca3910) at thread.c:1232
#1  0x08140e15 in rb_thread_schedule () at thread.c:947
#2  0x08141352 in rb_thread_execute_interrupts (th=0x8ca3910) at thread.c:1232
#3  0x08140e15 in rb_thread_schedule () at thread.c:947
#4  0x08141352 in rb_thread_execute_interrupts (th=0x8ca3910) at thread.c:1232
#5  0x08140e15 in rb_thread_schedule () at thread.c:947
#6  0x08141352 in rb_thread_execute_interrupts (th=0x8ca3910) at thread.c:1232
#7  0x08140e15 in rb_thread_schedule () at thread.c:947
#8  0x08141352 in rb_thread_execute_interrupts (th=0x8ca3910) at thread.c:1232
#9  0x08140e15 in rb_thread_schedule () at thread.c:947
#10 0x08141352 in rb_thread_execute_interrupts (th=0x8ca3910) at thread.c:1232
#11 0x08140e15 in rb_thread_schedule () at thread.c:947
#12 0x08141352 in rb_thread_execute_interrupts (th=0x8ca3910) at thread.c:1232
...
#8989 0x08140e15 in rb_thread_schedule () at thread.c:947
#8990 0x08141352 in rb_thread_execute_interrupts (th=0x8ca3910)
    at thread.c:1232
#8991 0x08140e15 in rb_thread_schedule () at thread.c:947
#8992 0x08141352 in rb_thread_execute_interrupts (th=0x8ca3910)
    at thread.c:1232
#8993 0x08140e15 in rb_thread_schedule () at thread.c:947
#8994 0x08141352 in rb_thread_execute_interrupts (th=0x8ca3910)
    at thread.c:1232
#8995 0x08140e15 in rb_thread_schedule () at thread.c:947
#8996 0x08141352 in rb_thread_execute_interrupts (th=0x8ca3910)
    at thread.c:1232
#8997 0x08134b97 in vm_call_method (th=0x8ca3910, cfp=0xb734e948, num=1, 
    blockptr=0xb734e95c, flag=0, id=2072, mn=0x81feca0, recv=142432520)
    at vm_insnhelper.c:599
#8998 0x08130ebe in vm_exec_core (th=0x8ca3910, initial=0) at insns.def:1000
#8999 0x0813c61f in vm_exec (th=0x8ca3910) at vm.c:1078
#9000 0x08137b33 in vm_call0 (th=0x8ca3910, klass=141083360, recv=153014260, 
    id=456, oid=456, argc=1, argv=0xb72cf2fc, body=0x8733d88, nosuper=0)
    at vm_eval.c:58
#9001 0x0813882e in rb_call0 (klass=141083360, recv=153014260, mid=456, 
    argc=1, argv=0xb72cf2fc, scope=1, self=6) at vm_eval.c:250
#9002 0x081384fa in rb_call (klass=141083360, recv=153014260, mid=456, argc=1, 
    argv=0xb72cf2fc, scope=1) at vm_eval.c:256
#9003 0x0813892d in rb_funcall2 (recv=153014260, mid=456, argc=1, 
    argv=0xb72cf2fc) at vm_eval.c:413
#9004 0x0805bb50 in rb_obj_call_init (obj=153014260, argc=1, argv=0xb72cf2fc)
    at eval.c:787
#9005 0x0808743a in rb_class_new_instance (argc=1, argv=0xb72cf2fc, 
    klass=141083360) at object.c:1483
#9006 0x081350f9 in call_cfunc (func=0x808740d <rb_class_new_instance>, 
    recv=141083360, len=-1, argc=1, argv=0xb72cf2fc) at vm_insnhelper.c:286
#9007 0x08134f70 in vm_call_cfunc (th=0x8ca3910, reg_cfp=0xb734ea08, num=1, 
    id=32512, oid=960, recv=141083360, klass=136330160, flag=0, mn=0x8201a90, 
    blockptr=0x0) at vm_insnhelper.c:376
#9008 0x08134814 in vm_call_method (th=0x8ca3910, cfp=0xb734ea08, num=1, 
    blockptr=0x0, flag=0, id=32512, mn=0x8733dec, recv=141083360)
    at vm_insnhelper.c:502
#9009 0x08130ebe in vm_exec_core (th=0x8ca3910, initial=0) at insns.def:1000
#9010 0x0813c61f in vm_exec (th=0x8ca3910) at vm.c:1078
#9011 0x0813b4b2 in invoke_block_from_c (th=0x8ca3910, block=0xb734eb0c, 
    self=136915340, argc=1, argv=0xb72cb250, blockptr=0x0, cref=0x0)
    at vm.c:524
#9012 0x0813b540 in vm_yield (th=0x8ca3910, argc=1, argv=0xb72cb250)
    at vm.c:554
#9013 0x08138aec in rb_yield_0 (argc=1, argv=0xb72cb250) at vm_eval.c:485
#9014 0x08138ac2 in rb_yield (val=142432440) at vm_eval.c:495
#9015 0x0814ee8f in rb_ary_collect (ary=152448440) at array.c:1907
#9016 0x0813510f in call_cfunc (func=0x814edd9 <rb_ary_collect>, 
    recv=152448440, len=0, argc=0, argv=0xb72cf290) at vm_insnhelper.c:289
#9017 0x08134f70 in vm_call_cfunc (th=0x8ca3910, reg_cfp=0xb734eaf8, num=0, 
    id=1496, oid=1496, recv=152448440, klass=136277340, flag=0, mn=0x81f621c, 
    blockptr=0xb734eb0c) at vm_insnhelper.c:376
#9018 0x08134814 in vm_call_method (th=0x8ca3910, cfp=0xb734eaf8, num=0, 
    blockptr=0xb734eb0c, flag=0, id=1496, mn=0x81f6208, recv=152448440)
    at vm_insnhelper.c:502
#9019 0x08130ebe in vm_exec_core (th=0x8ca3910, initial=0) at insns.def:1000
#9020 0x0813c61f in vm_exec (th=0x8ca3910) at vm.c:1078
#9021 0x0813b4b2 in invoke_block_from_c (th=0x8ca3910, block=0xb734ebcc, 
    self=136915340, argc=1, argv=0xb72cbc00, blockptr=0x0, cref=0x0)
    at vm.c:524
#9022 0x0813b540 in vm_yield (th=0x8ca3910, argc=1, argv=0xb72cbc00)
    at vm.c:554
#9023 0x08138aec in rb_yield_0 (argc=1, argv=0xb72cbc00) at vm_eval.c:485
#9024 0x08138ac2 in rb_yield (val=152448400) at vm_eval.c:495
#9025 0x0814ee8f in rb_ary_collect (ary=152448800) at array.c:1907
#9026 0x0813510f in call_cfunc (func=0x814edd9 <rb_ary_collect>, 
    recv=152448800, len=0, argc=0, argv=0xb72cf234) at vm_insnhelper.c:289
#9027 0x08134f70 in vm_call_cfunc (th=0x8ca3910, reg_cfp=0xb734ebb8, num=0, 
    id=1496, oid=1496, recv=152448800, klass=136277340, flag=0, mn=0x81f621c, 
    blockptr=0xb734ebcc) at vm_insnhelper.c:376
#9028 0x08134814 in vm_call_method (th=0x8ca3910, cfp=0xb734ebb8, num=0, 
    blockptr=0xb734ebcc, flag=0, id=1496, mn=0x81f6208, recv=152448800)
    at vm_insnhelper.c:502
#9029 0x08130ebe in vm_exec_core (th=0x8ca3910, initial=0) at insns.def:1000
#9030 0x0813c61f in vm_exec (th=0x8ca3910) at vm.c:1078
#9031 0x0813b4b2 in invoke_block_from_c (th=0x8ca3910, block=0xb734ec8c, 
    self=136915340, argc=1, argv=0xb72cc5b0, blockptr=0x0, cref=0x0)
    at vm.c:524
#9032 0x0813b540 in vm_yield (th=0x8ca3910, argc=1, argv=0xb72cc5b0)
    at vm.c:554
#9033 0x08138aec in rb_yield_0 (argc=1, argv=0xb72cc5b0) at vm_eval.c:485
#9034 0x08138ac2 in rb_yield (val=152447820) at vm_eval.c:495
#9035 0x0814ee8f in rb_ary_collect (ary=152813560) at array.c:1907
#9036 0x0813510f in call_cfunc (func=0x814edd9 <rb_ary_collect>, 
    recv=152813560, len=0, argc=0, argv=0xb72cf1d8) at vm_insnhelper.c:289
#9037 0x08134f70 in vm_call_cfunc (th=0x8ca3910, reg_cfp=0xb734ec78, num=0, 
    id=1496, oid=1496, recv=152813560, klass=136277340, flag=0, mn=0x81f621c, 
    blockptr=0xb734ec8c) at vm_insnhelper.c:376
#9038 0x08134814 in vm_call_method (th=0x8ca3910, cfp=0xb734ec78, num=0, 
    blockptr=0xb734ec8c, flag=0, id=1496, mn=0x81f6208, recv=152813560)
    at vm_insnhelper.c:502
#9039 0x08130ebe in vm_exec_core (th=0x8ca3910, initial=0) at insns.def:1000
#9040 0x0813c61f in vm_exec (th=0x8ca3910) at vm.c:1078
#9041 0x0813b4b2 in invoke_block_from_c (th=0x8ca3910, block=0xb734ed4c, 
    self=136915340, argc=1, argv=0xb72ccf60, blockptr=0x0, cref=0x0)
    at vm.c:524
#9042 0x0813b540 in vm_yield (th=0x8ca3910, argc=1, argv=0xb72ccf60)
    at vm.c:554
#9043 0x08138aec in rb_yield_0 (argc=1, argv=0xb72ccf60) at vm_eval.c:485
#9044 0x08138ac2 in rb_yield (val=151282340) at vm_eval.c:495
#9045 0x0814ee8f in rb_ary_collect (ary=152816400) at array.c:1907
#9046 0x0813510f in call_cfunc (func=0x814edd9 <rb_ary_collect>, 
    recv=152816400, len=0, argc=0, argv=0xb72cf17c) at vm_insnhelper.c:289
#9047 0x08134f70 in vm_call_cfunc (th=0x8ca3910, reg_cfp=0xb734ed38, num=0, 
    id=1496, oid=1496, recv=152816400, klass=136277340, flag=0, mn=0x81f621c, 
    blockptr=0xb734ed4c) at vm_insnhelper.c:376
#9048 0x08134814 in vm_call_method (th=0x8ca3910, cfp=0xb734ed38, num=0, 
    blockptr=0xb734ed4c, flag=0, id=1496, mn=0x81f6208, recv=152816400)
    at vm_insnhelper.c:502
#9049 0x08130ebe in vm_exec_core (th=0x8ca3910, initial=0) at insns.def:1000
#9050 0x0813c61f in vm_exec (th=0x8ca3910) at vm.c:1078
#9051 0x0813b4b2 in invoke_block_from_c (th=0x8ca3910, block=0xb734ee0c, 
    self=136915340, argc=1, argv=0xb72cd910, blockptr=0x0, cref=0x0)
    at vm.c:524
#9052 0x0813b540 in vm_yield (th=0x8ca3910, argc=1, argv=0xb72cd910)
    at vm.c:554
#9053 0x08138aec in rb_yield_0 (argc=1, argv=0xb72cd910) at vm_eval.c:485
#9054 0x08138ac2 in rb_yield (val=151282220) at vm_eval.c:495
#9055 0x0814ee8f in rb_ary_collect (ary=152816500) at array.c:1907
#9056 0x0813510f in call_cfunc (func=0x814edd9 <rb_ary_collect>, 
    recv=152816500, len=0, argc=0, argv=0xb72cf120) at vm_insnhelper.c:289
#9057 0x08134f70 in vm_call_cfunc (th=0x8ca3910, reg_cfp=0xb734edf8, num=0, 
    id=1496, oid=1496, recv=152816500, klass=136277340, flag=0, mn=0x81f621c, 
    blockptr=0xb734ee0c) at vm_insnhelper.c:376
#9058 0x08134814 in vm_call_method (th=0x8ca3910, cfp=0xb734edf8, num=0, 
    blockptr=0xb734ee0c, flag=0, id=1496, mn=0x81f6208, recv=152816500)
    at vm_insnhelper.c:502
#9059 0x08130ebe in vm_exec_core (th=0x8ca3910, initial=0) at insns.def:1000
#9060 0x0813c61f in vm_exec (th=0x8ca3910) at vm.c:1078
#9061 0x0813b4b2 in invoke_block_from_c (th=0x8ca3910, block=0x898a9e8, 
    self=144238200, argc=0, argv=0x82b2b54, blockptr=0x0, cref=0x0) at vm.c:524
#9062 0x0813b5f2 in rb_vm_invoke_proc (th=0x8ca3910, proc=0x898a9e8, 
    self=144238200, argc=0, argv=0x82b2b54, blockptr=0x0) at vm.c:571
#9063 0x0813ff5a in thread_start_func_2 (th=0x8ca3910, stack_start=0xb72ce450)
    at thread.c:381
#9064 0x0813f25b in thread_start_func_1 (th_ptr=0x8ca3910)
    at thread_pthread.c:356
#9065 0xb7f2a240 in start_thread () from /lib/tls/i686/cmov/libpthread.so.0
#9066 0xb7e5e49e in clone () from /lib/tls/i686/cmov/libc.so.6

これは vm_call_method から始まっている。

だが、これはいつもというわけではなくて、もうひとつは実際違う。

#0  0xb7f64006 in pthread_mutex_lock () from /lib/tls/i686/cmov/libpthread.so.0
#0  0xb7f64006 in pthread_mutex_lock () from /lib/tls/i686/cmov/libpthread.so.0
#1  0x0813eef5 in native_mutex_lock (lock=0x81d3874) at thread_pthread.c:36
#2  0x08140de5 in rb_thread_schedule () at thread.c:942
#3  0x08141352 in rb_thread_execute_interrupts (th=0x8c9f060) at thread.c:1232
#4  0x08140e15 in rb_thread_schedule () at thread.c:947
#5  0x08141352 in rb_thread_execute_interrupts (th=0x8c9f060) at thread.c:1232
#6  0x08140e15 in rb_thread_schedule () at thread.c:947
#7  0x08141352 in rb_thread_execute_interrupts (th=0x8c9f060) at thread.c:1232
#8  0x08140e15 in rb_thread_schedule () at thread.c:947
#9  0x08141352 in rb_thread_execute_interrupts (th=0x8c9f060) at thread.c:1232
...
#9240 0x08140e15 in rb_thread_schedule () at thread.c:947
#9241 0x08141352 in rb_thread_execute_interrupts (th=0x8c9f060)
    at thread.c:1232
#9242 0x08140e15 in rb_thread_schedule () at thread.c:947
#9243 0x08141352 in rb_thread_execute_interrupts (th=0x8c9f060)
    at thread.c:1232
#9244 0x08140e15 in rb_thread_schedule () at thread.c:947
#9245 0xb7a883d5 in zstream_run (z=0x8b8b9b8, src=0x0, len=0, flush=2)
    at zlib.c:725
#9246 0xb7a8b123 in gzfile_read_header (gz=0x8b8b9b8) at zlib.c:2019
#9247 0xb7a8d11a in rb_gzreader_initialize (argc=1, argv=0xb78110c0, 
    obj=142306260) at zlib.c:2965
#9248 0x081350f9 in call_cfunc (func=0xb7a8d015 <rb_gzreader_initialize>, 
    recv=142306260, len=-1, argc=1, argv=0xb78110c0) at vm_insnhelper.c:286
#9249 0x08137c7f in vm_call0 (th=0x8c9f060, klass=139769960, recv=142306260, 
    id=456, oid=456, argc=1, argv=0xb78110c0, body=0x854ae68, nosuper=0)
    at vm_eval.c:72
#9250 0x0813882e in rb_call0 (klass=139769960, recv=142306260, mid=456, 
    argc=1, argv=0xb78110c0, scope=1, self=6) at vm_eval.c:250
#9251 0x081384fa in rb_call (klass=139769960, recv=142306260, mid=456, argc=1, 
    argv=0xb78110c0, scope=1) at vm_eval.c:256
#9252 0x0813892d in rb_funcall2 (recv=142306260, mid=456, argc=1, 
    argv=0xb78110c0) at vm_eval.c:413
#9253 0x0805bb50 in rb_obj_call_init (obj=142306260, argc=1, argv=0xb78110c0)
    at eval.c:787
#9254 0x0808743a in rb_class_new_instance (argc=1, argv=0xb78110c0, 
    klass=139769960) at object.c:1483
#9255 0x081350f9 in call_cfunc (func=0x808740d <rb_class_new_instance>, 
    recv=139769960, len=-1, argc=1, argv=0xb78110c0) at vm_insnhelper.c:286
#9256 0x08134f70 in vm_call_cfunc (th=0x8c9f060, reg_cfp=0xb7890e88, num=1, 
    id=960, oid=960, recv=139769960, klass=136330160, flag=0, mn=0x8201a90, 
    blockptr=0x0) at vm_insnhelper.c:376
#9257 0x08134814 in vm_call_method (th=0x8c9f060, cfp=0xb7890e88, num=1, 
    blockptr=0x0, flag=0, id=960, mn=0x8201a7c, recv=139769960)
    at vm_insnhelper.c:502
#9258 0x08130ebe in vm_exec_core (th=0x8c9f060, initial=0) at insns.def:1000
#9259 0x0813c61f in vm_exec (th=0x8c9f060) at vm.c:1078
#9260 0x0813b4b2 in invoke_block_from_c (th=0x8c9f060, block=0x88ea8d8, 
    self=144042760, argc=0, argv=0x89444b8, blockptr=0x0, cref=0x0) at vm.c:524
#9261 0x0813b5f2 in rb_vm_invoke_proc (th=0x8c9f060, proc=0x88ea8d8, 
    self=144042760, argc=0, argv=0x89444b8, blockptr=0x0) at vm.c:571
#9262 0x0813ff5a in thread_start_func_2 (th=0x8c9f060, stack_start=0xb7810450)
    at thread.c:381
#9263 0x0813f25b in thread_start_func_1 (th_ptr=0x8c9f060)
    at thread_pthread.c:356
#9264 0xb7f62240 in start_thread () from /lib/tls/i686/cmov/libpthread.so.0
#9265 0xb7e9649e in clone () from /lib/tls/i686/cmov/libc.so.6

こちらでは、zstream_run から始まっている。

ちょっと調べてみようと思い立って、rb_thread_execute_interrupts と rb_thread_schedule に細工をいれて、相互再帰が起きたときに表示するようにしてみると、落ちなくてもそれなりに相互再帰が起こっているようだ。数時間動かしただけで数十段階の相互再帰がいくつも出てくる。おそらく、ごくまれにそれが何千段階になってしまったときに、stack overflow で落ちるのであろう。

#2

NetBSD kern/40661: kernel: page fault trap by IPV6_PKTINFO

2009-02-17 (Tue)

#1

OpenBSD kern/6080: msg_controllen of IPV6_PKTINFO

おぉ、これはバグではなく、意図してそうなっているのか。

2009-02-18 (Wed)

#1

datagram socket (例: UDP や UNIX datagram) で、長さがわからないデータを確実に受け取るにはどうしたらいいか。

ということで、長さがわからない場合は MSG_PEEK で試してから実際に読むということにしているのだが、SCM_RIGHTS で問題が出ることが分かった。

UNIX datagram socket で、長さを調べるために MSG_PEEK で読んだとき、相手が SCM_RIGHTS で fd を送ってくると、読み出した側に新しい fd ができる。長さを調べるのにこれを何回か繰り返すと、繰り返し毎に新しい fd ができていく。最終的に長さが分かって MSG_PEEK を抜いて読むと、さらに新しい fd ができる。

ここで、fd の leak を防ぐためには、最後以外での fd を close しないといけない。

うぅむ。

まぁ、SCM_RIGHTS はとっても有名なので対処すれば済むというのはそうである。でも、一般にそれ以外でも資源の確保がありうるとすると、個々に書いていかないといけないのだろうか。きっとそうなんだろうなぁ。いまのところ SCM_RIGHTS 以外に見当たらないのがせめてもの幸いではあるが。

そういう資源の確保を抑制するフラグが欲しいところだ。

2009-02-19 (Thu)

#1

負荷が高いと test_udp_server がうまく動かない?

現状、test_udp_server は手元の環境でとくに問題なく動いている。

% uname -a
Linux nute 2.6.18-6-486 #1 Fri Dec 12 16:18:30 UTC 2008 i686 GNU/Linux
% cat /etc/debian_version 
4.0
% ./ruby -v test/socket/test_socket.rb -v -n test_udp_server 
ruby 1.9.2dev (2009-02-15 trunk 22328) [i686-linux]
Loaded suite test/socket/test_socket
Started
TestSocket#test_udp_server: 0.00 s: .

Finished in 0.005410 seconds.

1 tests, 8 assertions, 0 failures, 0 errors, 0 skips

が、昨日、唐突にハングしまくるという症状が観測された。(タイムアウトするようにしてあるので、20秒で終了するが)

いろいろと調べた結果、どうも、無限ループしているプロセスが他に存在したのが原因なようだ。

実際、以下のような無限ループを動かしておくと再現できる。

% ruby -e 'loop {}'

そうやってハングした場合は以下のようになる。

% ./ruby -v test/socket/test_socket.rb -v -n test_udp_server
ruby 1.9.2dev (2009-02-15 trunk 22328) [i686-linux]
Loaded suite test/socket/test_socket
Started
TestSocket#test_udp_server: 20.19 s: E

Finished in 20.188279 seconds.

  1) Error:
test_udp_server(TestSocket):
RuntimeError: thread killed
    test/socket/test_socket.rb:269:in `ensure in block in test_udp_server'
    test/socket/test_socket.rb:269:in `block in test_udp_server'

1 tests, 2 assertions, 0 failures, 1 errors, 0 skips

どうも、スレッドがスイッチしない感じだが...

GVL が mutex っていうのが非常識らしいというのが気になるのだが、どうなのかな。

#2

ここで「非常識」というのは、mutex はロックしたらすぐにアンロックするもので、ロックできないというのは稀にしか起こらない状況に使うものである、という話を聞いたことがあるからである。

GVL はあきらかにそうでない。

#3

OpenBSD kern/6082: recvmsg creates too much file descriptors with SCM_RIGHTS if buffer is too small.

今度はどうか。

まぁ、これは OpenBSD だけじゃないのだが、とりあえず OpenBSD に報告してみた。

2009-02-20 (Fri)

#1

FreeBSD kern/131876: FD leak by receiving SCM_RIGHTS by recvmsg with small control message buffer

OpenBSD と同じ問題。

#2

NetBSD kern/40696: FD leak by recvmsg when receiving too much file descriptors with SCM_RIGHTS.

NetBSD も。(これは対処しようとしてうまくいってない?)

#3

今日は dhclient で特定の dhcp サーバを無視させる方法を学んでしまった。

2009-02-21 (Sat)

#1

OpenSSL FAQ: Can I use OpenSSL's SSL library with non-blocking I/O?

うぅむ。read するのに write が必要だったり、(またその逆が必要だったり) することもあるのか。

結局、以前考えた話は残念なことに実際にありうる、ということだな。

2009-02-22 (Sun)

#1

nonblocking I/O で、失敗したときになにを待つべきか、というのをもう少し考えてみると、エラー自体にその情報が含まれているべきなのであろう。

EWOULDBLOCK にはその情報が入っていない (read/write/except のどれで select で待てばいいのかわからない) のがよろしくない。

まぁ、エラーメッセージに書いておくのと、モジュールを 3つ作って例外オブジェクトに extend しておくあたりがいいのではないか。

モジュールは IO::Want{Read,Write,Except} とか?

#2

そういや select の except をつかうのってなんだったかな。

まぁ、カーネルが使いたいと思えば使うというだけの話ではあるのだが、具体的にはたしか tty まわりにあったはず... と思って探してみると pty のパケットモード (TIOCPKT) か。

#3

POSIX を調べ直すと、select の項にちょっと載っていた。

これなら試せるので試す。

だれも待ってない 9999番にパケットを送ると、エラーが返ってきて socket に溜るはずである。

% ruby -rsocket -ve '
Addrinfo.udp("127.0.0.1", 9999).connect {|s|
  s.send("a", 0)
  p IO.select([s], [], [s])
  p s.getsockopt(:SOCKET, :ERROR)
  p s.recv(10)
}'
ruby 1.9.2dev (2009-02-15 trunk 22328) [i686-linux]
[[#<Socket:fd 3>], [], []]
#<Socket::Option: INET SOCKET ERROR 111>
(ここでブロック)

えーと、エラーにはなってるが、select では単に readable である。except のところは空っぽ。しかも、recv するとブロック。うぅむ。

#4

それはそれとして 111 がなんなのか調べるのが面倒。むか。

% ./ruby -rsocket -ve '
Addrinfo.udp("127.0.0.1", 9999).connect {|s|
  s.send("a", 0)
  p IO.select([s], [], [s])
  p s.getsockopt(:SOCKET, :ERROR)
  p s.recv(10)
}'
ruby 1.9.2dev (2009-02-22 trunk 22505) [i686-linux]
[[#<Socket:fd 3>], [], []]
#<Socket::Option: INET SOCKET ERROR Connection refused (111)>
#5

もしかして UDP だからいかんのか。TCP ならどうだ。

% ./ruby -rsocket -ve '
s = Socket.new(:INET, :STREAM)
begin
  s.connect_nonblock(Addrinfo.tcp("127.0.0.1", 9999))
rescue Errno::EINPROGRESS
  p $!
end
p IO.select([s], [], [s])
p s.getsockopt(:SOCKET, :ERROR)
p s.getsockopt(:SOCKET, :ERROR)
'
ruby 1.9.2dev (2009-02-22 trunk 22505) [i686-linux]
#<Errno::EINPROGRESS: Operation now in progress - connect(2) WANT_WRITE>
[[#<Socket:fd 3>], [], []]
#<Socket::Option: INET SOCKET ERROR Connection refused (111)>
#<Socket::Option: INET SOCKET ERROR Success (0)>

これもだめ。

#6

そういや、readable なのにブロックするっていうのはいいのだろうか。(先人の教えに従って、select とは必ず nonblocking I/O を組み合わせるようにすれば関係ない話だが、ここでは逆らってみよう)

そうか、getsockopt が副作用を持っているのか。

getsockopt がエラーを読み出すと、エラーがなくなっちゃうから、それによって、recv がブロックしない状態からブロックする状態に遷移するのだ。

getsockopt を取り除けば、ブロックしない (エラーになる)。

% ./ruby -rsocket -ve '
Addrinfo.udp("127.0.0.1", 9999).connect {|s|
  s.send("a", 0)
  p IO.select([s], [], [s])
  #p s.getsockopt(:SOCKET, :ERROR)
  p s.recv(10)
}'
ruby 1.9.2dev (2009-02-22 trunk 22526) [i686-linux]
[[#<Socket:fd 3>], [], []]
-e:6:in `recv': Connection refused - recvfrom(2) (Errno::ECONNREFUSED)
        from -e:6:in `block in <main>'
        from /home/ruby/tcstate/lib/ruby/1.9.1/socket.rb:39:in `connect_internal'
        from /home/ruby/tcstate/lib/ruby/1.9.1/socket.rb:86:in `connect'
        from -e:2:in `<main>'

2009-02-23 (Mon)

#1

SO_TIMESTAMP が予想外にポータブルである。

% ./ruby -rsocket -e '
Addrinfo.udp("127.0.0.1", 0).bind {|s1| 
  Addrinfo.udp("127.0.0.1", 0).bind {|s2| 
    s1.setsockopt(:SOCKET, :TIMESTAMP, true) 
    s2.send "a", 0, s1.local_address 
    p s1.recvmsg    
  } 
}    
'
["a", #<Addrinfo: 127.0.0.1:32816 UDP>, 0, #<Socket::AncillaryData: INET SOCKET TIMESTAMP 2009-02-23 13:15:13.747273>]

SO_TIMESTAMP を setsockopt でつけておくと、SCM_TIMESTAMP な補助データがやってきて、struct timeval でパケットの到着時刻を教えてくれる。

ちょっと調べただけで、GNU/Linux, FreeBSD, NetBSD, OpenBSD, MacOS X, Solaris にある。

では (補助データを最初に導入した) 4.4BSD からあったのかというと、4.4BSD にはない。

もちろん、SUSv3 にもない。

なのになんでこんなにポータブルなんだろう。

ていうかどこが始めたの?

調べてみると、FreeBSD のようだ。

<URL:http://www.FreeBSD.org/cgi/query-pr.cgi?pr=1179>

1996年ということは、4.4BSD-Lite2 の翌年で、かなり早い。

用途は xntpd か... まぁそれは欲しいかもしれない。

#2

なお、GNU/Linux では struct timespec を返す TIMESTAMPNS が導入されているようだ。

また、FreeBSD では struct bintime を返すのがある模様。

でも struct bintime ってなに? 探してみると以下がみつかった。

Timecounters: Efficient and precise timekeeping in SMP kernels

うぅむ。2進で小数点以下64桁か。表示が厄介だな。long double を使いたくなってしまう。

2009-02-24 (Tue)

#1

小数点以下64bit といっても、実際にはどのくらい?

% ./ruby -rsocket -ve '
Addrinfo.udp("127.0.0.1",0).bind {|s1|
  Addrinfo.udp("127.0.0.1",0).bind {|s2|
    s2.setsockopt(:SOCKET, :BINTIME, true)
    10.times {
      s1.send "a", 0, s2.local_address
      ret = s2.recvmsg
      sec = ret.last.data[0,8].reverse.unpack("H*")[0]
      frac = ret.last.data[8,8].reverse.unpack("H*")[0]
      p [sec,frac]
    }
  }
}
'
ruby 1.9.2dev (2009-02-23 trunk 22569) [x86_64-freebsd6.4]
["0000000049a2ff3c", "fd80ec9f5a9cb400"]
["0000000049a2ff3c", "fd8b52d21fc28800"]
["0000000049a2ff3c", "fd8f13a640272b80"]
["0000000049a2ff3c", "fd931ac8566db580"]
["0000000049a2ff3c", "fd96d6ec99a12780"]
["0000000049a2ff3c", "fd9c6c73213d2100"]
["0000000049a2ff3c", "fda06ee55a527980"]
["0000000049a2ff3c", "fda3f2cb3f379980"]
["0000000049a2ff3c", "fda7ddce2656fa80"]
["0000000049a2ff3c", "fdab8be2d1f6d800"]

57bit くらい?

#2

out-of-band なデータの到着は exceptional condition として検出されるようだ。

% ./ruby -rsocket -ve '
Addrinfo.tcp("127.0.0.1", 0).listen {|serv|
  serv.local_address.connect {|s1|
    s2, _ = serv.accept
    s1.send "a", Socket::MSG_OOB
    p IO.select([s2], nil, [s2])
  }
}'
ruby 1.9.2dev (2009-02-24 trunk 22579) [i686-linux]
[[], [], [#<Socket:fd 6>]]
#3

考えてみると、エラーは次の recv をブロックさせない効果があるので、readable にするのは理にかなっているのかもしれない。OOB なデータが来ただけでは次の recv はブロックするので、readable にするのはよろしくない。

現状の挙動は、ブロックするかどうかを select で判定することを真摯に考えた結果なのかも。

2009-02-25 (Wed)

#1

SO_OOBINLINE を有効にすると、OOB なデータで、exceptional condition だけでなく、readable にもなる模様。なるほど。

% ./ruby -rsocket -ve '
Addrinfo.tcp("127.0.0.1", 0).listen {|serv|
  serv.local_address.connect {|s1|
    s2, _ = serv.accept
    s2.setsockopt(:SOCKET, :OOBINLINE, true)
    s1.send "a", Socket::MSG_OOB
    p IO.select([s2], nil, [s2])
  }
}'
ruby 1.9.2dev (2009-02-24 trunk 22597) [i686-linux]
[[#<Socket:fd 6>], [], [#<Socket:fd 6>]]

む。OOBINLINE が有効だと MSG_OOB つきで recv すると EINVAL か... まぁ、いけなくはないが。

% ./ruby -rsocket -ve '
Addrinfo.tcp("127.0.0.1", 0).listen {|serv|
  serv.local_address.connect {|s1|
    s2, _ = serv.accept
    s2.setsockopt(:SOCKET, :OOBINLINE, true)
    s1.send "a", Socket::MSG_OOB
    p IO.select([s2], nil, [s2])
    p s2.recv(10, Socket::MSG_OOB)
  }
}'
ruby 1.9.2dev (2009-02-24 trunk 22597) [i686-linux]
[[#<Socket:fd 6>], [], [#<Socket:fd 6>]]
-e:8:in `recv': Invalid argument - recvfrom(2) (Errno::EINVAL)
        from -e:8:in `block (2 levels) in <main>'
        from /home/ruby/tcio/lib/ruby/1.9.1/socket.rb:39:in `connect_internal'
        from /home/ruby/tcio/lib/ruby/1.9.1/socket.rb:86:in `connect'
        from -e:3:in `block in <main>'
        from /home/ruby/tcio/lib/ruby/1.9.1/socket.rb:139:in `listen'
        from -e:2:in `<main>'
#2

File#flock の rdoc の例が以下のようなものであった。

File.new("testfile").flock(File::LOCK_UN)   #=> 0

あまり役に立ちそうにない。違う例にしておく。

ところで、LOCK_EX を使うときには File::RDWR|File::CREAT を使う。

"w" だとロックする前にファイルの内容が消えちゃうし、"r+" だとファイルがないときにエラーになる。

ちょっと間違えやすい。

#3

SOL_SOCKET は socket level の意味で、基本的にすべての種類のソケットに適用される、ということになっている。

基本はどこにいった?

いちばん可能そうな timestamp でさえ、Unix domain datagram で動かない。


[latest]


田中哲