gauche on OpenBSD

主訴: お腹が痛いです

朝食後1時間ぐらいすると、お腹が痛くなった。そしてトイレに直行。おかしいな、悪い物を食べた記憶も無いし。。。 翌日も同様だった。そして更にその翌日も。

今までと変わった事ないか? じっくり思い出すと、食後に飲む薬のメーカーが変わったという事に気づいた。

薬局で薬を貰った時、 ライセンスフリー(いわゆる、ジェネリック医薬品)なんですが、業界のごたごたがあり、いつものメーカー品が入手できないので、別メーカー品にしましたって説明があったな。

ならば、薬のせいか確認する為、飲むのを一日止めてみよう。そしたら、腹痛はしなかった。たまたまかと思って、翌日は飲んでみる。そしたら腹痛。飲まないければ腹痛なし。

医者に相談したら、かかりつけの薬剤師に相談してくださいですって。そんなものなのか。

しょうがないので、薬局で実験結果を説明。薬剤師は納得してくれたよ。 薬局のネットワークを駆使して、今までの薬が手に入るか確認しますとの事。

そして、数日して、いつもの薬が手に入った。その後、混乱してた業界も落ち着いたみたいで、普通に今までの薬が手に入るようになった。あー、よかった。

Scm_VM()->curout

前回、gdbコマンドを拡張するんで、 Scm_Printf(Scm_VM()->curout, "%S\n", obj) なんてのを使った。ユーザーからは、この慣れ親しんだのが使えないのは残念。代わりにformatを使う事になる。

それはいいんだけど、この第一引数はportを指定する事になってる。C言語の世界の事なんで、どういう風になってるか、ちと眺めてみる。

src/vm.c

/*
 * The VM.
 *
 *   VM encapsulates the dynamic status of the current execution.
 *   In Gauche, there's always one active virtual machine per thread,
 *   referred by Scm_VM().   From Scheme, VM is seen as a <thread> object.
 *
 *   From Scheme, VM is viewed as <thread> object.  The class definition
 *   is in thrlib.stub.
 */

theVMてのが、pthreads時に使われるのかな。src/gauche/vm.hには、このバーチャルマシンの定義が載ってる。

ScmPort *curin;             /* current input port */
ScmPort *curout;            /* current output port */
ScmPort *curerr;            /* current error port */

/* Registers */
ScmCompiledCode *base;      /* Current executing closure's code packet. */
SCM_PCTYPE pc;              /* Program pointer.  Points into the code
                               vector. (base->code) */
