gdb for kernel
Table of Contents
/usr/bin/fortune
FreeBSDにログインする度に、Tipsが表示される。いいかげんにウザイので、 止めようとしたんだ。 .profile
# Display a random cookie on each login. if [ -x /usr/bin/fortune ] ; then /usr/bin/fortune freebsd-tips ; fi
正体は、これである。中身は、/usr/share/games/fortune/freebsd-tips で、 145個が収録されてた。一気読みしてから停止するか。いや、(中華式な)おみくじだから、楽しめ。OpenBSDで共有できるTipsかな？なんて想像するにはい いかも。
逆アセを眺めて
前回の最後で、逆アセンブルした。なんか悪い物を見たようで、眩暈がする。 大体、糞石は、レジスターに意味ありげな名前が付けられているんで、困惑し てしまうんだな。その点、昔やってた、MC68000みたいな、ミニコンの流れを 汲むやつは、すっきりしたレジスタ名で良い。
とある本を読んだんだけど、知らない事は、知るチャンス。嫌ッていないで、 触れてみろ。世の中はステキな情報で満ちている。たとえば、 OpenBSD kernel hack memo のregisterの部に要領良くまとめられているぞ。
元ソース
#define _FSHIFT 11 /* bits to right of fixed binary point */
#define FSCALE (1<<_FSHIFT)
static const fixpt_t cexp[3] = {
0.9200444146293232 * FSCALE, /* exp(-1/12) */
0.9834714538216174 * FSCALE, /* exp(-1/60) */
0.9944598480048967 * FSCALE, /* exp(-1/180) */
};
update_loadavg(void *unused) {
static struct timeout to = TIMEOUT_INITIALIZER(update_loadavg, NULL);
CPU_INFO_ITERATOR cii;
struct cpu_info *ci;
u_int i, nrun = 0;
CPU_INFO_FOREACH(cii, ci) {
if (!cpuset_isset(&sched_idle_cpus, ci))
nrun++;
nrun += ci->ci_schedstate.spc_nrun;
}
for (i = 0; i < 3; i++) {
averunnable.ldavg[i] = (cexp[i] * averunnable.ldavg[i] +
nrun * FSCALE * (FSCALE - cexp[i])) >> FSHIFT;
}
timeout_add_sec(&to, 5);
}
逆アセ
update_loadavg: pushl %ebp ; save base reg update_loadavg+0x1: movl %esp,%ebp ; sp -> base reg update_loadavg+0x3: pushl %edi ; save edi update_loadavg+0x4: pushl %esi ; save esi update_loadavg+0x5: movl cpu_info_list,%edi update_loadavg+0xb: xorl %esi,%esi ; 0 -> esi update_loadavg+0xd: testl %edi,%edi ; edi == 0 ? update_loadavg+0xf: jz update_loadavg+0x47 ; yes update_loadavg+0x11: jmp update_loadavg+0x20 ; no update_loadavg+0x14: int $3 : update_loadavg+0x20: pushl %edi update_loadavg+0x21: pushl $0xd0fd70d0 update_loadavg+0x26: call cpuset_isset update_loadavg+0x2b: addl $0x8,%esp ; update_loadavg+0x2e: addl 0x170(%edi),%esi update_loadavg+0x34: cmpl $0x1,%eax ; 1 == eax ? update_loadavg+0x37: adcl $0,%esi update_loadavg+0x3a: movl 0x190(%edi),%edi update_loadavg+0x40: testl %edi,%edi ; edi == 0 ? update_loadavg+0x42: jnz update_loadavg+0x20 update_loadavg+0x44: shll $0xb,%esi ; 11 << esi update_loadavg+0x47: imull $0x75c,averunnable,%eax update_loadavg+0x51: imull $0xa4,%esi,%ecx update_loadavg+0x57: addl %eax,%ecx update_loadavg+0x59: shrl $0xb,%ecx ; 11 >> ecx update_loadavg+0x5c: movl %ecx,averunnable ; save 1min's update_loadavg+0x62: imull $0x7de,averunnable+0x4,%eax update_loadavg+0x6c: movl %esi,%ecx update_loadavg+0x6e: shll $0x5,%ecx ; 5 << ecx update_loadavg+0x71: leal 0(%ecx,%esi,2),%ecx update_loadavg+0x74: addl %eax,%ecx update_loadavg+0x76: shrl $0xb,%ecx ; 11 >> ecx update_loadavg+0x79: movl %ecx,averunnable+0x4 ; save 5min's update_loadavg+0x7f: imull $0x7f4,averunnable+0x8,%eax update_loadavg+0x89: leal 0(%esi,%esi,2),%ecx update_loadavg+0x8c: leal 0(%eax,%ecx,4),%eax update_loadavg+0x8f: shrl $0xb,%eax : 11 >> eax update_loadavg+0x92: movl %eax,averunnable+0x8 ; save 15min's update_loadavg+0x97: pushl $0x5 ; below next update update_loadavg+0x99: pushl $0xd0ea178c update_loadavg+0x9e: call timeout_add_sec update_loadavg+0xa3: addl $0x8,%esp update_loadavg+0xa6: popl %esi update_loadavg+0xa7: popl %edi update_loadavg+0xa8: popl %ebp update_loadavg+0xa9: ret
for文は、展開されて、ベタになってた。この方が速いと判断したんだな。そ の他、乗除算は左右へのシフトで代用したり。
それより驚いたのは、インテルの想定したレジスターの用途を遵守してるのが、 esp(SP)とebp(FP)ぐらいしか無い事。後は普通なレジスター扱いになってる事。 用途を想定して、それらしい名前をレジスターに付けているけど、それは空回 りってもんだ。
無駄な機能と言えば筆頭に挙げたいのは、セグメントとかの機構。良かれと思っ て搭載したのに、話をこんがらせている。まあ、そんなんが出現するのは、カー ネルが起動できる舞台を整えるまでだから、関係無いちゃ無いんだけどね。
watch loadavg
起動直後からのロード・アベレージを取得して、それをグラフにしてみる。 下記はその取得スクリプト。
#! /bin/sh
CNT=30
while test $CNT -gt 0
do
uptime
sleep 5
CNT=`expr $CNT - 1`
done
そして、その実行結果。
6:53AM up 2 mins, 1 user, load averages: 1.27, 0.49, 0.19 6:53AM up 2 mins, 1 user, load averages: 1.17, 0.48, 0.19 : 6:56AM up 4 mins, 1 user, load averages: 0.22, 0.34, 0.17 6:56AM up 4 mins, 1 user, load averages: 0.21, 0.34, 0.17
このデータから、1分のロードアベレージ・データのみを抽出。
ob$ cat RAW | cut -d',' -f3 | cut -d' ' -f4 >LOG
それをgnuplotでグラフ表示。
set grid plot 'LOG' w l set term pdf size 6in, 4in set output 'loadavg.pdf' replot
いつも使い方を忘れるので、その度にググる。 きれいなグラフを作ろう！ gnuplot入門 とか、 gnuplotで作成したグラフの部分だけをpdfにする
loadavg.pdf 今回のデータを掲載。X軸は測定開始からの経過秒。所々グラフ が上昇してるのは、スクリプトのsleep 5 と、カーネル側の5秒毎が干渉して いるのだろう(多分)。予想が本当かどうか検証してみる。
まず、1回のループにどれぐらいの時間がかかっているか測定。ループが2回の 場合と、1回の場合の時間を測定。その差を取れば、正味の1回の消費時間がわ かる。
qemu$ time ./wa.sh > /dev/null
0m10.82s real 0m00.10s user 0m00.64s system
qemu$ time ./wa.sh > /dev/null
0m05.47s real 0m00.00s user 0m00.42s system
10.82 - 5.47 = 5.35s となった。この時間と、(多分)正確であろう、
update_loadavg の時間間隔5sとの一致する間隔を求めれば良い。
そう、5.35と5の最小公倍数ね。小数点を含み数じゃまずいので、100倍して、
LCMを求め、後で100で割って、元の単位に戻す。LCMの計算は、calc/emacsに
お任せあれ。
500
535
lcm 53500 ;; k l (‘calc-lcm’)
100
/>535
この例だと、両者が同一タイミングになるのは、535秒後という事だ。但し、 これはあくまで数学上の事。5.35sと言うのには、当然ゆらぎが有る。5.34sだ として計算すると、1335sと大幅に、かけ離れた数値になってしまった。
make
qemu用にgdbイネーブルなカーネルを作成してみる。
ob# time COPTS="-O0" make
/usr/src/sys/crypto/curve25519.c:782:5: error: stack frame size (2964) exceeds limit (2047) in function 'curve25519' [-Werror,-Wframe-larger-than]
int curve25519(uint8_t out[CURVE25519_KEY_SIZE],
^
1 error generated.
*** Error 1 in /sys/arch/i386/compile/SEE (Makefile:951 'curve25519.o')
2m47.26s real 2m06.02s user 0m20.58s system
なんてこったい。些細な事で足を引っぱられる。
./arch/i386/conf/Makefile.i386: -Wframe-larger-than=2047
元ネタはこのファイルにあったので、倍に設定。って、もう遅いんだけどね。 下記のように、直接編集。忘れてしまう、-O0も忘れずに編集ね。
ob# cd obj
ob# vi Makefile
ob# time make
:
text data bss dec hex
12806195 213448 1130496 14150139 d7e9fb
mv bsd bsd.gdb
ctfstrip -S -o bsd bsd.gdb
6m53.29s real 5m16.25s user 1m02.29s system
ob# ls -l bsd*
-rwxrwx--- 1 root wobj 14627100 Feb 16 08:15 bsd
-rw-r--r-- 1 root wobj 4636 Feb 16 08:10 bsd-comp.d
-rw-r--r-- 1 root wobj 25388 Feb 16 08:10 bsd-comp.o
-rwxrwx--- 1 root wobj 36827296 Feb 16 08:15 bsd.gdb
drmとnfsは使わないので削除したんだけど、その効果は微々たるものだな。 もっと大胆にUSB一式削除とか、RAIDはいらないよとかすればダイエットにな るだろうけど、まあ、程々に。
use new kernel
wobjなグループに所属していないと現場の、 usr/obj/sys/arch/i386/compile/SEE に、到達できない。 現場には、
ob$ cat .gdbinit target remote :1234
を用意。これを有効にする為、~/.gdbinitにも設定が必要。
ob$ cat /home/sakae/.gdbinit add-auto-load-safe-path /usr/obj/sys/arch/i386/compile/SEE/.gdbinit
ああ、qemuからOpenBSDを起動するスクリプトには、 -s を追加して、gdbと通 信できる用に設定しとく。母艦側で、qemuを動作させ、これにPuTTY側のgdbが 通信しながら、観察と言うか観光って言う使い方ができる。
high load
ob$ cat heavy
#!/bin/sh
CNT=90
while test $CNT -gt 0
do
seq 100 | grep 7 > /dev/null
ls -al > /dev/null
# CNT=`expr $CNT - 1`
done
先程作ったスクリプトを暴走族にして、負荷をかけてみる。
qemu$ uptime 6:37AM up 14 mins, 1 user, load averages: 2.33, 1.06, 0.48 qemu$ ps u USER PID %CPU %MEM VSZ RSS TT STAT STARTED TIME COMMAND sakae 23073 9.6 0.8 1076 828 00 Sp 6:35AM 0:15.39 /bin/sh ./he :
watch
ob$ gdb -q bsd.gdb
Reading symbols from bsd.gdb...
pmap_map_ptes_86 (pmap=0xd14ee000) at /usr/src/sys/arch/i386/i386/pmap.c:525
525 if (pmap_is_curpmap(pmap)) {
(gdb) p averunnable
$1 = {ldavg = {5028, 3111, 1509}, fscale = 2048}
(gdb) p cexp
$3 = {1884, 2014, 2036}
(gdb) b update_loadavg
Breakpoint 1 at 0xd048a22a: file /usr/src/sys/kern/sched_bsd.c, line 125.
(gdb) c
Continuing.
Breakpoint 1, update_loadavg (unused=0x0) at /usr/src/sys/kern/sched_bsd.c:125
125 u_int i, nrun = 0;
(gdb) bt
#0 update_loadavg (unused=0x0) at /usr/src/sys/kern/sched_bsd.c:125
#1 0xd0893248 in timeout_run (to=0xd0e3fee8 <update_loadavg.to>)
at /usr/src/sys/kern/kern_timeout.c:638
#2 0xd089386f in softclock_process_tick_timeout (
to=0xd0e3fee8 <update_loadavg.to>, new=0)
at /usr/src/sys/kern/kern_timeout.c:687
#3 0xd089198b in softclock (arg=0x0) at /usr/src/sys/kern/kern_timeout.c:718
#4 0xd076f9fa in softintr_dispatch (which=0)
at /usr/src/sys/arch/i386/i386/softintr.c:98
#5 0xd071c6ee in Xsoftclock ()
#6 0xd0f7b3a0 in uvm ()
127 CPU_INFO_FOREACH(cii, ci) {
(gdb)
133 for (i = 0; i < 3; i++) {
(gdb) p nrun
$2 = 2
(gdb) info registers
eax 0x0 0
ecx 0x1 1
edx 0x1 1
ebx 0x0 0
esp 0xf1b34cb0 0xf1b34cb0
ebp 0xf1b34ccc 0xf1b34ccc
esi 0xd071c5fe -797850114
edi 0x5 5
eip 0xd048a28f 0xd048a28f <update_loadavg+111>
eflags 0x246 [ IOPL=0 IF ZF PF ]
:
(gdb) disassemble
:
0xd048a281 <+97>: mov 0x190(%eax),%eax
0xd048a287 <+103>: mov %eax,-0xc(%ebp)
0xd048a28a <+106>: jmp 0xd048a240 <update_loadavg+32>
=> 0xd048a28f <+111>: movl $0x0,-0x10(%ebp)
0xd048a296 <+118>: cmpl $0x3,-0x10(%ebp)
0xd048a29a <+122>: jae 0xd048a2ee <update_loadavg+206>
0xd048a2a0 <+128>: mov -0x10(%ebp),%eax
0xd048a2a3 <+131>: mov -0x2f2a730c(,%eax,4),%ecx
0xd048a2aa <+138>: mov -0x10(%ebp),%eax
0xd048a2ad <+141>: imul -0x2f13a368(,%eax,4),%ecx
0xd048a2b5 <+149>: mov -0x14(%ebp),%eax
0xd048a2b8 <+152>: shl $0xb,%eax
0xd048a2bb <+155>: mov -0x10(%ebp),%esi
0xd048a2be <+158>: mov $0x800,%edx
0xd048a2c3 <+163>: sub -0x2f2a730c(,%esi,4),%edx
0xd048a2ca <+170>: xchg %edx,%eax
0xd048a2cc <+172>: imul %eax,%edx
0xd048a2cf <+175>: xchg %edx,%eax
0xd048a2d1 <+177>: add %eax,%ecx
0xd048a2d3 <+179>: shr $0xb,%ecx
0xd048a2d6 <+182>: mov -0x10(%ebp),%eax
0xd048a2d9 <+185>: mov %ecx,-0x2f13a368(,%eax,4)
0xd048a2e0 <+192>: mov -0x10(%ebp),%eax
0xd048a2e3 <+195>: add $0x1,%eax
0xd048a2e6 <+198>: mov %eax,-0x10(%ebp)
0xd048a2e9 <+201>: jmp 0xd048a296 <update_loadavg+118>
0xd048a2ee <+206>: mov %esp,%eax
0xd048a2f0 <+208>: movl $0x5,0x4(%eax)
0xd048a2f7 <+215>: movl $0xd0e3fee8,(%eax)
0xd048a2fd <+221>: call 0xd0891e10 <timeout_add_sec>
:
コンパイルした時、-O0 を指定しているので効率化は実施されていない。ゆえ に、長いコードになっている(逆に、分かりづらい面も有る)。
再びloadavgの検証
先の暴走族を100ループ(約1分)回して負荷をかけ、29,30,31秒間隔で、21ポイ ント分の locaavgを計測してみた。
gnuplot> set grid gnuplot> plot 's29' w l gnuplot> replot 's30' w l gnuplot> replot 's31' w l gnuplot> set term pdf size 6in, 4in gnuplot> set output 'loadavg3.pdf' gnuplot> replot
一枚のグラフに重ね描きするには、replotなんだね。