割り込みきた

QEMU Mona


「QemuのNE2000から割り込みが来ない」と書いたがやっと割り込みが来た。
uIP も動いている。
以下詳細なデバッグログ。（ほとんどの人には役に立たないと思う）
QEMU を利用したデバッグ。

現象

  • NE2000 の割り込みが来ない
  • QEMU上は割り込みイベントが発生しているっぽい

デバッグ方針

QEMU のソースに手を入れて調べる。

調査

gtags -v をやっておく。
割り込みコントローラで何が起きているか。
hw/i8259.c を見る。

#define DEBUG_PIC
#define DEBUG_IRQ_LATENCY
#define DEBUG_IRQ_COUNT

を有効にしてコンパイルしてみる。

情報が出すぎて困るので DEBUG_PIC だけにする。
さらに irq == 11 だけにしぼってみる

#if defined(DEBUG_PIC) || defined(DEBUG_IRQ_11)
    if (11 == irq) printf("pic_interrupt: [] irq=%d\n", irq);
#endif

ログに一度も出ないということは割り込みは起きていない。
全割り込みを知りたいので、11だけにしぼるのをやめて、ログをとり uniq する

~/src/qemu-0.9.0/i386-softmmu/qemu -cdrom ~/mona/tool/mkimg/mona.iso -fda ~/mona/tool/mkimg/mona.img -boot d -soundhw pcspk -k ja -serial file:/tmp/qemu_mona.log -soundhw es1370 -net nic -net user -redir tcp:5555:10.0.2.15:80 | sort | uniq


結果。

pic_interrupt: irq=0  # システムタイマ
pic_interrupt: irq=1  # キーボード
pic_interrupt: irq=12 # PS/2マウス
pic_interrupt: irq=15 # IDE
pic_interrupt: irq=6  # FDC

これは想定通り。ここに irq=11 がないのがおかしい。

ではどうして起きないのか？
int pic_read_irq(PicState2 *s) で pic_interrupt に printf がある。
pic_read_irq の呼出し以前にはじかれているようだ。

pic_read_irq が呼ばれているのは3ヶ所。

pic_read_irq      867 /home/taro/src/qemu-0.9.0/hw/apic.c                     vector = pic_read_irq(isa_pic);
pic_read_irq      440 /home/taro/src/qemu-0.9.0/hw/gt64xxx.c         val = pic_read_irq(isa_pic);
pic_read_irq       98 /home/taro/src/qemu-0.9.0/hw/pc.c     intno = pic_read_irq(isa_pic);

怪しいのは apic.c かな。
資料 - APIC - Wikipedia。

apic.c に printf をいれてみるか。ちょっと分からないかな。
pc.c にもいれてみよう。

分からなくなったので整理 & dev-j で neriさん okuokuさんに聞いてまわる。

  • PIC とAPIC どちらを使うかは OS が選択する
  • APIC はデフォルト無効

らしい。
pc.c の cpu_get_pic_interrupt から pic_read_irq が呼ばれている。

cpu_get_pic_interrupt  427 /home/taro/src/qemu-0.9.0/cpu-exec.c                         intno = cpu_get_pic_interrupt(env);

cpu-exec の引数の構造体は eflags など各種のレジスタ。
cpu_get_pic_interrupt はどういう関数か？

  • apic_get_interrupt(env);を呼ぶ
  • intno = pic_read_irq(isa_pic);を呼ぶ

irq2 = pic_get_irq(&s->pics[1]); した時点で、3が返らないとおかしい。(+8 して 11)

pic_get_irq では何が起きるか？

priority = get_priority(s, mask);

static inline int get_priority(PicState *s, int mask)
{
    int priority;
    if (mask == 0)
        return 8;
    priority = 0;
    while ((mask & (1 << ((priority + s->priority_add) & 7))) == 0)
        priority++;
    return priority;
}

んー。結局 mask が問題のように思える。
pics[0] の 2bit目のマスク部分と、pics[1] の3bit目のマスクをチェックしたい。

Mona側でチェックしてみよう。

uint8_t pic0 = inp8(0x21);
uint8_t pic1 = inp8(0xa1);

_printf("pic0=%x, pic1=%x\n", pic0, pic1);

pic0 => 1011'1000
pic1 => 0000 0001

もうマスクやめてみよう。

outp8(0x21, 0);
outp8(0xA1, 0);
uint8_t pic0 = inp8(0x21);
uint8_t pic1 = inp8(0xa1);
        printf("pic0=%x, pic=1=%x\n", pic0, pic1);

だめだ。状況は変わらない。
NE2000.c から追ってみよう。

static void ne2000_update_irq(NE2000State *s)
{
    int isr;
    isr = (s->isr & s->imr) & 0x7f;
#if defined(DEBUG_NE2000)
    printf("NE2000: Set IRQ line %d to %d (%02x %02x)\n",
   s->irq, isr ? 1 : 0, s->isr, s->imr);
#endif
    if (s->irq == 16) {
        /* PCI irq */
        pci_set_irq(s->pci_dev, 0, (isr != 0));
    } else {
        /* ISA irq */
        pic_set_irq(s->irq, (isr != 0));
    }
}

たぶん pci_set_irq の方を通っているのを確かめた。