ScmEnvFrame *env;           /* Current environment.                      */
ScmContFrame *cont;         /* Current continuation.                     */
ScmObj *argp;               /* Current argument pointer.  Points
 :

等々、見ておくと吉。

sakae@deb:~/src/Gauche$ gdb -q src/gosh
Reading symbols from src/gosh...
(gdb) b Scm__InitVM
Function "Scm__InitVM" not defined.
Make breakpoint pending on future shared library load? (y or [n]) y
Breakpoint 1 (Scm__InitVM) pending.
(gdb) r
Starting program: /home/sakae/src/Gauche/src/gosh
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/i386-linux-gnu/libthread_db.so.1".

Breakpoint 1, Scm__InitVM () at vm.c:3455
3455        Scm_HashCoreInitSimple(&vm_table, SCM_HASH_EQ, 8, NULL);
(gdb) bt
#0  Scm__InitVM () at vm.c:3455
#1  0xb7bab16b in Scm_Init (signature=<optimized out>,
    signature@entry=0x4052eb "0.98,utf8,pthreads") at core.c:180
#2  0x004025b5 in main (ac=1, av=0xbffff634) at main.c:792

こんな風にgaucheが始まるんだな。

generator->cseq

以前、 Gauche 0.9.11_pre1 のcheckをリナやFreeBSDで行った所、generator->cseqのテストでエラーになった。主治医に相談した所

cseqのエラーはちょっと謎な挙動です。"cseq (coroutine)" と出るテスト以降にcseqの
テストは無いんですよ。ということは最初のcseqのテストがもう一回実行されちゃってる
ことになるんですが、そんな器用なことがなぜ出来るのだ…? 

匙を投げられた格好。後は、民間療法に頼るしかないかな。

sakae@deb:~/src/Gauche/src$ ./gosh -ftest ../test/control.scm
Testing control ...
  :
<control.cseq>-----------------------------------------------------------------
testing bindings in #<module control.cseq> ... ok
test cseq (gen), expects (0 10) ==> ERROR: GOT (0 2)
test cseq (gen), expects (0 1 2 3 4 5 6 7 8 9) ==> ok
test cseq (gen), expects (0 1 2 3) ==> ok
test cseq (gen), expects #<<error> "oops"> ==> ok
test cseq (coroutine), expects (0 1 2 3 4 5 6 7 8 9) ==> ok
<control.future>---------------------------------------------------------------
  :

確かに、主治医が言うように、coroutine以降にはcseqの試験は無いな。ならば、分解して考える。無駄なものは排除して、単純化してく。これ科学のセオリー。問題の部分だけを抜き出して実行してみる。

sakae@deb:/tmp$ cat test.scm
  (use control.cseq)

  (let ((k 0))
    (define (gen) (if (>= k 10) (eof-object) (begin0 k (inc! k))))
    (define seq (generator->cseq gen))
    (display    (list (car seq) k)))

これ以上単純に出来無いぐらいに、テストコードから引っ張り出してみた。

sakae@deb:/tmp$ gosh test.scm
(0 2)

それで実行しても、現象が再現した。主治医の推測は外れ?かな。まあ、十分な情報を提供しないオイラーにも非があるんだけどね。今、良いFAQの書き方 なんて本読んでるけど、考えさせられる所、大だね。

そろりそろりと、聴診器ならぬ、プローブをあててみる。gaucheの有名なdebugの友を繰り出し、kの値をモニターする。begin0 #?=k

sakae@deb:/tmp$ gosh test.scm
#?=[1]k
#?-[1]    0
#?=[1]k
#?-[1]    1
(0 2)

確かに、呼出回数が少ないね。テスト結果は、現状を反映してる。そうなると、control.cseq に潜っていかないと、本当の原因にはありつけないな。lib/control/cseq.scmを引っ張り出してきて、勝手にaaa.scmと改名したよ。こうしておけば、改変(改悪)自由、勝手にどうぞだ。

改悪その1として、coroutine->cseq を削除。すこしコードを減らす。そして、プローブをenqueue/wait!の所に仕込む。勿論呼出側は、(use aaa)にしておく。

(define-module aaa
  (use gauche.generator)
  (use gauche.threads)
  (use data.queue)
  (export generator->cseq)  )
(select-module aaa)

(define (%concurrent-generator->lseq q thunk)
  (define t (thread-start! (make-thread thunk)))
  (generator->lseq (^[] (let1 r (dequeue/wait! q)
                          (when (eof-object? (car r))
                            (guard (e [(<uncaught-exception> e)
                                       (raise (~ e 'reason))]
                                      [else (raise e)])
                              (thread-join! t)))
                          (apply values r)))))

(define (generator->cseq producer :key (queue-length #))
  (define q (make-mtqueue :max-length (or queue-length 64)))
  (define (thunk)
    (guard [e (else (enqueue/wait! q (list (eof-object))) (raise e))]
      (let loop ()
        (receive (v . rest) (producer)
          (enqueue/wait! q #?=(cons v rest))   ;; probe here
          (unless (eof-object? v)
            (loop))))))
  (%concurrent-generator->lseq q thunk))
sakae@deb:/tmp$ gosh -I. test.scm
#?=[1](cons v rest)
#?-[1]    (0)
#?=[1](cons v rest)
#?-[1]    (1)
(0 2)

enqueue側でモニターしてるんだから、送出がちゃんと出来ていないって事になるんだけど、俄に想像がつかないぞ。何が考えられるんだろう?

一応、FreeBSDでも確認しとくかな。

[sakae@fb /tmp]$ gosh -I. test.scm
#?=[1](cons v rest)
#?-[1]    (0)
 :
#?=[1](cons v rest)
#?-[1]    (9)
#?=[1](cons v rest)
#?-[1]    (#<eof>)
(0 10)[sakae@fb /tmp]$

ありゃ、自然に治ってる。正規のcontrol.scmな試験でも正常。喜んでいいのか、悔しがるべきか、微妙な所。FreeBSDでは、大きな変更って無かったように記憶してる。

gauche on OpenBSD

OpenBSD 7.0が目出度くリリースされたので、気紛れでgaucheがコンパイル出来るか試してみた。

ob$ time gmake
  :
    7m57.49s real     5m41.57s user     2m41.59s system

なんと、今迄かたくなにエラーになってたのに、何とコンパイル出来ちゃった。gcがよくなったせいかしら?

ob$ gosh -V
Gauche scheme shell, version 0.9.10 [utf-8,pthreads], x86_64-unknown-openbsd7.0
(version "0.9.10")
(command "gosh")
(scheme.id gauche)
(languages scheme r5rs r7rs)
(encodings utf-8)
(website "https://practical-scheme.net/gauche")
(build.platform "x86_64-unknown-openbsd7.0")
(scheme.path "/usr/local/share/gauche-0.97/site/lib" "/usr/local/share/gauche-0.
97/0.9.10/lib")
(gauche.threads pthreads)
(gauche.net.tls axtls)

確かに、openbsd版と言ってる。信じられない!

ob$ gosh
gosh> ,i begin
WARNING: Couldn't find info document in ("/usr/local/share/info"). Maybe it has'
t been installed. Check your Gauche installation.
No info document for begin

気になるinfoは作成されていなかった。texinfoを入れると gmakeinfoが使えるらしいので、入れてあげたよ。tex一族がごっそり入ってきたぞ。doc/Makefileを修正してからinfoを作成したよ。

気になるやつ

ob$ gmake check
   :
Testing control ...                                              ^C^C^CReceived
too many signals before processing them.  Exitting for the emergency...
gmake[1]: *** [Makefile:463: test2] Error 130
gmake: *** [Makefile:54: check] Error 130

ob$ cat test.record
Total: 18859 tests, 18858 passed,     1 failed,     2 aborted.

途中でハングした。テストのサマリーを見ると、abortedが出てる。致命的に相性が悪い所が有るんだな。でも、一歩前進したね。

一応、vboxに入ってるi386なバージョンでもコンパイル。約10分かかったから、VMWAREよりは、パフォーマンスが悪いな。make checkで、途中ハングとかアボートした。

Testing uniform vector and array ...                             passed.
gmake[2]: Leaving directory '/home/sakae/src/Gauche-0.9.10/ext/uvector'
gmake[2]: Entering directory '/home/sakae/src/Gauche-0.9.10/ext/threads'
GAUCHE_TEST_RECORD_FILE="../../test.record" "../../src/gosh" -ftest -I"." -I. ".
/test.scm" > test.log
Testing threads ...                                              ^C^C^CReceived
too many signals before processing them.  Exitting for the emergency...
gmake[2]: *** [../Makefile.ext:89: check] Error 130

下記は、流れていたログから転写。

discrepancies found.  Errors are:
test inexact->exact->inexact roundtrip "1+d": expects 1.0000000000000002 => got
1.0000000000000004
test inexact->exact->inexact roundtrip "1-d": expects 0.9999999999999999 => got
0.9999999999999998
Testing SRFIs ...                                        Abort trap (core dumped)
Testing extension srfi modules ...                               failed.
discrepancies found.  Errors are:
test (fl+* ten11 ten12 one): expects 1.0000000000000001e23 => got 1.0e23

トラップが気になるな。

vbox$ gdb src/gosh src/gosh.core
(gdb) bt
#0  thrkill () at /tmp/-:3
#1  0x0f6e94e0 in _libc_raise (s=6) at /usr/src/lib/libc/gen/raise.c:37
#2  0x0f69d976 in _libc_abort () at /usr/src/lib/libc/stdlib/abort.c:51
#3  0x0f6f5784 in _libc_pthread_mutex_unlock (mutexp=0x3fe08c50)
    at /usr/src/lib/libc/thread/rthread_mutex.c:265
#4  0x0c322278 in force_cc (result=0x40416580, data=0xcf7f1638) at lazy.c:169
#5  0x0c2ac535 in run_loop () at vmcall.c:195
#6  0x0c2a663f in user_eval_inner (program=Unhandled dwarf expression opcode 0xa3) at vm.c:1577
#7  0x0c2a6f70 in Scm_ApplyRec (proc=0x3efcfec0, args=Variable "args" is not available.
) at vm.c:1696
#8  0x0c31fe01 in Scm_Load (cpath=0xcf7f1ab4 "srfi.scm", flags=20,
    packet=0xcf7f184c) at load.c:230
#9  0x159d3701 in execute_script (scriptfile=0xcf7f1ab4 "srfi.scm",
    args=0x3f0acb20) at main.c:683
#10 0x159d4118 in main (ac=4, av=0xcf7f19d4) at main.c:889

coreが有れば、検死したくなるものさ。そして、規模の小さいテスト。

vbox$ ./gosh -ftest ../test/srfi.scm
  :
<SRFI 155: Promises>-----------------------------------------------------------
test (force (delay (+ 1 2))), expects 3 ==> Abort trap (core dumped)

これらは、OpenBSDの風土病?

see configure.ac line:121 SRFI test aborts on OpenBSD-current #334

何となくOpenBSDの住人の性向が、オイラーと同じで、安心した。なんてのは、どうでもよくて、スレッド禁止でgaucheを作るのが、OpenBSD住人の勤めらしい。

ob$ ./configure --enable-threads=none
 <snip>
cc -DHAVE_CONFIG_H -I. -I. -I./../gc/include -I../gc/include `./get-atomic-ops-f
lags.sh .. .. --cflags`   -g -O2 -Wall -Wextra -Wno-unused-label -fPIC -DPIC  -c
 dispatch.c
In file included from dispatch.c:36:
./gauche/priv/atomicP.h:102:10: fatal error: 'atomic_ops.h' file not found
#include "atomic_ops.h"
         ^~~~~~~~~~~~~~
1 error generated.
gmake[1]: *** [Makefile:17: dispatch.o] Error 1
gmake[1]: Leaving directory '/tmp/Gauche-0.9.10/src'

実際にやってみると、この通りのエラーになった。

ob$ ls -l ./gc/libatomic_ops/src/atomic_ops.h
-rw-r--r--  1 sakae  wheel  20727 Dec 11  2020 ./gc/libatomic_ops/src/atomic_ops.h

でも、ちゃんと古くから存在してる。住人なら原因を探って行くんだろうけど、それは止めた。 スレッドを駆使するような事は、なさそうだからね。どうせやるなら、並行じゃなくて並列でしょ。

ob$ time gmake -j 4
     :
    3m35.34s real     8m32.29s user     2m19.81s system

忘れていた、並列なmakeをやってみた。シリアライズのmakeの時は、体感スピードが8分だったから、2倍の高速化になってるんだね。

電子負荷装置

4個のCPUに負荷をかけてみる。負荷回路としてすぐに思い付くのは、gaucheでアッカーマン関数を走らせるとか、定義通りのfibを走らせるのがお手軽。でも、中にはgauche何それって人も居るだろうから、簡単な負荷回路を自作した。

#include <stdlib.h>

int main(){
  for (;;){
    rand();
  }
}

ひたすら乱数を発生させるやつ。これを3つ動かして、その時のtopを出してみた。

load averages:  2.23,  0.71,  0.34                     ob.localhost.jp 06:05:22
24 processes: 20 idle, 4 on processor                                  up  1:04
CPU0: 95.4% user,  0.0% nice,  0.2% sys,  0.0% spin,  0.0% intr,  4.4% idle
CPU1:  4.4% user,  0.0% nice,  0.0% sys,  0.0% spin,  0.0% intr, 95.6% idle
CPU2:  100% user,  0.0% nice,  0.0% sys,  0.0% spin,  0.0% intr,  0.0% idle
CPU3: 99.8% user,  0.0% nice,  0.2% sys,  0.0% spin,  0.0% intr,  0.0% idle
Memory: Real: 244M/1345M act/tot Free: 1080M Cache: 485M Swap: 0K/502M

  PID USERNAME PRI NICE  SIZE   RES STATE     WAIT      TIME    CPU COMMAND
51333 sakae     64    0  176K  860K onproc/2  -         1:25 98.24% a.out
33522 sakae     64    0  172K  856K onproc/3  -         0:21 98.10% a.out
89095 sakae     64    0  184K  872K onproc/1  -         1:06 95.65% a.out

STATE欄のonproc/2 とかは、担当のCPU番号を意味してる。じっと見ていると、担当CPUが移り変っていくのが解る。前回調べたカーネルのスケジューラーが采配してるんだね。

リナでの表示。数字の1を押すと、CPU毎のサマリーを確認出来る。

Tasks: 166 total,   4 running, 162 sleeping,   0 stopped,   0 zombie
%Cpu0  :100.0 us,  0.0 sy,  0.0 ni,  0.0 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
%Cpu1  :  0.0 us,  0.0 sy,  0.0 ni,100.0 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
%Cpu2  :100.0 us,  0.0 sy,  0.0 ni,  0.0 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
%Cpu3  :100.0 us,  0.0 sy,  0.0 ni,  0.0 id,  0.0 wa,  0.0 hi,  0.0 si,  0.0 st
MiB Mem :   2416.5 total,   1208.3 free,    266.5 used,    941.7 buff/cache
MiB Swap:   2045.0 total,   2045.0 free,      0.0 used.   1961.7 avail Mem

    PID USER      PR  NI    VIRT    RES    SHR S  %CPU  %MEM     TIME+ COMMAND
   1318 sakae     20   0    2172    504    440 R 100.0   0.0   1:36.93 a.out
   1319 sakae     20   0    2172    556    492 R 100.0   0.0   1:34.53 a.out
   1320 sakae     20   0    2172    568    504 R 100.0   0.0   1:32.64 a.out

リナのtopでは、プロセスがどのCPUに割当てられたかは、確認出来無い。それでも困る事は無いんだけど、その隙間を埋めるのが前回やった、tasksetて訳だな。コマンドを増やすのが大好きなリナであります。

top on OpenBSD

実行してるプロセスがどのCPUに割当てられているか、どうやって表示してる? プチ疑問なので追ってみると machine.c

state_abbr(struct kinfo_proc *pp)
{
        static char buf[10];

        if (ncpu > 1 && pp->p_cpuid != KI_NOCPU)
                snprintf(buf, sizeof buf, "%s/%llu",
                    state_abbrev[(unsigned char)pp->p_stat], pp->p_cpuid);
        else
                snprintf(buf, sizeof buf, "%s",
                    state_abbrev[(unsigned char)pp->p_stat]);

これが表示部分。で、 kinfo_proc という型を追ってみると、getprocsって関数に行き着いた。得意のmibをセットしてsysctlを発している。ここから先はカーネルエリアだな。

p_cpuid を探してみると、 kern_sysctl.c の中に

#ifdef MULTIPROCESSOR
                if (p->p_cpu != NULL)
                        ki->p_cpuid = CPU_INFO_UNIT(p->p_cpu);
#endif

このファイルをざっと見したけど、実に色々な情報を取り出せる。リナの /proc みたいに、手軽にカーネル情報を開示してない訳ね。

cpuに迫るなら、arch/amd64/include/cpu.h 等を見ればよい。バスにぶら下がった一つのデバイスって扱いが面白いな。

プリセット型電子負荷装置

最後におまけで、プリセット型の電子負荷装置を作ってみる。上記に示したやつは、常にフルロードのやつだったんで、負荷率50%みたいなやつを作ってみたかったのさ。

原理は簡単、ラズパイをやってる人にはお馴染のPWMだ。適当な負荷をかける関数osってのを作る。そして、その実行時間を測っておく。

後は、その関数をn回呼ぶ。分かり易いようにn%って事にする。それを実行した後、(100 - n) * 実行時間分だけ、お休みさせれば良い。

#include <stdlib.h>
#include <time.h>

#define BT (5 * 1000 * 1000)   // unit ns, must be adj

void os() { for (int i=0; i<100000; i++){ rand(); } }   // 1% time
void spend(int n) {for (int i=0; i< n; i++){ os(); } }

int main(){
  struct timespec  req = {0,  (100 - LF) * BT};
//  for (;;){
    spend(LF);
    nanosleep(&req,  NULL);
//  }
}

最初は、キャリブレーションって事で、次のようにする。

ob$ cc -DLF=50 el.c
ob$ time ./a.out
    0m00.51s real     0m00.26s user     0m00.00s system

50%の負荷になるようにコンパイルした。そして実行。既にBTの値を調整してあるので、real = user + 待ち時間と考えると、丁度このアプリは半分の時間だけお休みしてる事になる。 こうして、BTの設定値をそのパソコン用に調整すればよい。

あるいはもっと簡単に、-D LF=100 でコンパイルして実行。userの示す値の 1/100 をセットする。こちらの方が直感的かな。

ob$ cc -DLF=100 el.c -o el100
ob$ cc -DLF=25 el.c -o el25
ob$ time ./el100
    0m00.51s real     0m00.51s user     0m00.00s system
ob$ time ./el25
    0m00.52s real     0m00.12s user     0m00.01s system

後は、main内のコメントを外して、上記のようにコンパイルすれば、プリセット型の電子負荷装置の出来上がり。なんか、トラ技の記事みたいだな。

ob$ ./el25 &
[1] 16507
ob$ ./el100 &
[2] 53835

こんな風に起動しておいて、topで観測

load averages:  1.22,  0.49,  0.19                     ob.localhost.jp 07:51:48
23 processes: 21 idle, 2 on processor                                  up  2:36
CPU0: 98.0% user,  0.0% nice,  0.0% sys,  0.0% spin,  0.0% intr,  2.0% idle
CPU1:  0.0% user,  0.0% nice,  0.0% sys,  0.0% spin,  0.0% intr,  100% idle
CPU2: 24.8% user,  0.0% nice,  0.0% sys,  0.0% spin,  0.0% intr, 75.2% idle
CPU3:  0.0% user,  0.0% nice,  0.0% sys,  0.0% spin,  0.0% intr,  100% idle
Memory: Real: 57M/1038M act/tot Free: 1386M Cache: 485M Swap: 0K/502M

  PID USERNAME PRI NICE  SIZE   RES STATE     WAIT      TIME    CPU COMMAND
53835 sakae     64    0  176K  904K onproc/0  -         2:13 97.31% el100
16507 sakae     10    0  172K  892K sleep/2   nanoslp   0:53 26.51% el25
62441 sakae     28    0 1088K 2324K onproc/1  -         0:05  0.00% top
 :

This year's Index

Home