BSD小僧の日記

つまらんミスで動いてなかった。

if(hoge)
    return 0;

というのをprintf debugした際に

if(hoge)
    printf(piyo);
    return 0;

としていた。中かっこが足らないのだ。初心者かよ！

いざ、実行。

sys_execve
sys_execve: eror = -2
cnopen: minor
cnopen: cn_tab == NULL?
cnopen: cndev=000fff00
cnopen: cndev == NODEV?
cnopen: dev == cndev?
cnopen: cn_devvp == NULLVP? unit=0
cnopen: cdevvp()
cnopen: cdevvp() error=0
cnopen: vn_lock()
cnopen: vn_lock error=0
cnopen: VOP_OPEN cndevvp[0]=c1bf2a50
cnopen: VOP_UNLOCK error=6

openが6を返している。エラーコードが6というとENXIOとのこと。

#define    ENXIO        6        /* Device not configured */

じゃぁ、cndevvp[0]=c1bf2a50のc1bf2a50ってなんだよ、とnetbsd.mapを見てみると

.text          0x00000000c0184c64      0x4e0 wmt_com.o
                0x00000000c0184c64                wmtcomcnpollc
                0x00000000c0184c6c                wmtcomstop
                0x00000000c0184c78                wmtcomioctl
                0x00000000c0184c98                wmtcompoll
                0x00000000c0184cb8                wmtcomwrite
                0x00000000c0184cd8                wmtcomread
                0x00000000c0184cf8                wmtcomclose
                0x00000000c0184d18                wmtcomopen

ということでハズしている。後で確認したが、objdump -dでみたら、netbsd.mapとも違う数字になっていた。なんだこりゃ。


VOP_OPENをもう少し表示させてみる。

sys_execve: eror = -2
VOP_OPEN: vp=c1bf2c60, VOFFSET(vop_open)=00000005
cnopen: minor
cnopen: cn_tab == NULL?
cnopen: cndev=000fff00
cnopen: cndev == NODEV?
cnopen: dev == cndev?
cnopen: cn_devvp == NULLVP? unit=0
cnopen: cdevvp()
cnopen: cdevvp() error=0
cnopen: vn_lock()
cnopen: vn_lock error=0
cnopen: VOP_OPEN cndevvp[0]=c1bf2a50
VOP_OPEN: vp=c1bf2a50, VOFFSET(vop_open)=00000005
cnopen: VOP_UNLOCK error=6

わかんないな。ん？　なんだ、c1bf2c60というのがcnopenの前に出てるぞ？
VOP_OPENがcnopen経由以外で呼ばれているってことか。それっぽいのは以下あたり？

• vfs_mount.cのvfs_mountroot(void)
• tty_tty.cのcttyopen(dev_t dev, int flag, int mode, struct lwp *l)

ちがうかな？init.cのopenlogかもしれん。

と思ったが、ramdisk.fsだとインストーラように小さくするため、きっと#ifndef LETS_GET_SMALLのはずだから違うか。

とりあえず、本当は誰が呼んでるかわからんからpanicさせてみるかなぁ。

rn_init: radix functions require max_keylen be set
start_init
module_init_class
boot device: <unknown>
root on md0a dumps on md0b
VOP_OPEN: vp=c1bf2f20, VOFFSET(vop_open)=00000005
VOP_OPEN: error=0
panic: VOP_OPEN
Stopped in pid 0.1 (system) at  netbsd:cpu_Debugger+0x4:        bx      r14
0xc06b1f24: netbsd:vpanic+0xc
0xc06b1f3c: netbsd:printf_nolog
0xc06b1f70: netbsd:VOP_OPEN+0x70
0xc06b1f9c: netbsd:vfs_mountroot+0x280
0xc06b1fec: netbsd:main+0x350
0xc06b1ffc: netbsd:kernel_text+0x50
db>

ふむ。やはりvfs_mountroot。

じゃぁ、cnopenは？

root on md0a dumps on md0b
VOP_OPEN: vp=c1bf2f20, VOFFSET(vop_open)=00000005
VOP_OPEN: error=0
mountroot: trying nfs...
mountroot: trying msdos...
mountroot: trying ffs...
root file system type: ffs
configure3
inittodr
WARNING: no TOD clock present
WARNING: using filesystem time
WARNING: CHECK AND RESET THE DATE!
uvm_swap_init
VOP_OPEN: vp=c1bf2dc0, VOFFSET(vop_open)=00000005
VOP_OPEN: error=0
uvm_scheduler
init: copying out flags `-s' 3
init: copying out path `/sbin/init' 11
move out arg pinters
sys_execve
VOP_OPEN: vp=c1bf2b00, VOFFSET(vop_open)=00000005
VOP_OPEN: error=0
sys_execve: eror = -2
VOP_OPEN: vp=c1bf2c60, VOFFSET(vop_open)=00000005
cnopen: minor
cnopen: cn_tab == NULL?
cnopen: cndev=000fff00
cnopen: cndev == NODEV?
cnopen: dev == cndev?
cnopen: cn_devvp == NULLVP? unit=0
cnopen: cdevvp()
cnopen: cdevvp() error=0
cnopen: vn_lock()
cnopen: vn_lock error=0
cnopen: VOP_OPEN cndevvp[0]=c1bf2a50
VOP_OPEN: vp=c1bf2a50, VOFFSET(vop_open)=00000005
VOP_OPEN: error=6
cnopen: VOP_UNLOCK error=6
panic: cnopen
Stopped in pid 1.1 (init) at    netbsd:cpu_Debugger+0x4:        bx      r14
0xca86cc80: netbsd:vpanic+0xc
0xca86cc98: netbsd:printf_nolog
0xca86ccd4: netbsd:cnopen+0x16c
0xca86ccfc: netbsd:cdev_open+0x68
0xca86cd4c: netbsd:spec_open+0x198
0xca86cd70: netbsd:VOP_OPEN+0x98
0xca86ce24: netbsd:vn_open+0x1dc
0xca86ce9c: netbsd:do_open+0xb0
0xca86cecc: netbsd:do_sys_openat+0x7c
0xca86cef0: netbsd:sys_open+0x34
0xca86cf84: netbsd:syscall+0x88
0xca86cfac: netbsd:swi_handler+0x98
db>