void pci_set_irq(PCIDevice *pci_dev, int irq_num, int level)
{
    PCIBus *bus;
    int change;
    
    change = level - pci_dev->irq_state[irq_num];
    printf("irq_num=%d change=%d\n", irq_num, change);
    if (!change)
        return;

ありゃ。irq_num = 0, change = 0だ。
pci_devって？ nameがあったりbusがあったり、PCI接続のデバイスっぽい。
name には正しいものが入ってなかった。
→

name=ES1370 irq_num=0 change=0
name=NE2000 irq_num=0 change=0

明日は level を掘り下げる。
pci初期化を疑う。audio_server2 はうまくいっているので比べる。

baseはとれているな。

        _printf("base=%x\n", pciinfo.BaseAd & ~1);

audio_server を起動すると ES1370 の状態が変化する

name=ES1370 irq_num=0 level=0 pci_dev->irq_state[irq_num]=0
name=ES1370 irq_num=0 level=1 pci_dev->irq_state[irq_num]=0
name=NE2000 irq_num=0 level=0 pci_dev->irq_state[irq_num]=0

level が変わるようだ。
level は pci_set_irq の3番めの引数で

pci_set_irq(s->pci_dev, 0, (isr != 0));

isr が 0以外のものになっていればよい。

さて NE2000 では isr は

isr = (s->isr & s->imr) & 0x7f;

となっていて、0 になっている。

s->isr => 0x80
s->imr => 0x01

ふむ。さてどうしようか。

データを受信したときに何が起こるか見てみるかな？

static void ne2000_receive(void *opaque, const uint8_t *buf, int size)

で受信処理が走っているけど、ne2000_receive の最後にある ne2000_update_irq(s); にたどり着いていない。
どこで return しているかな？

    /* XXX: check this */
    if (s->rxcr & 0x10) {
        /* promiscuous: receive all */
    } else {
        if (!memcmp(buf,  broadcast_macaddr, 6)) {
            /* broadcast address */
            if (!(s->rxcr & 0x04))
                return;
        } else if (buf[0] & 0x01) {
            /* multicast */
            if (!(s->rxcr & 0x08))
                return;
            mcast_idx = compute_mcast_idx(buf);
            if (!(s->mult[mcast_idx >> 3] & (1 << (mcast_idx & 7))))
                return;
        } else if (s->mem[0] == buf[0] &&
                   s->mem[2] == buf[1] &&                   
                   s->mem[4] == buf[2] &&            
                   s->mem[6] == buf[3] &&            
                   s->mem[8] == buf[4] &&            
                   s->mem[10] == buf[5]) {
            /* match */
        } else {
            return;
        }
    }

受信データが自分が受信すべきものかを判断していて else にいって unmatch になっているな。
一番簡単なのはプロミスキャスモードにして全部受け取ってしまうことだけどどうだろうなぁ。
まずはどういうデータがきているか見てみよう!

buf 0 0 0 0 0 0
mem 52 54 0 12 34 56

s->mem は MAC アドレスっぽい。 buf は受信データ。
0 が続くデータが来ているみたい。

Wireshark(旧ethereal) でのぞき見てみよう。
Ether ヘッダ を見ると MAC アドレスが Src/Dst ともに 0 になっている。

Ethernet II, Src: 00:00:00_00:00:00 (00:00:00:00:00:00), Dst: 00:00:00_00:00:00 (00:00:00:00:00:00)

QEMU の オプジョンで -redir tcp:5555:10.0.2.15:80 のようにリダイレクトしているのが良くないのかな。
ひょっとして 127.0.0.1 へのアクセスのときは MAC アドレスが 0 あつかいになる？
例に 127.0.0.1 に ICMP リクエストを送ってみたらやっぱり 0 だ。


同じ条件で Linux を立ち上げたときに Linux 上の Apache に対して HTTP GET が成功したのはなぜだろう？
Linux を立ち上げてみたら、きちんと MAC アドレスが一致しているなあ。


ということは？
vlan が read_buffer に入れる時点でおかしいっことかな？

    s->vc = qemu_new_vlan_client(nd->vlan, ne2000_receive,
                                 ne2000_can_receive, s);

qemu_send_packet の中で vc->fd_read(vc->opaque, buf, size); が呼ばれていてこれで、ne2000_receive が呼ばれている。
slirp_output(const uint8_t *pkt, int pkt_len) => void if_encap(const uint8_t *ip_data, int ip_data_len)

結局 void if_encap(...)で pkt を作成しているようだ。
ether header が 0 になるのはいつだろうか？

    memcpy(eh->h_dest, client_ethaddr, ETH_ALEN);
    memcpy(eh->h_source, special_ethaddr, ETH_ALEN - 1);

client_ethaddr が 0 埋めなのが問題だ。

client_ethaddr は OS からの dhcp のリクエストの際にこっそり MAC アドレスを取得しているのだけど。
bootp.c

    if (dhcp_msg_type != DHCPDISCOVER && 
        dhcp_msg_type != DHCPREQUEST)
        return;
    /* XXX: this is a hack to get the client mac address */
    memcpy(client_ethaddr, bp->bp_hwaddr, 6);

a hack とか書いてあるし!。
これでは dhcp リクエストに答えられない Mona のような OS はネットワークが使えないということになる。

  • file.bin の落ちる原因を探る
  • web サーバーが動くように。
  • Memory map エラーを分かりや好く
    • 誰が作ったのか？
    • 誰が開放したのか？
    • 無効なハンドルなのか？


file.bin が落ちる。
分かっていること

  • Mutex を使いつづけると関係ないはずの FILE.BIN が落ちる
  • FILE.BIN が落ちるアドレスは Mutex のなか。mutex_id_ を参照して落ちている

デバッグ方法を考える

  • uIP のどこで Mutex つかっている？ => printf だ！。 printf は MONITOR.CFGで起動したときは何も起きないし、変な Stream に書き換えてしまう！
  • Mutext の lock/unlock を繰り返してみて、様子を見る

monitor.cfg で起動する人達は、printf しちゃだめ。
防止する機能を作る

今回の件、まとめる