acct
図書館へ行ったら、ニュートン誌のちょっと古いのが置いてあった。人気があって結構貸し出し中になってる事が多いんだけどな。
宇宙論で有名になったホーキング博士の追悼特集だった。博士は今年３月に逝去されてる。車椅子の博士ってのが強烈に頭に残ってるぞ。
学生時代頃までは、大丈夫だったとかで、ご結婚もされ、３人のお子さんにも恵まれたそうだ。そういう事は知らなかったなあ。
そして、もう一冊、追悼の本を借りてきた。先月５３歳という若さで世を去った、さくらももこ さんの本。追悼コーナーがあって、そこにある何冊かから、一冊選んだもの。
たいのおかしらと言う、エッセー本。
ある時、夫が結婚指輪を見せろと言ったとか。ひょっとして、誕生日に指輪でも買ってあげようって魂胆で、サイズを調べたいに違いないと早合点。期待にそわそわ。
所が、夫はその指輪を使ってマジックを始めちゃったものだから、ガックリした、なんてのが 筆致鮮やかに載ってた。
その他のエッセーで、父ヒロシってのが出て来る。ひょっとして、ちびまる子ちゃんの登場人物にいなかったけと調べてみると、へー、そうだったんだとなりました。
遅ればせながら、ご両者のご冥福をお祈りいたします。
acct
以前からのお約束、ユーザーがどれぐらいコンピュータを使ったかっていうデータを収集するソフトを、ThinkPad/SL510に入れているDebianで試してみた。apt install acctするだけで、動き出したよ。
んでもって、どんなコマンドが実行されてるか調べてみたんだ。
debian:~$ sudo lastcomm | head iwconfig S root __ 0.00 secs Thu Sep 6 06:50 ifconfig root __ 0.00 secs Thu Sep 6 06:50 ifconfig root __ 0.00 secs Thu Sep 6 06:50 iwconfig S root __ 0.00 secs Thu Sep 6 06:50 ifconfig root __ 0.00 secs Thu Sep 6 06:50 ifconfig root __ 0.00 secs Thu Sep 6 06:50 iwconfig S root __ 0.00 secs Thu Sep 6 06:50 ifconfig root __ 0.00 secs Thu Sep 6 06:50 ifconfig root __ 0.00 secs Thu Sep 6 06:50 iwconfig S root __ 0.00 secs Thu Sep 6 06:50
そしたら、頻繁に、ifconfigやらiwconfigが実行されてる。実行ユーザーがrootってなってるけど、いくらなんでも、rootさんが気を利かせて、死活状況をモニターしてるとは考えずらい。 だれかが、rootさんをこき使ってるはず。一体何処の誰や？ この場合の誰ってのは、プログラムの事ね。
真っ先に思付くのは、時の神さんのcron。/etcの下にcronで動くべきスクリプトが用意されてる。それを眺めまわしてみたけど、そんな素振りは無し。
次に思いつくのはOS起動時から某ダエモン君が居座って、サービスを始めるというストーリー。 これが臭そうだけど、リナは不慣れなんで、そんなダエモン君の名前を思い付かない。
はて、どうしてくれよう？ こういう場合、一時的にiwconfigが動かないようにし（実行属性を落とす）、/var/log/messagesあたりにエラーが出てこないか確認かな。
ログが、messages,kern.log,syslogの３種に出て来た。例えば、kern.logには
Sep 6 07:07:48 debian kernel: [ 5965.186638] iwlwifi 0000:05:00.0: L1 Enabled - LTR Disabled Sep 6 07:07:48 debian kernel: [ 5965.186728] iwlwifi 0000:05:00.0: Radio type=0x1-0x2-0x0
こんなのが上がってたけど、今回の目的には役立たずである。
はて、どうしてくれよう？ 取り合えずこういう時は、散歩してくる。そしたら閃いたぞ。 iwconfigのラッパーを書いてしまえ。
debian:sbin$ cat iwconfig #!/bin/sh pstree -aA >/tmp/LOG iwconfig.org $@
オリジナルのiwconfigを別名にしておく。ラッパースクリプトで受けて、pstreeを取り、ログに落とす。実行結果は
debian:tmp$ cat LOG
systemd
|-ModemManager
| |-{gdbus}
| `-{gmain}
|-NetworkManager --no-daemon
:
|-wicd -O /usr/share/wicd/daemon/wicd-daemon.py --keep-connection
| |-iwconfig /sbin/iwconfig wlp5s0
| | `-pstree -aA
| `-wicd-monitor -O /usr/share/wicd/daemon/monitor.py
|-wicd-client -O /usr/share/wicd/gtk/wicd-client.py --tray
| |-{gdbus}
| `-{gmain}
wicdっていうダエモン君が勝手に動いているな。LXDEというDeskTop環境によって導入されたものかな？ 考えていても、どうにもならないので、取り合えずのmanだな。リナには珍しい事に、ちゃんとmanが用意されてた。
NAME
Wicd - Wired and Wireless Network Connection Manager
STRUCTURE
Wicd has two major parts: the daemon, which runs with root privileges;
and the user interface, which runs with normal user privileges. The
two parts run as separate processes and make use of D-Bus to communi‐
cate.
切れても、自動的に再接続する、しつこいやつだ。そのために、頻繁にNICを叩いているんだな。パイソンのコードを見たら、有線用と無線用のダエモン君を作って、DBUSと協調しながら動いているみたいだった。これ以上の深入りは止めよう。
それよりこのダエモン君が、systemd直下に居る事が、基幹モジュールだよって事が分かって、よかったね、という事にしておくよ。GUIは何かと仕掛けが大がかりで嫌いさ。
ついでに、acctの構成を見ておくか。パッキングリストを確認だな。
debian:share$ dpkg -L acct /etc /etc/cron.daily /etc/cron.daily/acct /etc/cron.monthly /etc/cron.monthly/acct /etc/default /etc/default/acct /etc/init.d /etc/init.d/acct /usr /usr/bin /usr/bin/ac /usr/bin/lastcomm /usr/sbin /usr/sbin/accton /usr/sbin/dump-acct /usr/sbin/dump-utmp /usr/sbin/sa :
acctの上げ下げ設定は、/etc/default/acctあたりでやってると思われる。リナは設定ファイルが、勝手にあちこちに分散してて（作者の思い付きに付き合わされる）嫌いだ。その点BSD系だと、/etc/rc.conf か、/usr/local/etc/ の下に集中してるんで、楽でいいよ。
pico sh ?
前回、シグナルを使って、動いているプロセスにSIGQUIT等を送ると、終了コードとして128のげたを履いたシグナル番号が返ってきた。
ob6$ sleep 10 ^\Quit (core dumped) ;; ------ Ctl+\ ob6$ echo $? 131
coreなんで、検視が出来る。
ob6$ gdb -q /bin/sleep sleep.core Reading symbols from /bin/sleep...(no debugging symbols found)...done. [New process 181513] Core was generated by `sleep'. Program terminated with signal SIGQUIT, Quit.
ここまでは、復習だ。
んで、128が何処で足されている？ sys_exitやsys_waitを精査しても、128を足している場所は見つからなかった。
話を膨らませて、ユーザーランド側での処置だろう。 多分shellの仕業と思われるんで、shellをのけ者にして実験してみる。これが正しい科学者の態度です。どうするかと言うと、自前で超ミニ（よりはピコだ）なshellを組んじゃう事だ。
なに、構える事はないよ。
nb8$ cat stck.c
#include <stdio.h>
int main(){
int rv;
printf("PID= %d\n", getpid());
if (fork() == 0){
printf("pid= %d\n", getpid());
sleep(5);
kill(getpid(), 15);
}
puts("Waiting child die!");
wait(&rv);
printf("rv= %d\n", rv);
exit(rv);
}
あっけに取られるぐらい、いい加減なやつである。何せ実験用のバラックですから。電子工作で言ったら、ベタなプリント板にハーメチック端子を立てて、空中配線したようないい加減なやつ。 勿論、保護回路と言うかエラーチェックなんてのは、省いています。（そんな事、自慢になるか） C言語診断室のあの人が、怒りだすのは承知です。実際にコンパイルしても、数々の注意を 受けますから。
nb8$ cc stck.c
stck.c: In function 'main':
stck.c:6:23: warning: implicit declaration of function 'getpid' [-Wimplicit-function-declaration]
printf("PID= %d\n", getpid());
^
:
stck.c:15:3: note: include '<stdlib.h>' or provide a declaration of 'exit'
暗黙の了承ってやつ（阿吽の呼吸）が働いて何とか親プログラム（子を内包ですが）が出来上がりましたよ。そんな事より、実験の意図の説明をば。
いきなり団子じゃなくて、いきなりforkです。if文の中は、子供プロセスです。子供は控えめに、pid=と、小文字でプロセス番号を表示。それから５秒生きて、自死します。
親の方は、薄情で、子供が死ぬのを待ってるぞと宣言。そしてwaitで子供を看取ります。その時に、子供の死因を神(kernel)に尋ねています。尋ねるには結果を受け取る用紙（死亡診断書だな）の場所を&rvとして差し出す約束になってます。神からの通知はrvによって知らされるので、それを公表。親自身も、子の死因を胸に秘めて、終了します。
終了結果は、親を生んだshellに伝えられます。で、実行してみる。
nb8$ ./a.out PID= 3355 Waiting child die! pid= 2825 rv= 15 ;; --------------------- 親は５秒後に終了
ちゃんと、SIGTERMの番号が返ってきた。
nb8$ echo $? 15
子の終了コードが、本物のshellに何の加工もなく伝わった。
じゃ、自分で終了コードを加工したらどうなるかやってみる。上記サンプルの最後で、exitに引き渡すrvに1000を加えてみるか。128よりは、分かり易いと思うから。
debian:tmp$ ./a.out PID= 4065 Waiting child die! pid= 4066 rv= 15 debian:tmp$ echo $? 247
1015になるはずが、247に化けている？ どこからそんな数値が出て来るの、、、って考えていたら、結果は8Bit分って、どかに書いてあったな。と言う事は、
debian:tmp$ gdb -q (gdb) p 1015 % 256 $1 = 247 (gdb) p 1015 & 0xff $2 = 247
解釈は、ご自由になさってください。
それから、mainの最後にexitを置いてるけど、これをreturnに変更しても良い。 何故なら、mainは、次のようにして起動されるから。
_start(exit(main(...)))
ああ、これlisp風な概念図ね。mainに渡されるargvとかは、_startが用意してくれている。そして、mainの返り値が、exitへの引数になってるんだ。詳しい事はハロワ本に載ってるぞ。 この本は、マニアックな事も書かれているけど、とっても良書です。
shell exit status
さて、いまNetBSDで使ってるshellは、kshです。signalを受けてプロセスが終了した時、どんな終了コードが返さるか、ksh(1)から、statusで検索してみます。
? The exit status of the last non-asynchronous command executed.
If the last command was killed by a signal, $? is set to 128
plus the signal number.
しっかり、128を足すからねって書いてありました。そんじゃcshは？
status The status returned by the last command. If it terminated
abnormally, then 0200 is added to the status. Builtin
commands that fail return exit status `1', all other builtin
commands set status to `0'.
時代がかったshellは、説明もちょっぴり時代がかってますなあ。0200って表記は、８進数ですよ。10進数に翻訳すれば、128になります。このcshは、ビル・ジョイさんあたりがC語に似せて 作ったはず。
更に古い(a)shも同梱されてる。sh(1)によれば、
HISTORY
A sh command appeared in Version 1 AT&T UNIX. It was replaced in
Version 7 AT&T UNIX with a version that introduced the basis of the
current syntax. That was, however, unmaintainable so we wrote this one.
らしい。そんじゃ、ちょいとshのコードを探ってみる。grepするだけーーーーー。
nb8$ pwd /usr/src/bin/sh nb8$ grep 128 * eval.c: exitstatus = e == EXINT ? SIGINT + 128 : expand.c: char buf[128]; jobs.c: return 128 + lastsig(); jobs.c: return 128 + lastsig(); jobs.c: retval = WSTOPSIG(status) + 128; jobs.c: retval = WTERMSIG(status) + 128; jobs.c: st = WSTOPSIG(status) + 128; jobs.c: st = WTERMSIG(status) + 128; sh.1:its exit status will be greater than 128.
これだけでも、signalの時は、128を足しこんでいる事が明白になりましたな。
最後はみんな大好きbashの番です。
For the shell's purposes, a command which exits with a zero exit status
has succeeded. An exit status of zero indicates success. A non-zero
exit status indicates failure. When a command terminates on a fatal
signal N, bash uses the value of 128+N as the exit status.
どうやらshell業界では、談合と言うか昔からの習慣がずっと継承されてるようです。
gdb tips
gdbで生まれた子供を追いかけられるのか？ 上で出て来たコードで実験
(gdb) r Starting program: /tmp/a.out Breakpoint 1, main () at stck.c:3 (gdb) n (gdb) PID= 10970 (gdb) pid= 10971 (gdb) Waiting child die! (gdb) (gdb) rv= 15 (gdb) [Inferior 1 (process 10970) exited with code 017]
普通にやると、ifの所はすっ飛ばされて（子供は無視）、親側だけを追跡。
(gdb) set follow-fork-mode child (gdb) r Starting program: /tmp/a.out (gdb) n (gdb) PID= 10987 (gdb) Waiting child die! [New process 10988] [Switching to process 10988] main () at stck.c:8 (gdb) pid= 10988 (gdb) (gdb) n Thread 3.1 "a.out" received signal SIGTERM, Terminated. 0x00007ffff7a23187 in kill () at ../sysdeps/unix/syscall-template.S:78 78 ../sysdeps/unix/syscall-template.S: No such file or directory.
子供を追いかけるぞ宣言しておくと、子供側に行ってくれた。そしてSIGTERMが受信されましたとさ。
下記はリナ限定っぽいけど、プロセスのマッピング情報をgdbから確認出来る。これもそれも、/procが有るからかな？
(gdb) info proc mappings
process 10999
Mapped address spaces:
Start Addr End Addr Size Offset objfile
0x555555554000 0x555555555000 0x1000 0x0 /tmp/a.out
0x555555754000 0x555555755000 0x1000 0x0 /tmp/a.out
0x555555755000 0x555555756000 0x1000 0x1000 /tmp/a.out
0x7ffff79e4000 0x7ffff7bcb000 0x1e7000 0x0 /lib/x86_64-linux-gnu/libc-2.27.so
0x7ffff7bcb000 0x7ffff7dcb000 0x200000 0x1e7000 /lib/x86_64-linux-gnu/libc-2.27.so
0x7ffff7dcb000 0x7ffff7dcf000 0x4000 0x1e7000 /lib/x86_64-linux-gnu/libc-2.27.so
0x7ffff7dcf000 0x7ffff7dd1000 0x2000 0x1eb000 /lib/x86_64-linux-gnu/libc-2.27.so
0x7ffff7dd1000 0x7ffff7dd5000 0x4000 0x0
0x7ffff7dd5000 0x7ffff7dfc000 0x27000 0x0 /lib/x86_64-linux-gnu/ld-2.27.so
0x7ffff7fe6000 0x7ffff7fe8000 0x2000 0x0
0x7ffff7ff7000 0x7ffff7ffa000 0x3000 0x0 [vvar]
0x7ffff7ffa000 0x7ffff7ffc000 0x2000 0x0 [vdso]
0x7ffff7ffc000 0x7ffff7ffd000 0x1000 0x27000 /lib/x86_64-linux-gnu/ld-2.27.so
0x7ffff7ffd000 0x7ffff7ffe000 0x1000 0x28000 /lib/x86_64-linux-gnu/ld-2.27.so
0x7ffff7ffe000 0x7ffff7fff000 0x1000 0x0
0x7ffffffde000 0x7ffffffff000 0x21000 0x0 [stack]
0xffffffffff600000 0xffffffffff601000 0x1000 0x0 [vsyscall]
思い立ったが吉日じゃなくて、忘れないうちに確認々。
sakae@usvr:~$ sleep 3000 & [2] 2319 sakae@usvr:~$ cd /proc/2319 sakae@usvr:/proc/2319$ ls attr/ exe@ mounts projid_map status autogroup fd/ mountstats root@ syscall auxv fdinfo/ net/ sched task/ cgroup gid_map ns/ schedstat timers clear_refs io numa_maps sessionid timerslack_ns cmdline limits oom_adj setgroups uid_map comm loginuid oom_score smaps wchan coredump_filter map_files/ oom_score_adj smaps_rollup cpuset maps pagemap stack cwd@ mem patch_state stat environ mountinfo personality statm sakae@usvr:/proc/2319$ cat maps 555e0021d000-555e00224000 r-xp 00000000 08:02 1048706 /bin/sleep 555e00424000-555e00425000 r--p 00007000 08:02 1048706 /bin/sleep 555e00425000-555e00426000 rw-p 00008000 08:02 1048706 /bin/sleep 555e0050a000-555e0052b000 rw-p 00000000 00:00 0 [heap] 7fe8f235f000-7fe8f2546000 r-xp 00000000 08:02 1316070 /lib/x86_64-linux-gnu/libc-2.27.so 7fe8f2546000-7fe8f2746000 ---p 001e7000 08:02 1316070 /lib/x86_64-linux-gnu/libc-2.27.so 7fe8f2746000-7fe8f274a000 r--p 001e7000 08:02 1316070 /lib/x86_64-linux-gnu/libc-2.27.so 7fe8f274a000-7fe8f274c000 rw-p 001eb000 08:02 1316070 /lib/x86_64-linux-gnu/libc-2.27.so 7fe8f274c000-7fe8f2750000 rw-p 00000000 00:00 0 7fe8f2750000-7fe8f2777000 r-xp 00000000 08:02 1316058 /lib/x86_64-linux-gnu/ld-2.27.so 7fe8f27cb000-7fe8f2966000 r--p 00000000 08:02 534530 /usr/lib/locale/locale-archive 7fe8f2966000-7fe8f2968000 rw-p 00000000 00:00 0 7fe8f2977000-7fe8f2978000 r--p 00027000 08:02 1316058 /lib/x86_64-linux-gnu/ld-2.27.so 7fe8f2978000-7fe8f2979000 rw-p 00028000 08:02 1316058 /lib/x86_64-linux-gnu/ld-2.27.so 7fe8f2979000-7fe8f297a000 rw-p 00000000 00:00 0 7ffd5ae9b000-7ffd5aebc000 rw-p 00000000 00:00 0 [stack] 7ffd5af98000-7ffd5af9b000 r--p 00000000 00:00 0 [vvar] 7ffd5af9b000-7ffd5af9d000 r-xp 00000000 00:00 0 [vdso] ffffffffff600000-ffffffffff601000 r-xp 00000000 00:00 0 [vsyscall]
当たらずとも遠からずと言った所かな。それにしても、色々なプロセス状況が見られるようになってるのね。知らんかったわい。
debian:2142$ cat stack [<dc0ca27d>] hrtimer_start_range_ns+0x18d/0x460 [<dc07116c>] flush_work+0x3c/0x190 [<dc0c9a50>] __hrtimer_init+0xb0/0xb0 [<dc1dd7ce>] poll_schedule_timeout+0x3e/0x70 [<dc1de2cb>] do_select+0x6bb/0x7c0 [<dc1dd940>] poll_select_copy_remaining+0x140/0x140 [<dc1dd940>] poll_select_copy_remaining+0x140/0x140 [<dc29febd>] crypto_shash_update+0x3d/0xf0 [<dc08922f>] update_curr+0x13f/0x200 [<dc08922f>] update_curr+0x13f/0x200 [<dc089c87>] task_tick_fair+0x467/0xcb0 [<dc08ec2a>] enqueue_entity+0x2fa/0x1350 [<dc099bd7>] __wake_up+0x37/0x50 : [<dc1de7ba>] SyS_select+0x9a/0xf0 [<dc001a88>] do_fast_syscall_32+0x98/0x160 [<dc597e3a>] sysenter_past_esp+0x47/0x75 [<ffffffff>] 0xffffffff
これ、w3mって言うCUIタイプのブラウザーが動いている時の、スタック状態らしい。スタックの底に、マークっぽいものが見えるな。
この他、面白そうなものが公開されてるので、暇にあかせて覗いてみると吉、かな？
debian:2142$ cat sched w3m (2142, #threads: 1) ------------------------------------------------------------------- se.exec_start : 2236716.077425 se.vruntime : 30045.616080 se.sum_exec_runtime : 149.723384 se.nr_migrations : 0 nr_switches : 1873 nr_voluntary_switches : 1609 nr_involuntary_switches : 264 se.load.weight : 1024 se.avg.load_sum : 31744 se.avg.util_sum : 28672 se.avg.load_avg : 0 se.avg.util_avg : 0 se.avg.last_update_time : 2236716077425 policy : 0 prio : 120 clock-delta : 215
見る人が見れば吉だろう。