うん。swi_handlerでした。

読めば読むほどinit.cのprint_consoleどうにもできる気がしない。

ということで、このpanicさせるopenシステムコールを少しずつ動かして、どこまで進んでいるかを見れば、どこで止まっているかはわかる。

どうやら、sbin/init/init.c#771の場所。single_user()の中で使われているwaitpid()が帰ってきていないようだ。

    771 	requested_transition = 0;
    772 	do {
    773 		if ((wpid = waitpid(-1, &status, WUNTRACED)) != -1)
    774 			collect_child(wpid, status);

というか、そのまえのfork()が失敗しているということである。
kernelのfork1は成功して/sbin/initが実行されているのだけれど、forkはうまく動いていないようだ。
とにかく、いろいろおかしいことがわかってきた。こういう時、どうデバックしたらいいのか。
まずは、forkが失敗しようがしまいが、進めてしまうとどうなるのだろうか。

sys_execve
VOP_OPEN: vp=c1bf2b00, VOFFSET(vop_open)=00000005
VOP_OPEN: error=0
sys_execve: error = -2
proc: table is full - increase kern.maxproc or NPROC

しばらくして上のproc: table is full - ... が出た。なんか、ループして食いつぶしたような感じである。

とにかくだ、シリアル動かないとにっちもさっちも。やっぱりprint_console動かす方向に戻す。

VOP_OPENを追っかけると、vpではなくvp->v_opが大事そうである。
つまり、vp->v_op[offset]が関数ポインタとして実行されるのである。
ということで、vp->v_opを表示させるようにしてみる。

VOP_OPEN: vp=c1bf2a50, vp->v_op=c1a35d28, VOFFSET(vop_open)=00000005
VOP_OPEN: error=6
cnopen: VOP_UNLOCK error=6
panic: cnopen
Stopped in pid 1.1 (init) at    netbsd:cpu_Debugger+0x4:        bx      r14
0xca86cc80: netbsd:vpanic+0xc
0xca86cc98: netbsd:printf_nolog
0xca86ccd4: netbsd:cnopen+0x16c
0xca86ccfc: netbsd:cdev_open+0x68
0xca86cd4c: netbsd:spec_open+0x198
0xca86cd70: netbsd:VOP_OPEN+0xa0
0xca86ce24: netbsd:vn_open+0x1e8
0xca86ce9c: netbsd:do_open+0xb0
0xca86cecc: netbsd:do_sys_openat+0x7c
0xca86cef0: netbsd:sys_open+0x34
0xca86cf84: netbsd:syscall+0x88
0xca86cfac: netbsd:swi_handler+0x98
db>

とはいうものの、c1a35d28はobjdumpしても見つからない。
よく考えたら、アドレスがわかっても意味なくって、アドレスに格納されている値が大事なのでは？

まてよ、そういえばコンソールから入力できるようになっているので、ddbが使えるということでは？！

man ddbしてみると、いくつかのコマンドが打てる。
psとかやってみる。

db> ps
PID    LID S CPU     FLAGS       STRUCT LWP *               NAME WAIT
2        1 2   0         0           c1a3b540               init
1    >   1 7   0         0           c1be8aa0               init
0       30 3   0       200           c1a3b2a0           aiodoned aiodoned
0       29 3   0       200           c1be8d40            ioflush syncer
0       28 3   0       200           c1a3b000           pgdaemon pgdaemon
0       25 3   0       200           c1be8800              unpgc unpgc
0       24 3   0       200           c1be8560        vmem_rehash vmem_rehash
0       15 3   0       200           c1a3ba80         pmfsuspend pmfsuspend
0       14 3   0       200           c1a3bd20           pmfevent pmfevent
0       13 3   0       200           c1a34020         sopendfree sopendfr
0       12 3   0       200           c1a342c0           nfssilly nfssilly
0       11 3   0       200           c1a34560            cachegc cachegc
0       10 3   0       200           c1a34800              vrele vrele
0        9 3   0       200           c1a34aa0             vdrain vdrain
0        8 3   0       200           c1a34d40          modunload mod_unld
0        7 3   0       200           c1a2b000            xcall/0 xcall
0        6 1   0       200           c1a2b2a0          softser/0
0        5 1   0       200           c1a2b540          softclk/0
0        4 1   0       200           c1a2b7e0          softbio/0
0        3 1   0       200           c1a2ba80          softnet/0
0        2 1   0       201           c1a2bd20             idle/0
0        1 3   0       200           c029b120            swapper uvm
db>

おぉー、プロセスがけっこう動いているみたいじゃないか。

アドレスの中身を除くのはexamineのようだ。

本題に戻ってc1a35d28つまりvp->v_opから先頭を10こ表示させてみる。

db> examine /x c1a35d28,10
c1a35d28:       c0167b48    c01640b8    c00d77c8    c00402ec    c00402ec    c00d
85f8    c00d7944    c004047c    c004047c    c004047c    c00d82dc    c00d7f74
c1a35d58:       c00d7e40    c00402d8    c00d7da4    c00d7d78
db>

ほうほう。VOFFSET(vop_open)=00000005だった。配列は0から始まるので6個目がそれにあたる。
つまり、改行しているところにある値がそれで、c00d85f8である。
これをobjdumpの結果にgrepしてみる。

c00d85f8 <spec_open>:
c00d85f8:       e1a0c00d        mov     ip, sp
c00d85fc:       e92ddff0        push    {r4, r5, r6, r7, r8, r9, sl, fp, ip, lr, pc}
c00d8600:       e24cb004        sub     fp, ip, #4
c00d8604:       e24dd024        sub     sp, sp, #36     ; 0x24
c00d8608:       e1a06000        mov     r6, r0
c00d860c:       ee1d3f90        mrc     15, 0, r3, cr13, cr0, {4}
c00d8610:       e5904004        ldr     r4, [r0, #4]
c00d8614:       e5933178        ldr     r3, [r3, #376]  ; 0x178
c00d8618:       e5945098        ldr     r5, [r4, #152]  ; 0x98
c00d861c:       e50b3034        str     r3, [fp, #-52]  ; 0x34
c00d8620:       e5943064        ldr     r3, [r4, #100]  ; 0x64
c00d8624:       e595800c        ldr     r8, [r5, #12]
c00d8628:       e3530000        cmp     r3, #0
c00d862c:       e595a010        ldr     sl, [r5, #16]
c00d8630:       e5959004        ldr     r9, [r5, #4]

おぉ、関数名にopenがついてそれっぽいぞ！

spec_openは[sys/miscfs/specfs/spec_vnops.c#spec_open]にある。

sys/kern/vfs_subr.c#cdevvpにあったgetdevvpにVCHRが与えられていたことから、

    352 int
    353 cdevvp(dev_t dev, vnode_t **vpp)
    354 {
    355 
    356     return (getdevvp(dev, vpp, VCHR));
    357 }

このブロックがひじょーに怪しいな。device not configuredのENXIOという記述もあるし。

    531     switch (vp->v_type) {
    532     case VCHR:
    533         error = kauth_authorize_device_spec(ap->a_cred, req, vp);
    534         if (error != 0)
    535             return (error);
    536 
    537         /*
    538          * Character devices can accept opens from multiple
    539          * vnodes.
    540          */
    541         mutex_enter(&device_lock);
    542         if (sn->sn_gone) {
    543             mutex_exit(&device_lock);
    544             return (EBADF);
    545         }
    546         sd->sd_opencnt++;
    547         sn->sn_opencnt++;
    548         mutex_exit(&device_lock);
    549         if (cdev_type(dev) == D_TTY)
    550             vp->v_vflag |= VV_ISTTY;
    551         VOP_UNLOCK(vp);
    552         do {
    553             const struct cdevsw *cdev;
    554 
    555             gen = module_gen;
    556             error = cdev_open(dev, ap->a_mode, S_IFCHR, l);
    557             if (error != ENXIO)
    558                 break;
    559 
    560             /* Check if we already have a valid driver */
    561             mutex_enter(&device_lock);
    562             cdev = cdevsw_lookup(dev);
    563             mutex_exit(&device_lock);
    564             if (cdev != NULL)
    565                 break;
    566 
    567             /* Get device name from devsw_conv array */
    568             if ((name = cdevsw_getname(major(dev))) == NULL)
    569                 break;
    570 
    571             /* Try to autoload device module */
    572             (void) module_autoload(name, MODULE_CLASS_DRIVER);
    573         } while (gen != module_gen);
    574 
    575         vn_lock(vp, LK_EXCLUSIVE | LK_RETRY);
    576         break;

ここがprintfで反応したらビンゴかもしれん。

ビンゴであった。
結局subr_devsw.cのcdevsw_lookup, cdev_openあたりにprintfを入れまくり。

ひさびさにバナーからログを残しておこう。　

init subsystems: stacks vectors undefined page pmap_physload pmap [ Kernel symbol table missing! ]
done.
Loaded initial symtab at 0xc01e431c, strtab at 0xc020453c, # entries 8211
pmap_postinit: Allocated 35 static L1 descriptor tables
Copyright (c) 1996, 1997, 1998, 1999, 2000, 2001, 2002, 2003, 2004, 2005,
    2006, 2007, 2008, 2009, 2010, 2011, 2012, 2013
    The NetBSD Foundation, Inc.  All rights reserved.
Copyright (c) 1982, 1986, 1989, 1991, 1993
    The Regents of the University of California.  All rights reserved.

NetBSD 6.99.23 (APC) #50: Mon Oct  7 17:28:43 UTC 2013
        root@builder.localdomain:/usr/obj/sys/arch/evbarm/compile/APC
total memory = 512 MB
avail memory = 495 MB
mainbus0 (root)
cpu0 at mainbus0 core 0: ARM1176JZ-S r0p7 (ARM11J V6ZK core)
cpu0: DC enabled IC enabled WB enabled LABT
cpu0: 16KB/32B 4-way L1 Instruction cache
cpu0: 16KB/32B 4-way write-back-locking-C L1 Data cache
vfp0 at cpu0: VFP11
obio0 at mainbus0
wmicu0 at obio0 addr 0xd8140000-0xd814ffff
icu-debug:
d8140040: 00000000 -> 00000000
d8140044: 00000000 -> 00000000
d8140048: 00000000 -> 00000000
d814004c: 00000000 -> 00000000
d8140050: 00000000 -> 00000000
d8140054: 00000000 -> 00000000
d8140058: 00000000 -> 00000000
d814005c: 00000000 -> 00000000
d8140060: 00000000 -> 00000000
d8140064: 00000000 -> 00000000
d8140068: 00000000 -> 00000000
d814006c: 00000000 -> 00000000
d8140070: 00000000 -> 00000000
d8140074: 00000000 -> 00000000
d8140078: 00000000 -> 00000000
d814007c: 00000000 -> 00000000
wmtmr0 at obio0 addr 0xd8100000-0xd810ffff intr 48 : WMT System Timer
wmtcom0 at obio0 addr 0xd8200000-0xd820ffff intr 32 : WMT UART
wmtcom:wmtcom_attach_subr
wmtcom:wmtcom_attach_subr 1
wmtcom:wmtcom_attach_subr 1-1
wmtcom:wmtcom_attach_subr 1-2
wmtcom:wmtcom_attach_subr 1-3
wmtcom:wmtcom_attach_subr 2
wmtcom:wmtcom_attach_subr 3
wmtcom:wmtcom_attach_subr 3-1
wmtcom0: console cn_tab->cn_dev=000fff00
icu: establish_irq: is->is_irq=0x20
icu: unblock: irqbase=0x00000020, irqmask=0x00000001, irq_num=32, reg=0x00000008
icu: establish_irq: is->is_irq=0x30
icu: unblock: irqbase=0x00000020, irqmask=0x00010000, irq_num=48, reg=0x00000008
rn_init: radix functions require max_keylen be set
start_init
module_init_class
boot device: <unknown>
root on md0a dumps on md0b
VOP_OPEN: vp=c1bf2f20, vp->v_op=c1a35d28, VOFFSET(vop_open)=00000005
spec_open: start
cdevsw_lookup: dev=00001200, cmajor = 18, cdevsw = c01e0350
spec_open: cdev_ioctl error=0
VOP_OPEN: error=0
mountroot: trying nfs...
mountroot: trying msdos...
mountroot: trying ffs...
root file system type: ffs
configure3
inittodr
WARNING: no TOD clock present
WARNING: using filesystem time
WARNING: CHECK AND RESET THE DATE!
uvm_swap_init
VOP_OPEN: vp=c1bf2dc0, vp->v_op=c1a35d28, VOFFSET(vop_open)=00000005
spec_open: start
cdevsw_lookup: dev=00000100, cmajor = 1, cdevsw = c01e0350
spec_open: cdev_type(dev) != D_DISK error=0
VOP_OPEN: error=0
uvm_scheduler
init: copying out flags `-s' 3
init: copying out path `/sbin/init' 11
move out arg pinters
sys_execve
VOP_OPEN: vp=c1bf2b00, vp->v_op=c1a35b68, VOFFSET(vop_open)=00000005
VOP_OPEN: error=0
sys_execve: error = -2
vn_open: pathstring=/dev/console
VOP_OPEN: vp=c1bf2c60, vp->v_op=c1a35a88, VOFFSET(vop_open)=00000005
spec_open: start
spec_open: VCHR
cdevsw_lookup: dev=00000200, cmajor = 2, cdevsw = c01e0350
cdevsw_lookup: dev=00000200, cmajor = 2, cdevsw = c01e0350
cdevsw_lookup: dev=00000200, cmajor = 2, cdevsw = c01e0350
cdev_open: d->d_open = c001034c, dev=00000200
cnopen: minor
cnopen: cn_tab == NULL?
cnopen: cndev=000fff00
cnopen: cndev == NODEV?
cnopen: dev == cndev?
cnopen: cn_devvp == NULLVP? unit=0
cnopen: cdevvp()
cnopen: cdevvp() error=0
cnopen: vn_lock()
cnopen: vn_lock error=0
cnopen: VOP_OPEN cndevvp[0]=c1bf2a50
VOP_OPEN: vp=c1bf2a50, vp->v_op=c1a35d28, VOFFSET(vop_open)=00000005
spec_open: start
spec_open: VCHR
cdevsw_lookup: dev=000fff00, cmajor = 4095, cdevsw = c01e0350
cdevsw_lookup: dev=000fff00, cmajor = 4095, cdevsw = c01e0350
cdevsw_lookup: dev=000fff00, cmajor = 4095, cdevsw = c01e0350
cdev_open: cdevsw_lookup() == NULL, dev=000fff00
spec_open: cdev_open error=6
cdevsw_lookup: dev=000fff00, cmajor = 4095, cdevsw = c01e0350
cdevsw_lookup: dev=000fff00, cmajor = 4095, cdevsw = c01e0350
spec_open: cdev_type(dev) != D_DISK error=6
VOP_OPEN: error=6
cnopen: VOP_UNLOCK error=6
panic: cnopen
Stopped in pid 1.1 (init) at    netbsd:cpu_Debugger+0x4:        bx      r14
0xca86cc80: netbsd:vpanic+0xc
0xca86cc98: netbsd:printf_nolog
0xca86ccd4: netbsd:cnopen+0x16c
0xca86ccfc: netbsd:cdev_open+0x78
0xca86cd4c: netbsd:spec_open+0x1b0
0xca86cd70: netbsd:VOP_OPEN+0xa0
0xca86ce24: netbsd:vn_open+0x1e8
0xca86ce9c: netbsd:do_open+0xb0
0xca86cecc: netbsd:do_sys_openat+0x7c
0xca86cef0: netbsd:sys_open+0x34
0xca86cf84: netbsd:syscall+0x88
0xca86cfac: netbsd:swi_handler+0x98
db>

結論から言えば、cdevsw[]に所望のデバイスが見つからない（lookupできない）のでエラーになっていた。
うまくlookupできているものとそうでないものを比較していてぴんときた。

cdevsw_lookup: dev=00000200, cmajor = 2, cdevsw = c01e0350
cdevsw_lookup: dev=000fff00, cmajor = 4095, cdevsw = c01e0350

そういえば、dev=000fff00って変だなと思っていて、wmt_com.cのattachでそれを作っていたのだった。

                /* locate the major number */
                maj = cdevsw_lookup_major(&wmtcom_cdevsw);

                cn_tab->cn_dev = makedev(maj, device_unit(sc->sc_dev));

makedevはビットシフトしてintを作るだけなんだけど、majが怪しいってことですな。
で、それの元ネタになるのが&wmtcom_cdevswなわけで、デバイスのメジャー番号ってどこで定義するんだっけ？　自動的に決まるというはずはなくってどこかに書いたはずだけど、ということでgrep -i major しまくるとarch/arm/conf/majors.arm32にたどり着いた。
ここにはepcomなどのCPU固有のデバイスを含めて記述されている。wmtcomはここに書いていないからうまくlookupできないのに違いない。
evbarm/conf/APCに一行加えてやってみる。

mountroot: trying msdos...
mountroot: trying ffs...
root file system type: ffs
configure3
inittodr
WARNING: no TOD clock present
WARNING: using filesystem time
WARNING: CHECK AND RESET THE DATE!
uvm_swap_init
VOP_OPEN: vp=c1bf2dc0, vp->v_op=c1a35d28, VOFFSET(vop_open)=00000005
spec_open: start
cdevsw_lookup: dev=00000100, cmajor = 1, cdevsw = c01e0350
spec_open: cdev_type(dev) != D_DISK error=0
VOP_OPEN: error=0
uvm_scheduler
init: copying out flags `-s' 3
init: copying out path `/sbin/init' 11
move out arg pinters
sys_execve
VOP_OPEN: vp=c1bf2b00, vp->v_op=c1a35b68, VOFFSET(vop_open)=00000005
VOP_OPEN: error=0
sys_execve: error = -2
vn_open: pathstring=/dev/console
VOP_OPEN: vp=c1bf2c60, vp->v_op=c1a35a88, VOFFSET(vop_open)=00000005
spec_open: start
spec_open: VCHR
cdevsw_lookup: dev=00000200, cmajor = 2, cdevsw = c01e0350
cdevsw_lookup: dev=00000200, cmajor = 2, cdevsw = c01e0350
cdevsw_lookup: dev=00000200, cmajor = 2, cdevsw = c01e0350
cdev_open: d->d_open = c001034c, dev=00000200
cnopen: minor
cnopen: cn_tab == NULL?
cnopen: cndev=00007000
cnopen: cndev == NODEV?
cnopen: dev == cndev?
cnopen: cn_devvp == NULLVP? unit=0
cnopen: cdevvp()
cnopen: cdevvp() error=0
cnopen: vn_lock()
cnopen: vn_lock error=0
cnopen: VOP_OPEN cndevvp[0]=c1bf2a50
VOP_OPEN: vp=c1bf2a50, vp->v_op=c1a35d28, VOFFSET(vop_open)=00000005
spec_open: start
spec_open: VCHR
cdevsw_lookup: dev=00007000, cmajor = 112, cdevsw = c01e0350
cdevsw_lookup: dev=00007000, cmajor = 112, cdevsw = c01e0350
cdevsw_lookup: dev=00007000, cmajor = 112, cdevsw = c01e0350
cdev_open: d->d_open = c0184f7c, dev=00007000
panic: wmtcom: open

Stopped in pid 1.1 (init) at    netbsd:cpu_Debugger+0x4:        bx      r14
0xca86cbd4: netbsd:vpanic+0xc
0xca86cbec: netbsd:printf_nolog
0xca86cc0c: netbsd:wmtcomopen+0x14
0xca86cc34: netbsd:cdev_open+0x78
0xca86cc84: netbsd:spec_open+0x1b0
0xca86cca8: netbsd:VOP_OPEN+0xa0
0xca86ccd4: netbsd:cnopen+0x150
0xca86ccfc: netbsd:cdev_open+0x78
0xca86cd4c: netbsd:spec_open+0x1b0
0xca86cd70: netbsd:VOP_OPEN+0xa0
0xca86ce24: netbsd:vn_open+0x1e8
0xca86ce9c: netbsd:do_open+0xb0
0xca86cecc: netbsd:do_sys_openat+0x7c
0xca86cef0: netbsd:sys_open+0x34
0xca86cf84: netbsd:syscall+0x88
0xca86cfac: netbsd:swi_handler+0x98
db>

よし！ wmt_com.cのwmtcomopenが呼ばれた！

ついに/sbin/initのシステムコールopenからソフトウェア割込み経由でカーネルに入り、vn_open -> spec_open -> cdev_open -> cn_open -> spec_open -> cdev_open -> wmtcomopenというopenの流れをつなぐことができた。

vnode（vn)からキャラクタデバイス（cdev)にいき、コンソール(cn)に行き、デバイスドライバに行き着くということなんだろうか。

gitリポジトリに久しぶりにcommit & push。ファイルをリネームして億劫になっていた。

結局、git mv oldfile newfileとやらねばならないらしく、ファイル名をいったん戻してからcommitし直して面倒だった。うかつに通常のmvを使ってはいけないね。

さて、ここまで来たら、またixp12x0_comを手本にしてシリアルコンソールドライバを作りこむことになりそうだ。

ハードウェア割込みとソフトウェア割り込みの合わせ技でread/writeするというのを実現しつつ、今のところ用途がわからない関数をうめていくのかなぁ。まずは、ユーザランドから一文字でもいいから出力してみたい。うん。

一日releaseさせて、いざ。

ramdisk.fsがインストールカーネルのfsなので、それをmdsetimageしてブートしてみたが、症状は同じであった。つまり、何にも変わらない。

ということで、mdsetimageやらramdisk.fsを疑うよりも、/sbin/initが動いているのか追っかけてみるのがよさそうである。

/sbin/initはユーザ空間では動いていないので、コンソール出力といってもcnputcは使えないよなぁ、と思いながらinit.cを読む。

するとsbin/init/init.c#393にはprint_consoleという関数が用意されている。少し手前の#if 0で潰されているけれど、なんだこれは。

    392 static void
    393 print_console(int level, const char *message, va_list ap)
    394 {
    395 	/*
    396 	 * XXX: syslog seems to just plain not work in console-only
    397 	 * XXX: situation... that should be fixed.  Let's leave this
    398 	 * XXX: note + code here in case someone gets in trouble and
    399 	 * XXX: wants to debug. -- Jachym Holecek <freza (at) liberouter.org>
    400 	 */
    401 	char errbuf[1024];
    402 	int fd, len;
    403 
    404 	/* We can't do anything on errors, anyway... */
    405 	fd = open(_PATH_CONSOLE, O_WRONLY);
    406 	if (fd == -1)
    407 		return ;
    408 
    409 	/* %m will get lost... */
    410 	len = vsnprintf(errbuf, sizeof(errbuf), message, ap);
    411 	(void)write(fd, (void *)errbuf, len);
    412 	(void)close(fd);
    413 }

いかにもopen, write, closeてな調子でシステムコールを呼んでくれそうだ。ひいては、それがwmtcomopenやwmtcomwriteを読んでくれるのではないか。まぁ、open, writeは実装されていないから、シリアルドライバをちゃんと動くようにしなきゃダメだろうけど。ひとまず、手掛かりを追ってみよう。　

さて、init.cをいじってramdisk.fsを作るのは面倒くさそうである。build.sh releaseを毎回やるのは時間がかかりすぎる。もっと良い手があるはず。

build中のログを見ると、

===> Updated makewrapper: /usr/src/obj/tooldir.NetBSD-6.99.23-amd64/bin/nbmake-evbarm

なる行がある。これを使えば、とても楽ちんである。

builder# cd /usr/src/distrib/evbarm/instkernel/ramdisk/
builder# vi /usr/src/sbin/init/init.c
builder# /usr/src/obj/tooldir.NetBSD-6.99.23-amd64/bin/nbmake-evbarm  > make.log
builder# cp obj/ramdisk.fs /root/md

これでinit.cを修正した版のramdisk.fsができるのである。

ということで、main関数の最初のほうでprint_consoleを仕込んでみた。

wmtmr0 at obio0 addr 0xd8100000-0xd810ffff intr 48 : WMT System Timer
wmtcom0 at obio0 addr 0xd8200000-0xd820ffff intr 32 : WMT UART
wmtcom:wmtcom_attach_subr
icu: establish_irq: is->is_irq=0x20
icu: unblock: irqbase=0x00000020, irqmask=0x00000001, irq_num=32, reg=0x00000008
icu: establish_irq: is->is_irq=0x30
icu: unblock: irqbase=0x00000020, irqmask=0x00010000, irq_num=48, reg=0x00000008
rn_init: radix functions require max_keylen be set
start_init
module_init_class
boot device: <unknown>
root on md0a dumps on md0b
mountroot: trying nfs...
mountroot: trying msdos...
mountroot: trying ffs...
root file system type: ffs
configure3
inittodr
WARNING: no TOD clock present
WARNING: using filesystem time
WARNING: CHECK AND RESET THE DATE!
uvm_swap_init
uvm_scheduler
init: copying out flags `-s' 3
init: copying out path `/sbin/init' 11
move out arg pinters
sys_execve
sys_execve: eror = -2
panic: cnopen: no console device
Stopped in pid 1.1 (init) at    netbsd:cpu_Debugger+0x4:        bx      r14
0xca86cc94: netbsd:vpanic+0xc
0xca86ccac: netbsd:printf_nolog
0xca86ccd8: netbsd:cnopen+0xf0
0xca86cd00: netbsd:cdev_open+0x68
0xca86cd50: netbsd:spec_open+0x198
0xca86cd70: netbsd:VOP_OPEN+0x60
0xca86ce24: netbsd:vn_open+0x1dc
0xca86ce9c: netbsd:do_open+0xb0
0xca86cecc: netbsd:do_sys_openat+0x7c
0xca86cef0: netbsd:sys_open+0x34
0xca86cf84: netbsd:syscall+0x88
0xca86cfac: netbsd:swi_handler+0x98
db>

よっしゃpanicしてくれた。

トレースからなんとなく、openがソフトウェア割込み（swi）を発生させて、その割込みをswi_handlerが拾って割込み処理をしているように見える。

panicとともに表示されているno console deviceと出力しているのは//nxr.netbsd.org/xref/src/sys/dev/cons.c#cnopen関数である。

     96     cndev = cn_tab->cn_dev;
     97     if (cndev == NODEV) {
     98         /*
     99          * This is most likely an error in the console attach
    100          * code. Panicking looks better than jumping into nowhere
    101          * through cdevsw below....
    102          */
    103         panic("cnopen: no console device");
    104     }

ということで、cn_tab->cn_devがないのである。

なんとなくcn_tabに見覚えがあったので、sys/arch/arm/ixp12x0/ixp12x0_com.c#ixpcom_attach_subrをみてみると、

    183 void
    184 ixpcom_attach_subr(struct ixpcom_softc *sc)
    185 {
... 
    223 
    224 	tty_attach(tp);
    225 
    226 	if (ISSET(sc->sc_hwflags, COM_HW_CONSOLE)) {
    227 		int maj;
    228 
    229 		/* locate the major number */
    230 		maj = cdevsw_lookup_major(&ixpcom_cdevsw);
    231 
    232 		cn_tab->cn_dev = makedev(maj, device_unit(sc->sc_dev));
    233 
    234 		aprint_normal("%s: console\n", device_xname(sc->sc_dev));
    235 	}

ここで定義している。つまり、wmtcom_attach_subrで同じようにしてやればよいのであろう。コピーして、すこし手直しすればよさそうである。

動かしてみると、wmtcom_attach_subrで止まる。printf debugしてみるとdelay(10000)で止まっている。

    196 		/* Make sure the console is always "hardwired". */
    197 		/* XXX IXPCOM_SR should be checked  */
    198 		delay(10000);	/* wait for output to finish */

これは、やっぱしdelayを適当に作ったのがイカンかったようですな。wmt_tmr.cもやっぱりちゃんとやらないとダメなんですね。うーん。
とはいえ、delayを#ifdef hogeで飛ばすと、ひとまず先に進んで、やっぱりとまる。

d814007c: 00000000 -> 00000000
wmtmr0 at obio0 addr 0xd8100000-0xd810ffff intr 48 : WMT System Timer
wmtcom0 at obio0 addr 0xd8200000-0xd820ffff intr 32 : WMT UART
wmtcom:wmtcom_attach_subr
wmtcom:wmtcom_attach_subr 1
wmtcom:wmtcom_attach_subr 1-1
wmtcom:wmtcom_attach_subr 1-2
wmtcom:wmtcom_attach_subr 1-3
wmtcom:wmtcom_attach_subr 2
wmtcom:wmtcom_attach_subr 3
wmtcom:wmtcom_attach_subr 3-1
wmtcom0: console
icu: establish_irq: is->is_irq=0x20
icu: unblock: irqbase=0x00000020, irqmask=0x00000001, irq_num=32, reg=0x00000008
icu: establish_irq: is->is_irq=0x30
icu: unblock: irqbase=0x00000020, irqmask=0x00010000, irq_num=48, reg=0x00000008
rn_init: radix functions require max_keylen be set
start_init
module_init_class
boot device: <unknown>
root on md0a dumps on md0b
mountroot: trying nfs...
mountroot: trying msdos...
mountroot: trying ffs...
root file system type: ffs
configure3
inittodr
WARNING: no TOD clock present
WARNING: using filesystem time
WARNING: CHECK AND RESET THE DATE!
uvm_swap_init
uvm_scheduler
init: copying out flags `-s' 3
init: copying out path `/sbin/init' 11
move out arg pinters
sys_execve
sys_execve: eror = -2

cons.cは通っているんだろうか？
wmtcomxxxxのaprintf_normalが動く保証がどこにもないな。
うーん、かたっぱしからpanicするようにしたらいいんだろうか。

まず、//nxr.netbsd.org/xref/src/sys/dev/cons.c#cnopenをprintf debug

uvm_swap_init
uvm_scheduler
init: copying out flags `-s' 3
init: copying out path `/sbin/init' 11
move out arg pinters
sys_execve
sys_execve: eror = -2
cnopen: minor
cnopen: cn_tab == NULL?
cnopen: cndev == NODEV?
cnopen: dev == cndev?
cnopen: cn_devvp == NULLVP?
Process (pid 1) got sig 11
Process (pid 1) got sig 11
Process (pid 1) got sig 11
Process (pid 1) got sig 11
Process (pid 1) got sig 11
以降sig 11が続く

二回やっても同じ。signal 11はsys/signal.hより、

     63 #define    SIGSEGV        11    /* segmentation violation */

らしい。うーん、変なところを指しているのかな。というか、NULLVPということは、

    114     if (cn_devvp[unit] != NULLVP)
    115         return 0;

ということだから、unitがめちゃくちゃなのかな？

sys_execve: eror = -2
cnopen: minor
cnopen: cn_tab == NULL?
cnopen: cndev == NODEV?
cnopen: dev == cndev?
cnopen: cn_devvp == NULLVP? unit=0
Process (pid 1) got sig 11
Process (pid 1) got sig 11
Process (pid 1) got sig 11
Process (pid 1) got sig 11

unit=0である。cn_devvp触ったら死んでいるということか。
sys/dev/cons.c#cnopenの手前にある定義ではこうなっている。

struct  tty *constty = NULL;    /* virtual console output device */
struct  consdev *cn_tab;        /* physical console device info */
struct  vnode *cn_devvp[2];     /* vnode for underlying device. */

int
cnopen(dev_t dev, int flag, int mode, struct lwp *l)

うーん。なにがいかんのか。わからんので寝る！

あらためて考えたら、ちゃんとsbin/init/init.cの中が実行されているということだよな。

さて、シリアルコンソールが動いてroot deviceを指定できるようになったので、/sbin/initを動かしてみたい。とはいえ、etherドライバもないし、SDのドライバもないのでmdデバイスを使ってメモリ上で動かしてみようと思う。512MBもメモリあるし。

conf/APCにoptions MEMORY_DISKシリーズをINSTALLからパクってくる。

ルートファイルシステムイメージのファイルを作る。

dd if=/dev/zero of=rootfs.img bs=12m count=1
vnconfig vnd0 rootfs.img
newfs /dev/rvnd0a
mount /dev/rvnd0a /mnt

イメージファイルの中身はevbarmのbase.tgz, etc.tgzを拾ってきて、sbin/init, bin/sh, dev/MAKEDEVあたりをコピー。
MAKEDEV allしないとpanicするので注意だな。

mdsetimage netbsd rootfs.img

でメモリディスクつきのkernelになる。簡単だね。
ただ、rescue/init, shで動かしてみると、initを実行するところで止まってしまう。

icu: establish_irq: is->is_irq=0x30
icu: unblock: irqbase=0x00000020, irqmask=0x00010000, irq_num=48, reg=0x00000008
rn_init: radix functions require max_keylen be set
boot device: <unknown>
root on md0a dumps on md0b
mountroot: trying nfs...
mountroot: trying msdos...
mountroot: trying ffs...
root file system type: ffs
WARNING: no TOD clock present
WARNING: using filesystem time
WARNING: CHECK AND RESET THE DATE!
init: copying out flags `-s' 3
init: copying out path `/sbin/init' 11
exec /sbin/init: error 2
init: copying out flags `-s' 3
init: copying out path `/sbin/oinit' 12
exec /sbin/oinit: error 2
init: copying out flags `-s' 3
init: copying out path `/sbin/init.bak' 15
exec /sbin/init.bak: error 2
init path (default /sbin/init): /rescue/init
init: copying out flags `-s' 3
init: copying out path `/rescue/init' 13

うーん、どこが変なのかな。資材が足りてないのか、mdsetimageがうまく動いてくれていないのか。initはバイナリをとってきたやつなのでデバッグ文も入れられらないし。

ディスクイメージの作り方ミスだと悲しすぎるのと改造版/sbin/initを作れるようにするためにbuild.sh releaseしよう。ちゃんとしたやり方でINSTALLカーネルが作られるはずだし。

そういや、initはconsoleをopenするのだろうか。まぁ、インストーラは絶対openするだろうからとにかくやってみるかな。