【建造中】 MacBook 機種乗り換え時のToDo

入れるアプリケーションたち

.app以外のソフト

  • homebrew
  • tmux
  • ftdiドライバ (USBシリアル変換ケーブル用)

configs

  • dotfiles
  • teminal
    • viver-terminal
    • Rictyfonts

WIP : OpenFlow on WatchGuard Firebox V60

FacebookにてOpenFlow AP with PC Engineなるwikiページが紹介されていた。
ちょうど手元には、Firebox V60が余っている。
一応この子はx86なのできっと上手くいくだろうという安直な発想の元、試しに突っ込んでみた。
以下はそのときのログ。


手順

まずは上記wikiページの手順に沿ってCFを用意する。
これを実機にセットして起動すれば終わりと手順もなにもあったものではないが、シリアルコンソールで取るときは以下に注意

baud rateは38400

BIOS画面は9600だが, OpenFlow側は(grubのmenu.lst等に書いてあるが)38400を使用している。
なおケーブルはCiscoのきしめんケーブルでOK


起動

意を決して電源を入れると下記起動時ログにあるように起動が始まる。
とりあえずここでは以下のように拡張ボードみたいにPCIに繋がっているNIC(?)ははずしている


なにやらいろいろなところで怒られている感が満載。
もっとも重大なのはeth0のfirmwareがロードできなくて転けているあたり。
ifconfigを叩いても以下のようにデフォルトではupしていない。

root@openflow-ap:~# ifconfig
dp0       Link encap:Ethernet  HWaddr 00:23:20:d6:d7:e3  
          inet addr:192.168.1.1  Bcast:192.168.1.255  Mask:255.255.255.0
          inet6 addr: fe80::223:20ff:fed6:d7e3/64 Scope:Link
          UP BROADCAST RUNNING MULTICAST  MTU:1500  Metric:1
          RX packets:0 errors:0 dropped:0 overruns:0 frame:0
          TX packets:45 errors:0 dropped:0 overruns:0 carrier:0
          collisions:0 txqueuelen:0 
          RX bytes:0 (0.0 B)  TX bytes:2106 (2.0 KiB)

lo        Link encap:Local Loopback  
          inet addr:127.0.0.1  Mask:255.0.0.0
          inet6 addr: ::1/128 Scope:Host
          UP LOOPBACK RUNNING  MTU:16436  Metric:1
          RX packets:45 errors:0 dropped:0 overruns:0 frame:0
          TX packets:45 errors:0 dropped:0 overruns:0 carrier:0
          collisions:0 txqueuelen:0 
          RX bytes:4108 (4.0 KiB)  TX bytes:4108 (4.0 KiB)

mii-toolで見てみると一応リンク状態はとれているらしい。ここではeth1からeth0に抜いて挿してをしてみたところ

root@openflow-ap:~# mii-tool 
eth0: no link
eth1: negotiated 100baseTx-FD flow-control, link ok
root@openflow-ap:~# Apr 01 06:48:13|00019|fail_open|INFO|Still in fail-open mode after 137 seconds disconnected from controller
mii-tool 
eth0: no link
eth1: no link
root@openflow-ap:~# mii-tool 
eth0: negotiated 100baseTx-FD flow-control, link ok
eth1: no link

ただしeth0にアドレスを割り当てようとすると発狂し始めた。コンソールはまだとれるものの良く分からないところにアクセスしようとして失敗する、を繰り返している。
ちなみにこの状態では外部へのpingは届かない模様。LEDもぴかぴかしない。

root@openflow-ap:~# ifconfig eth0 inet 192.168.2.1/24
[  273.756572] e100 0000:00:05.0: firmware: requesting e100/d101s_ucode.bin
[  273.767810] e100: eth0: e100_request_firmware: Failed to load firmware "e100/d101s_ucode.bin": -2
Apr 01 06:48:43|00020|timeval|WARN|35 ms poll interval (0 ms user, 0 ms system) is over 56 times the weighted mean interval 1 ms (227 samples)
Apr 01 06:48:43|00021|timeval|WARN|context switches: 1 voluntary, 0 involuntary
Apr 01 06:48:43|00022|coverage|INFO|Event coverage (epoch 227/entire run), hash=093fc71b:
Apr 01 06:48:43|00023|coverage|INFO|dpif_port_group_set          2 /         4
Apr 01 06:48:43|00024|coverage|INFO|netdev_ethtool               1 /         3
Apr 01 06:48:43|00025|coverage|INFO|netdev_get_hwaddr            1 /         3
Apr 01 06:48:43|00026|coverage|INFO|ofproto_update_port          1 /         1
Apr 01 06:48:43|00027|coverage|INFO|poll_fd_wait                 8 /      1655
Apr 01 06:48:43|00028|coverage|INFO|util_xalloc                 40 /      3924
Apr 01 06:48:43|00029|coverage|INFO|dpif_execute                 0 /         6
Apr 01 06:48:43|00030|coverage|INFO|dpif_flow_del                0 /         6
Apr 01 06:48:43|00031|coverage|INFO|dpif_flow_flush              0 /         2
Apr 01 06:48:43|00032|coverage|INFO|dpif_flow_put                0 /         6
Apr 01 06:48:43|00033|coverage|INFO|dpif_flow_query_list         0 /       166
Apr 01 06:48:43|00034|coverage|INFO|dpif_flow_query_list_n       0 /       162
Apr 01 06:48:43|00035|coverage|INFO|dpif_purge                   0 /         1
Apr 01 06:48:43|00036|coverage|INFO|flow_extract                 0 /        21
Apr 01 06:48:43|00037|coverage|INFO|hmap_expand                  0 /        10
Apr 01 06:48:43|00038|coverage|INFO|mac_learning_learned         0 /         1
Apr 01 06:48:43|00039|coverage|INFO|netlink_received             0 /         1
Apr 01 06:48:43|00040|coverage|INFO|ofproto_add_wc_flow          0 /         1
Apr 01 06:48:43|00041|coverage|INFO|ofproto_expiration           0 /       166
Apr 01 06:48:43|00042|coverage|INFO|ofproto_flush                0 /         1
Apr 01 06:48:43|00043|coverage|INFO|ofproto_odp_unchanged        0 /         6
Apr 01 06:48:43|00044|coverage|INFO|ofproto_ofp2odp              0 /         6
Apr 01 06:48:43|00045|coverage|INFO|ofproto_packet_in            0 /        15
Apr 01 06:48:43|00046|coverage|INFO|ofproto_revalidate           0 /         2
Apr 01 06:48:43|00047|coverage|INFO|ofproto_subrule_create       0 /         6
Apr 01 06:48:43|00048|coverage|INFO|poll_zero_timeout            0 /         1
Apr 01 06:48:43|00049|coverage|INFO|pstream_open                 0 /         1
Apr 01 06:48:43|00050|coverage|INFO|rconn_overflow               0 /        21
Apr 01 06:48:43|00051|coverage|INFO|rtnetlink_changed            0 /         1
Apr 01 06:48:43|00052|coverage|INFO|stream_open                  0 /        20
Apr 01 06:48:43|00053|coverage|INFO|vconn_open                   0 /        20
Apr 01 06:48:43|00054|coverage|INFO|65 events never hit
SIOCSIFFLAGS: No such file or directory
Apr 01 06:48:53|00055|stream_tcp|ERR|tcp:172.27.74.152:6634: connect: Network is unreachable
Apr 01 06:48:53|00056|rconn|WARN|dp0<->tcp:172.27.74.152:6634: connection failed (Network is unreachable)
Apr 01 06:49:01|00057|stream_tcp|ERR|tcp:172.27.74.152:6634: connect: Network is unreachable
Apr 01 06:49:01|00058|rconn|WARN|dp0<->tcp:172.27.74.152:6634: connection failed (Network is unreachable)
root@openflow-ap:~# Apr 01 06:49:09|00059|stream_tcp|ERR|tcp:172.27.74.152:6634: connect: Network is unreachable
Apr 01 06:49:09|00060|rconn|WARN|dp0<->tcp:172.27.74.152:6634: connection failed (Network is unreachable)
Apr 01 06:49:13|00061|fail_open|INFO|Still in fail-open mode after 198 seconds disconnected from controller
Apr 01 06:49:17|00062|stream_tcp|ERR|tcp:172.27.74.152:6634: connect: Network is unreachable
Apr 01 06:49:17|00063|rconn|WARN|dp0<->tcp:172.27.74.152:6634: connection failed (Network is unreachable)
Apr 01 06:49:25|00064|stream_tcp|ERR|tcp:172.27.74.152:6634: connect: Network is unreachable
Apr 01 06:49:25|00065|rconn|WARN|dp0<->tcp:172.27.74.152:6634: connection failed (Network is unreachable)
Apr 01 06:49:33|00066|stream_tcp|ERR|tcp:172.27.74.152:6634: connect: Network is unreachable
Apr 01 06:49:33|00067|rconn|WARN|dp0<->tcp:172.27.74.152:6634: connection failed (Network is unreachable)
Apr 01 06:49:41|00068|stream_tcp|ERR|tcp:172.27.74.152:6634: connect: Network is unreachable
Apr 01 06:49:41|00069|rconn|WARN|dp0<->tcp:172.27.74.152:6634: connection failed (Network is unreachable)
Apr 01 06:49:49|00070|stream_tcp|ERR|tcp:172.27.74.152:6634: connect: Network is unreachable
Apr 01 06:49:49|00071|rconn|WARN|dp0<->tcp:172.27.74.152:6634: connection failed (Network is unreachable)
Apr 01 06:49:57|00072|stream_tcp|ERR|tcp:172.27.74.152:6634: connect: Network is unreachable
Apr 01 06:49:57|00073|rconn|WARN|dp0<->tcp:172.27.74.152:6634: connection failed (Network is unreachable)
Apr 01 06:50:05|00074|stream_tcp|ERR|tcp:172.27.74.152:6634: connect: Network is unreachable
Apr 01 06:50:05|00075|rconn|WARN|dp0<->tcp:172.27.74.152:6634: connection failed (Network is unreachable)

root@openflow-ap:~#
起動ログ
[    0.000000] Initializing cgroup subsys cpuset
[    0.000000] Initializing cgroup subsys cpu
[    0.000000] Linux version 2.6.32-5-486 (Debian 2.6.32-18) (ben@decadent.org.uk) (gcc version 4.3.5 (Debian 4.3.5-2) ) #1 Sat Jul 24 01:48:25 UTC 2010
[    0.000000] KERNEL supported cpus:
[    0.000000]   Intel GenuineIntel
[    0.000000]   AMD AuthenticAMD
[    0.000000]   NSC Geode by NSC
[    0.000000]   Cyrix CyrixInstead
[    0.000000]   Centaur CentaurHauls
[    0.000000]   Transmeta GenuineTMx86
[    0.000000]   Transmeta TransmetaCPU
[    0.000000]   UMC UMC UMC UMC
[    0.000000] BIOS-provided physical RAM map:
[    0.000000]  BIOS-e820: 0000000000000000 - 000000000009f800 (usable)
[    0.000000]  BIOS-e820: 000000000009f800 - 00000000000a0000 (reserved)
[    0.000000]  BIOS-e820: 00000000000e0800 - 0000000000100000 (reserved)
[    0.000000]  BIOS-e820: 0000000000100000 - 0000000004000000 (usable)
[    0.000000]  BIOS-e820: 00000000fff00000 - 0000000100000000 (reserved)
[    0.000000] DMI not present or invalid.
[    0.000000] last_pfn = 0x4000 max_arch_pfn = 0x100000
[    0.000000] PAT not supported by CPU.
[    0.000000] init_memory_mapping: 0000000000000000-0000000004000000
[    0.000000] RAMDISK: 037e6000 - 03fef3fe
[    0.000000] 0MB HIGHMEM available.
[    0.000000] 64MB LOWMEM available.
[    0.000000]   mapped low ram: 0 - 04000000
[    0.000000]   low ram: 0 - 04000000
[    0.000000]   node 0 low ram: 00000000 - 04000000
[    0.000000]   node 0 bootmap 00001000 - 00001800
[    0.000000] (6 early reservations) ==> bootmem [0000000000 - 0004000000]
[    0.000000]   #0 [0000000000 - 0000001000]   BIOS data page ==> [0000000000 - 0000001000]
[    0.000000]   #1 [0001000000 - 000144fa00]    TEXT DATA BSS ==> [0001000000 - 000144fa00]
[    0.000000]   #2 [00037e6000 - 0003fef3fe]          RAMDISK ==> [00037e6000 - 0003fef3fe]
[    0.000000]   #3 [000009f800 - 0000100000]    BIOS reserved ==> [000009f800 - 0000100000]
[    0.000000]   #4 [0001450000 - 0001456000]              BRK ==> [0001450000 - 0001456000]
[    0.000000]   #5 [0000001000 - 0000002000]          BOOTMAP ==> [0000001000 - 0000002000]
[    0.000000] Zone PFN ranges:
[    0.000000]   DMA      0x00000000 -> 0x00001000
[    0.000000]   Normal   0x00001000 -> 0x00004000
[    0.000000]   HighMem  0x00004000 -> 0x00004000
[    0.000000] Movable zone start PFN for each node
[    0.000000] early_node_map[2] active PFN ranges
[    0.000000]     0: 0x00000000 -> 0x0000009f
[    0.000000]     0: 0x00000100 -> 0x00004000
[    0.000000] Using APIC driver default
[    0.000000] SFI: Simple Firmware Interface v0.7 http://simplefirmware.org
[    0.000000] Local APIC disabled by BIOS -- you can enable it with "lapic"
[    0.000000] APIC: disable apic facility
[    0.000000] PM: Registered nosave memory: 000000000009f000 - 00000000000a0000
[    0.000000] PM: Registered nosave memory: 00000000000a0000 - 00000000000e1000
[    0.000000] PM: Registered nosave memory: 00000000000e1000 - 0000000000100000
[    0.000000] Allocating PCI resources starting at 4000000 (gap: 4000000:fbf00000)
[    0.000000] Booting paravirtualized kernel on bare hardware
[    0.000000] Built 1 zonelists in Zone order, mobility grouping on.  Total pages: 16159
[    0.000000] Kernel command line: root=/dev/sda2 ro acpi=off console=ttyS0,38400n8 reboot=bios
[    0.000000] PID hash table entries: 256 (order: -2, 1024 bytes)
[    0.000000] Dentry cache hash table entries: 8192 (order: 3, 32768 bytes)
[    0.000000] Inode-cache hash table entries: 4096 (order: 2, 16384 bytes)
[    0.000000] Enabling fast FPU save and restore... done.
[    0.000000] Enabling unmasked SIMD FPU exception support... done.
[    0.000000] Initializing CPU#0
[    0.000000] Initializing HighMem for node 0 (00000000:00000000)
[    0.000000] Memory: 51868k/65536k available (2332k kernel code, 13256k reserved, 1145k data, 440k init, 0k highmem)
[    0.000000] virtual kernel memory layout:
[    0.000000]     fixmap  : 0xfffa2000 - 0xfffff000   ( 372 kB)
[    0.000000]     pkmap   : 0xff800000 - 0xffc00000   (4096 kB)
[    0.000000]     vmalloc : 0xc4800000 - 0xff7fe000   ( 943 MB)
[    0.000000]     lowmem  : 0xc0000000 - 0xc4000000   (  64 MB)
[    0.000000]       .init : 0xc1366000 - 0xc13d4000   ( 440 kB)
[    0.000000]       .data : 0xc124735b - 0xc1365a80   (1145 kB)
[    0.000000]       .text : 0xc1000000 - 0xc124735b   (2332 kB)
[    0.000000] Checking if this processor honours the WP bit even in supervisor mode...Ok.
[    0.000000] SLUB: Genslabs=13, HWalign=32, Order=0-3, MinObjects=0, CPUs=1, Nodes=1
[    0.000000] Hierarchical RCU implementation.
[    0.000000] NR_IRQS:288
[    0.000000] Console: colour dummy device 80x25
[    0.000000] console [ttyS0] enabled
[    0.000000] Fast TSC calibration using PIT
[    0.000000] Detected 847.712 MHz processor.
[    0.016007] Calibrating delay loop (skipped), value calculated using timer frequency.. 1695.42 BogoMIPS (lpj=3390848)
[    0.024033] Security Framework initialized
[    0.028019] SELinux:  Disabled at boot.
[    0.032016] Mount-cache hash table entries: 512
[    0.036268] Initializing cgroup subsys ns
[    0.040012] Initializing cgroup subsys cpuacct
[    0.044007] Initializing cgroup subsys devices
[    0.048008] Initializing cgroup subsys freezer
[    0.052007] Initializing cgroup subsys net_cls
[    0.056052] CPU: L1 I cache: 16K, L1 D cache: 16K
[    0.064006] CPU: L2 cache: 256K
[    0.068008] CPU serial number disabled.
[    0.072030] CPU: Intel Pentium III (Coppermine) stepping 0a
[    0.088011] Checking 'hlt' instruction... OK.
[    0.113645] devtmpfs: initialized
[    0.120712] regulator: core version 0.5
[    0.124181] NET: Registered protocol family 16
[    0.128285] EISA bus registered
[    0.132192] PCI: PCI BIOS revision 2.10 entry at 0xe5692, last bus=0
[    0.136008] PCI: Using configuration type 1 for base access
[    0.144329] bio: create slab <bio-0> at 0
[    0.148161] ACPI: Interpreter disabled.
[    0.156073] vgaarb: loaded
[    0.160149] PCI: Probing PCI hardware
[    0.164250] pci 0000:00:05.0: PME# supported from D0 D1 D2 D3hot
[    0.168010] pci 0000:00:05.0: PME# disabled
[    0.172113] pci 0000:00:06.0: PME# supported from D0 D1 D2 D3hot
[    0.176009] pci 0000:00:06.0: PME# disabled
[    0.180219] * Found PM-Timer Bug on the chipset. Due to workarounds for a bug,
[    0.180224] * this clock source is slow. Consider trying other clock sources
[    0.184049] pci 0000:00:07.3: quirk: region 1000-103f claimed by PIIX4 ACPI
[    0.188009] pci 0000:00:07.3: quirk: region 10a0-10af claimed by PIIX4 SMB
[    0.193086] Switching to clocksource tsc
[    0.199094] pnp: PnP ACPI: disabled
[    0.209563] PnPBIOS: Scanning system for PnP BIOS support...
[    0.226695] PnPBIOS: PnP BIOS support was not detected.
[    0.243128] NET: Registered protocol family 2
[    0.256433] IP route cache hash table entries: 1024 (order: 0, 4096 bytes)
[    0.277767] TCP established hash table entries: 2048 (order: 2, 16384 bytes)
[    0.298914] TCP bind hash table entries: 2048 (order: 1, 8192 bytes)
[    0.317948] TCP: Hash tables configured (established 2048 bind 2048)
[    0.336956] TCP reno registered
[    0.346498] NET: Registered protocol family 1
[    0.359562] pci 0000:00:00.0: Limiting direct PCI/PCI transfers
[    0.377313] pci 0000:00:05.0: Firmware left e100 interrupts enabled; disabling
[    0.398937] pci 0000:00:06.0: Firmware left e100 interrupts enabled; disabling
[    0.420701] Unpacking initramfs...
[    1.121005] Freeing initrd memory: 8228k freed
[    1.177455] platform rtc_cmos: registered platform RTC device (no PNP device found)
[    1.200857] audit: initializing netlink socket (disabled)
[    1.217094] type=2000 audit(1333287848.217:1): initialized
[    1.244715] HugeTLB registered 4 MB page size, pre-allocated 0 pages
[    1.267974] VFS: Disk quotas dquot_6.5.2
[    1.279886] Dquot-cache hash table entries: 1024 (order 0, 4096 bytes)
[    1.299608] msgmni has been set to 117
[    1.311348] alg: No test for stdrng (krng)
[    1.323688] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 253)
[    1.345824] io scheduler noop registered
[    1.357550] io scheduler anticipatory registered
[    1.371356] io scheduler deadline registered
[    1.384245] io scheduler cfq registered (default)
[    1.398694] isapnp: Scanning for PnP cards...
[    1.462419] Clocksource tsc unstable (delta = 168027939 ns)
[    1.520567] Switching to clocksource pit
[    1.793960] isapnp: No Plug & Play device found
[    1.799669] Linux agpgart interface v0.103
[    1.804260] Serial: 8250/16550 driver, 4 ports, IRQ sharing enabled
[    1.807934] serial8250: ttyS0 at I/O 0x3f8 (irq = 4) is a 16550A
[    1.813300] serial8250: ttyS1 at I/O 0x2f8 (irq = 3) is a 16550A
[    1.817141] PNP: No PS/2 controller found. Probing ports directly.
[    1.824814] serio: i8042 KBD port at 0x60,0x64 irq 1
[    1.827709] serio: i8042 AUX port at 0x60,0x64 irq 12
[    1.831669] mice: PS/2 mouse device common for all mice
[    1.834922] rtc_cmos rtc_cmos: rtc core: registered rtc_cmos as rtc0
[    1.841991] rtc0: alarms up to one day, 114 bytes nvram
[    1.846124] EISA: Probing bus 0 at eisa.0
[    1.850256] Cannot allocate resource for EISA slot 1
[    1.854119] EISA: Detected 0 cards.
[    1.857111] cpuidle: using governor ladder
[    1.860193] cpuidle: using governor menu
[    1.864186] No iBFT detected.
[    1.870042] TCP cubic registered
[    1.872811] NET: Registered protocol family 10
[    1.878732] lo: Disabled Privacy Extensions
[    1.884171] Mobile IPv6
[    1.887494] NET: Registered protocol family 17
[    1.892802] Using IPI Shortcut mode
[    1.896786] registered taskstats version 1
[    1.900053] rtc_cmos rtc_cmos: setting system clock to 2012-04-01 13:44:11 UTC (1333287851)
[    1.905097] Initalizing network drop monitor service
[    1.909048] Freeing unused kernel memory: 440k freed
[    1.912805] Write protecting the kernel text: 2336k
[    1.915513] Write protecting the kernel read-only data: 892k
[    2.426058] irq 4: nobody cared (try booting with the "irqpoll" option)
[    2.426466] Pid: 1, comm: swapper Not tainted 2.6.32-5-486 #1
[    2.426466] Call Trace:
[    2.426466]  [<c105975c>] ? __report_bad_irq+0x24/0x69
[    2.426466]  [<c1059763>] ? __report_bad_irq+0x2b/0x69
[    2.426466]  [<c1059886>] ? note_interrupt+0xe5/0x13b
[    2.426466]  [<c1059de5>] ? handle_level_irq+0x52/0x83
[    2.426466]  [<c1004507>] ? handle_irq+0x17/0x1c
[    2.426466]  [<c10041d6>] ? do_IRQ+0x2b/0x76
[    2.426466]  [<c1003790>] ? common_interrupt+0x30/0x40
[    2.426466]  [<c103007b>] ? current_is_keventd+0xe/0x1f
[    2.426466]  [<c10266fb>] ? __do_softirq+0x32/0x130
[    2.426466]  [<c1026829>] ? do_softirq+0x30/0x3b
[    2.426466]  [<c10268e8>] ? irq_exit+0x25/0x53
[    2.426466]  [<c1004211>] ? do_IRQ+0x66/0x76
[    2.426466]  [<c1003790>] ? common_interrupt+0x30/0x40
[    2.426466]  [<c1050000>] ? cpuset_can_attach+0x80/0x9b
[    2.426466]  [<c10591d3>] ? __setup_irq+0x1e7/0x272
[    2.426466]  [<c10592e5>] ? request_threaded_irq+0x87/0x135
[    2.426466]  [<c1059367>] ? request_threaded_irq+0x109/0x135
[    2.426466]  [<c1188c7d>] ? serial8250_interrupt+0x0/0xae
[    2.426466]  [<c11888e5>] ? serial8250_startup+0x43e/0x595
[    2.426466]  [<c1185834>] ? uart_startup+0x64/0xeb
[    2.426466]  [<c11859a9>] ? uart_open+0xee/0x29d
[    2.426466]  [<c116d9ce>] ? tty_ldisc_enable+0x2a/0x2c
[    2.426466]  [<c116da20>] ? tty_ldisc_setup+0x50/0x58
[    2.426466]  [<c1169e18>] ? tty_init_dev+0xf0/0x133
[    2.426466]  [<c116a0e6>] ? tty_open+0x28b/0x355
[    2.426466]  [<c1095aee>] ? chrdev_open+0xcb/0xe1
[    2.426466]  [<c10921f4>] ? __dentry_open+0x142/0x231
[    2.426466]  [<c1092373>] ? nameidata_to_filp+0x28/0x3b
[    2.426466]  [<c1095a23>] ? chrdev_open+0x0/0xe1
[    2.426466]  [<c109bbe7>] ? do_filp_open+0x423/0x7ba
[    2.426466]  [<c10268f4>] ? irq_exit+0x31/0x53
[    2.426466]  [<c1022b23>] ? vprintk+0x282/0x2a4
[    2.426466]  [<c10a301e>] ? alloc_fd+0x4a/0xac
[    2.426466]  [<c1091f86>] ? do_sys_open+0x48/0x115
[    2.426466]  [<c1092097>] ? sys_open+0x1e/0x23
[    2.426466]  [<c1001263>] ? init_post+0x27/0x138
[    2.426466]  [<c1366261>] ? kernel_init+0xde/0xe2
[    2.426466]  [<c1366183>] ? kernel_init+0x0/0xe2
[    2.426466]  [<c1003997>] ? kernel_thread_helper+0x7/0x10
[    2.426466] handlers:
[    2.426466] [<c1188c7d>] (serial8250_interrupt+0x0/0xae)
[    2.426466] Disabling IRQ #4
[    2.482791] udev: starting version 158
Loading, please wait...
[    2.736371] SCSI subsystem initialized
[    2.761788] e100: Intel(R) PRO/100 Network Driver, 3.5.24-k2-NAPI
[    2.764062] e100: Copyright(c) 1999-2006 Intel Corporation
[    2.790782] e100 0000:00:05.0: PME# disabled
[    2.834810] e100: eth0: e100_probe: addr 0xc0000000, irq 9, MAC addr 00:01:21:b0:12:aa
[    2.860762] e100 0000:00:06.0: PME# disabled
[    2.872934] usbcore: registered new interface driver usbfs
[    2.970226] usbcore: registered new interface driver hub
[    2.974958] usbcore: registered new device driver usb
[    2.984602] e100: eth1: e100_probe: addr 0xc0040000, irq 6, MAC addr 00:01:21:b0:12:a9
[    3.014881] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver
[    3.033226] scsi0 : ata_piix
[    3.039140] uhci_hcd: USB Universal Host Controller Interface driver
[    3.046207] scsi1 : ata_piix
[    3.050170] ata1: PATA max UDMA/33 cmd 0x1f0 ctl 0x3f6 bmdma 0xf400 irq 14
[    3.051705] ata2: PATA max UDMA/33 cmd 0x170 ctl 0x376 bmdma 0xf408 irq 15
[    3.056727] uhci_hcd 0000:00:07.2: UHCI Host Controller
[    3.061167] uhci_hcd 0000:00:07.2: new USB bus registered, assigned bus number 1
[    3.064364] uhci_hcd 0000:00:07.2: irq 11, io base 0x0000f000
[    3.068713] usb usb1: New USB device found, idVendor=1d6b, idProduct=0001
[    3.073045] usb usb1: New USB device strings: Mfr=3, Product=2, SerialNumber=1
[    3.077036] usb usb1: Product: UHCI Host Controller
[    3.081265] usb usb1: Manufacturer: Linux 2.6.32-5-486 uhci_hcd
[    3.085259] usb usb1: SerialNumber: 0000:00:07.2
[    3.091662] usb usb1: configuration #1 chosen from 1 choice
[    3.096596] hub 1-0:1.0: USB hub found
[    3.100357] hub 1-0:1.0: 2 ports detected
[    3.218849] ata1.00: CFA: CF 2GB, 20101028, max UDMA/66
[    3.226535] ata1.00: 3931200 sectors, multi 0: LBA 
[    3.246998] ata1.00: configured for UDMA/33
[    3.251809] scsi 0:0:0:0: Direct-Access     ATA      CF 2GB           2010 PQ: 0 ANSI: 5
[    3.301613] sd 0:0:0:0: [sda] 3931200 512-byte logical blocks: (2.01 GB/1.87 GiB)
[    3.304841] sd 0:0:0:0: [sda] Write Protect is off
[    3.308028] sd 0:0:0:0: [sda] Write cache: disabled, read cache: enabled, doesn't support DPO or FUA
[    3.311196]  sda:
[   34.180314] ata1: lost interrupt (Status 0x50)
[   34.186184] ata1.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen
[   34.191290] ata1.00: failed command: READ DMA
[   34.195278] ata1.00: cmd c8/00:08:00:00:00/00:00:00:00:00/e0 tag 0 dma 4096 in
[   34.195278]          res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
[   34.200079] ata1.00: status: { DRDY }
[   34.204071] ata1: soft resetting link
[   34.384515] ata1.00: configured for UDMA/33
[   34.389044] ata1.00: device reported invalid CHS sector 0
[   34.393216] ata1: EH complete
[   65.182074] ata1: lost interrupt (Status 0x50)
[   65.187400] ata1.00: limiting speed to UDMA/25:PIO4
[   65.194006] ata1.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen
[   65.197996] ata1.00: failed command: READ DMA
[   65.200160] ata1.00: cmd c8/00:08:00:00:00/00:00:00:00:00/e0 tag 0 dma 4096 in
[   65.200164]          res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
[   65.204140] ata1.00: status: { DRDY }
[   65.207889] ata1: soft resetting link
[   65.390278] ata1.00: configured for UDMA/25
[   65.394805] ata1.00: device reported invalid CHS sector 0
[   65.398976] ata1: EH complete
[   96.183841] ata1: lost interrupt (Status 0x50)
[   96.189164] ata1.00: limiting speed to PIO4
[   96.193689] ata1.00: exception Emask 0x0 SAct 0x0 SErr 0x0 action 0x6 frozen
[   96.198791] ata1.00: failed command: READ DMA
[   96.202781] ata1.00: cmd c8/00:08:00:00:00/00:00:00:00:00/e0 tag 0 dma 4096 in
[   96.202781]          res 40/00:00:00:00:00/00:00:00:00:00/00 Emask 0x4 (timeout)
[   96.207584] ata1.00: status: { DRDY }
[   96.211575] ata1: soft resetting link
[   96.392045] ata1.00: configured for PIO4
[   96.399789] ata1.00: device reported invalid CHS sector 0
[   96.403779] ata1: EH complete
[   96.405930]  sda1 sda2 sda3 sda4
[   96.418256] sd 0:0:0:0: [sda] Attached SCSI disk
Begin: Loading e[   96.737981] EXT3-fs: INFO: recovery required on readonly filesystem.
[   96.741868] EXT3-fs: write access will be enabled during recovery.
ssential drivers ... done.
Begi[   96.998059] kjournald starting.  Commit interval 5 seconds
[   97.002521] EXT3-fs: recovery complete.
[   97.021072] EXT3-fs: mounted filesystem with ordered data mode.
n: Running /scripts/init-premount ... done.
Begin: Mounting root file system ... Begin: Running /scripts/local-top ... done.
Begin: Running /scripts/local-premount ... done.
Begin: Running /scripts/local-bottom ... done.
done.
Begin: Running /scripts/init-bottom ... done.
[   99.245499] irq 4: nobody cared (try booting with the "irqpoll" option)
[   99.247983] Pid: 1, comm: init Not tainted 2.6.32-5-486 #1
[   99.247983] Call Trace:
[   99.247983]  [<c105975c>] ? __report_bad_irq+0x24/0x69
[   99.247983]  [<c1059763>] ? __report_bad_irq+0x2b/0x69
[   99.247983]  [<c1059886>] ? note_interrupt+0xe5/0x13b
[   99.247983]  [<c1059de5>] ? handle_level_irq+0x52/0x83
[   99.247983]  [<c1004507>] ? handle_irq+0x17/0x1c
[   99.247983]  [<c10041d6>] ? do_IRQ+0x2b/0x76
[   99.247983]  [<c1003790>] ? common_interrupt+0x30/0x40
[   99.247983]  [<c103007b>] ? current_is_keventd+0xe/0x1f
[   99.247983]  [<c10266fb>] ? __do_softirq+0x32/0x130
[   99.247983]  [<c1026829>] ? do_softirq+0x30/0x3b
[   99.247983]  [<c10268e8>] ? irq_exit+0x25/0x53
[   99.247983]  [<c1004211>] ? do_IRQ+0x66/0x76
[   99.247983]  [<c1003790>] ? common_interrupt+0x30/0x40
[   99.247983]  [<c1050000>] ? cpuset_can_attach+0x80/0x9b
[   99.247983]  [<c10591d3>] ? __setup_irq+0x1e7/0x272
[   99.247983]  [<c10592e5>] ? request_threaded_irq+0x87/0x135
[   99.247983]  [<c1059367>] ? request_threaded_irq+0x109/0x135
[   99.247983]  [<c1188c7d>] ? serial8250_interrupt+0x0/0xae
[   99.247983]  [<c11888e5>] ? serial8250_startup+0x43e/0x595
[   99.247983]  [<c1185834>] ? uart_startup+0x64/0xeb
[   99.247983]  [<c11859a9>] ? uart_open+0xee/0x29d
[   99.247983]  [<c116d9ce>] ? tty_ldisc_enable+0x2a/0x2c
[   99.247983]  [<c116da20>] ? tty_ldisc_setup+0x50/0x58
[   99.247983]  [<c1169e18>] ? tty_init_dev+0xf0/0x133
[   99.247983]  [<c116a0e6>] ? tty_open+0x28b/0x355
[   99.247983]  [<c1095aee>] ? chrdev_open+0xcb/0xe1
[   99.247983]  [<c10921f4>] ? __dentry_open+0x142/0x231
[   99.247983]  [<c1092373>] ? nameidata_to_filp+0x28/0x3b
[   99.247983]  [<c1095a23>] ? chrdev_open+0x0/0xe1
[   99.247983]  [<c109bbe7>] ? do_filp_open+0x423/0x7ba
[   99.247983]  [<c107f1fe>] ? handle_mm_fault+0x34b/0x714
[   99.247983]  [<c10a301e>] ? alloc_fd+0x4a/0xac
[   99.247983]  [<c1091f86>] ? do_sys_open+0x48/0x115
[   99.247983]  [<c1092097>] ? sys_open+0x1e/0x23
[   99.247983]  [<c100314c>] ? syscall_call+0x7/0xb
[   99.247983] handlers:
[   99.247983] [<c1188c7d>] (serial8250_interrupt+0x0/0xae)
[   99.247983] Disabling IRQ #4
[   99.758802] irq 4: nobody cared (try booting with the "irqpoll" option)
[   99.760013] Pid: 1, comm: init Not tainted 2.6.32-5-486 #1
[   99.760013] Call Trace:
[   99.760013]  [<c105975c>] ? __report_bad_irq+0x24/0x69
[   99.760013]  [<c1059763>] ? __report_bad_irq+0x2b/0x69
[   99.760013]  [<c1059886>] ? note_interrupt+0xe5/0x13b
[   99.760013]  [<c1059de5>] ? handle_level_irq+0x52/0x83
[   99.760013]  [<c1004507>] ? handle_irq+0x17/0x1c
[   99.760013]  [<c10041d6>] ? do_IRQ+0x2b/0x76
[   99.760013]  [<c1003790>] ? common_interrupt+0x30/0x40
[   99.760013]  [<c103007b>] ? current_is_keventd+0xe/0x1f
[   99.760013]  [<c10266fb>] ? __do_softirq+0x32/0x130
[   99.760013]  [<c1026829>] ? do_softirq+0x30/0x3b
[   99.760013]  [<c10268e8>] ? irq_exit+0x25/0x53
[   99.760013]  [<c1004211>] ? do_IRQ+0x66/0x76
[   99.760013]  [<c1003790>] ? common_interrupt+0x30/0x40
[   99.760013]  [<c1050000>] ? cpuset_can_attach+0x80/0x9b
[   99.760013]  [<c10591d3>] ? __setup_irq+0x1e7/0x272
[   99.760013]  [<c10592e5>] ? request_threaded_irq+0x87/0x135
[   99.760013]  [<c1059367>] ? request_threaded_irq+0x109/0x135
[   99.760013]  [<c1188c7d>] ? serial8250_interrupt+0x0/0xae
[   99.760013]  [<c11888e5>] ? serial8250_startup+0x43e/0x595
[   99.760013]  [<c1185834>] ? uart_startup+0x64/0xeb
[   99.760013]  [<c11859a9>] ? uart_open+0xee/0x29d
[   99.760013]  [<c116d9ce>] ? tty_ldisc_enable+0x2a/0x2c
[   99.760013]  [<c116da20>] ? tty_ldisc_setup+0x50/0x58
[   99.760013]  [<c1169e18>] ? tty_init_dev+0xf0/0x133
[   99.760013]  [<c116a0e6>] ? tty_open+0x28b/0x355
[   99.760013]  [<c1095aee>] ? chrdev_open+0xcb/0xe1
[   99.760013]  [<c10921f4>] ? __dentry_open+0x142/0x231
[   99.760013]  [<c1092373>] ? nameidata_to_filp+0x28/0x3b
[   99.760013]  [<c1095a23>] ? chrdev_open+0x0/0xe1
[   99.760013]  [<c109bbe7>] ? do_filp_open+0x423/0x7ba
[   99.760013]  [<c107f1fe>] ? handle_mm_fault+0x34b/0x714
[   99.760013]  [<c10a301e>] ? alloc_fd+0x4a/0xac
[   99.760013]  [<c1091f86>] ? do_sys_open+0x48/0x115
[   99.760013]  [<c1092097>] ? sys_open+0x1e/0x23
[   99.760013]  [<c100314c>] ? syscall_call+0x7/0xb
[   99.760013] handlers:
[   99.760013] [<c1188c7d>] (serial8250_interrupt+0x0/0xae)
[   99.760013] Disabling IRQ #4

INIT: [  100.369535] irq 4: nobody cared (try booting with the "irqpoll" option)
[  100.372048] Pid: 1, comm: init Not tainted 2.6.32-5-486 #1
[  100.372048] Call Trace:
[  100.372048]  [<c105975c>] ? __report_bad_irq+0x24/0x69
[  100.372048]  [<c1059763>] ? __report_bad_irq+0x2b/0x69
[  100.372048]  [<c1059886>] ? note_interrupt+0xe5/0x13b
[  100.372048]  [<c1059de5>] ? handle_level_irq+0x52/0x83
[  100.372048]  [<c1004507>] ? handle_irq+0x17/0x1c
[  100.372048]  [<c10041d6>] ? do_IRQ+0x2b/0x76
[  100.372048]  [<c1003790>] ? common_interrupt+0x30/0x40
[  100.372048]  [<c10266fb>] ? __do_softirq+0x32/0x130
[  100.372048]  [<c1026829>] ? do_softirq+0x30/0x3b
[  100.372048]  [<c10268e8>] ? irq_exit+0x25/0x53
[  100.372048]  [<c1004211>] ? do_IRQ+0x66/0x76
[  100.372048]  [<c1003790>] ? common_interrupt+0x30/0x40
[  100.372048]  [<c1050000>] ? cpuset_can_attach+0x80/0x9b
[  100.372048]  [<c10591d3>] ? __setup_irq+0x1e7/0x272
[  100.372048]  [<c10592e5>] ? request_threaded_irq+0x87/0x135
[  100.372048]  [<c1059367>] ? request_threaded_irq+0x109/0x135
[  100.372048]  [<c1188c7d>] ? serial8250_interrupt+0x0/0xae
[  100.372048]  [<c11888e5>] ? serial8250_startup+0x43e/0x595
[  100.372048]  [<c1185834>] ? uart_startup+0x64/0xeb
[  100.372048]  [<c11859a9>] ? uart_open+0xee/0x29d
[  100.372048]  [<c116d9ce>] ? tty_ldisc_enable+0x2a/0x2c
[  100.372048]  [<c116da20>] ? tty_ldisc_setup+0x50/0x58
[  100.372048]  [<c1169e18>] ? tty_init_dev+0xf0/0x133
[  100.372048]  [<c116a0e6>] ? tty_open+0x28b/0x355
[  100.372048]  [<c1095aee>] ? chrdev_open+0xcb/0xe1
[  100.372048]  [<c10921f4>] ? __dentry_open+0x142/0x231
[  100.372048]  [<c1092373>] ? nameidata_to_filp+0x28/0x3b
[  100.372048]  [<c1095a23>] ? chrdev_open+0x0/0xe1
[  100.372048]  [<c109bbe7>] ? do_filp_open+0x423/0x7ba
[  100.372048]  [<c1169c5a>] ? tty_release_dev+0x387/0x3b3
[  100.372048]  [<c10a301e>] ? alloc_fd+0x4a/0xac
[  100.372048]  [<c1091f86>] ? do_sys_open+0x48/0x115
[  100.372048]  [<c1092097>] ? sys_open+0x1e/0x23
[  100.372048]  [<c100314c>] ? syscall_call+0x7/0xb
[  100.372048] handlers:
[  100.372048] [<c1188c7d>] (serial8250_interrupt+0x0/0xae)
[  100.372048] Disabling IRQ #4
version 2.88 booting[  101.081574] irq 4: nobody cared (try booting with the "irqpoll" option)
[  101.084090] Pid: 1, comm: init Not tainted 2.6.32-5-486 #1
[  101.084090] Call Trace:
[  101.084090]  [<c105975c>] ? __report_bad_irq+0x24/0x69
[  101.084090]  [<c1059763>] ? __report_bad_irq+0x2b/0x69
[  101.084090]  [<c1059886>] ? note_interrupt+0xe5/0x13b
[  101.084090]  [<c1059de5>] ? handle_level_irq+0x52/0x83
[  101.084090]  [<c1004507>] ? handle_irq+0x17/0x1c
[  101.084090]  [<c10041d6>] ? do_IRQ+0x2b/0x76
[  101.084090]  [<c1003790>] ? common_interrupt+0x30/0x40
[  101.084090]  [<c10266fb>] ? __do_softirq+0x32/0x130
[  101.084090]  [<c1026829>] ? do_softirq+0x30/0x3b
[  101.084090]  [<c10268e8>] ? irq_exit+0x25/0x53
[  101.084090]  [<c1004211>] ? do_IRQ+0x66/0x76
[  101.084090]  [<c1003790>] ? common_interrupt+0x30/0x40
[  101.084090]  [<c1050000>] ? cpuset_can_attach+0x80/0x9b
[  101.084090]  [<c10591d3>] ? __setup_irq+0x1e7/0x272
[  101.084090]  [<c10592e5>] ? request_threaded_irq+0x87/0x135
[  101.084090]  [<c1059367>] ? request_threaded_irq+0x109/0x135
[  101.084090]  [<c1188c7d>] ? serial8250_interrupt+0x0/0xae
[  101.084090]  [<c11888e5>] ? serial8250_startup+0x43e/0x595
[  101.084090]  [<c1185834>] ? uart_startup+0x64/0xeb
[  101.084090]  [<c11859a9>] ? uart_open+0xee/0x29d
[  101.084090]  [<c116d9ce>] ? tty_ldisc_enable+0x2a/0x2c
[  101.084090]  [<c116da20>] ? tty_ldisc_setup+0x50/0x58
[  101.084090]  [<c1169e18>] ? tty_init_dev+0xf0/0x133
[  101.084090]  [<c116a0e6>] ? tty_open+0x28b/0x355
[  101.084090]  [<c1095aee>] ? chrdev_open+0xcb/0xe1
[  101.084090]  [<c10921f4>] ? __dentry_open+0x142/0x231
[  101.084090]  [<c1092373>] ? nameidata_to_filp+0x28/0x3b
[  101.084090]  [<c1095a23>] ? chrdev_open+0x0/0xe1
[  101.084090]  [<c109bbe7>] ? do_filp_open+0x423/0x7ba
[  101.084090]  [<c1169c5a>] ? tty_release_dev+0x387/0x3b3
[  101.084090]  [<c10a301e>] ? alloc_fd+0x4a/0xac
[  101.084090]  [<c1091f86>] ? do_sys_open+0x48/0x115
[  101.084090]  [<c1092097>] ? sys_open+0x1e/0x23
[  101.084090]  [<c100314c>] ? syscall_call+0x7/0xb
[  101.084090] handlers:
[  101.084090] [<c1188c7d>] (serial8250_interrupt+0x0/0xae)
[  101.084090] Disabling IRQ #4


[  101.696594] irq 4: nobody cared (try booting with the "irqpoll" option)
[  101.700125] Pid: 127, comm: init Not tainted 2.6.32-5-486 #1
[  101.700125] Call Trace:
[  101.700125]  [<c105975c>] ? __report_bad_irq+0x24/0x69
[  101.700125]  [<c1059763>] ? __report_bad_irq+0x2b/0x69
[  101.700125]  [<c1059886>] ? note_interrupt+0xe5/0x13b
[  101.700125]  [<c1059de5>] ? handle_level_irq+0x52/0x83
[  101.700125]  [<c1004507>] ? handle_irq+0x17/0x1c
[  101.700125]  [<c10041d6>] ? do_IRQ+0x2b/0x76
[  101.700125]  [<c1003790>] ? common_interrupt+0x30/0x40
[  101.700125]  [<c10266fb>] ? __do_softirq+0x32/0x130
[  101.700125]  [<c1026829>] ? do_softirq+0x30/0x3b
[  101.700125]  [<c10268e8>] ? irq_exit+0x25/0x53
[  101.700125]  [<c1004211>] ? do_IRQ+0x66/0x76
[  101.700125]  [<c1003790>] ? common_interrupt+0x30/0x40
[  101.700125]  [<c1050000>] ? cpuset_can_attach+0x80/0x9b
[  101.700125]  [<c10591d3>] ? __setup_irq+0x1e7/0x272
[  101.700125]  [<c10592e5>] ? request_threaded_irq+0x87/0x135
[  101.700125]  [<c1059367>] ? request_threaded_irq+0x109/0x135
[  101.700125]  [<c1188c7d>] ? serial8250_interrupt+0x0/0xae
[  101.700125]  [<c11888e5>] ? serial8250_startup+0x43e/0x595
[  101.700125]  [<c1185834>] ? uart_startup+0x64/0xeb
[  101.700125]  [<c11859a9>] ? uart_open+0xee/0x29d
[  101.700125]  [<c116d9ce>] ? tty_ldisc_enable+0x2a/0x2c
[  101.700125]  [<c116da20>] ? tty_ldisc_setup+0x50/0x58
[  101.700125]  [<c1169e18>] ? tty_init_dev+0xf0/0x133
[  101.700125]  [<c116a0e6>] ? tty_open+0x28b/0x355
[  101.700125]  [<c1095aee>] ? chrdev_open+0xcb/0xe1
[  101.700125]  [<c10921f4>] ? __dentry_open+0x142/0x231
[  101.700125]  [<c1092373>] ? nameidata_to_filp+0x28/0x3b
[  101.700125]  [<c1095a23>] ? chrdev_open+0x0/0xe1
[  101.700125]  [<c109bbe7>] ? do_filp_open+0x423/0x7ba
[  101.700125]  [<c107f1fe>] ? handle_mm_fault+0x34b/0x714
[  101.700125]  [<c10a301e>] ? alloc_fd+0x4a/0xac
[  101.700125]  [<c1091f86>] ? do_sys_open+0x48/0x115
[  101.700125]  [<c1092097>] ? sys_open+0x1e/0x23
[  101.700125]  [<c100314c>] ? syscall_call+0x7/0xb
[  101.700125] handlers:
[  101.700125] [<c1188c7d>] (serial8250_interrupt+0x0/0xae)
[  101.700125] Disabling IRQ #4
Using makefile-style concurrent boot in runlevel[  102.132067] udev: starting version 158
 S.
Starting the hotplug events dispatcher: udevd.
Synthesizing the initial hotplug events...done.
Waiting fo[  102.823592] input: PC Speaker as /devices/platform/pcspkr/input/input0
r /dev to be ful[  102.948874] piix4_smbus 0000:00:07.3: SMBus Host Controller at 0x10a0, revision 0
ly populated...[  103.158045] Error: Driver 'pcspkr' is already registered, aborting...
done.
Activating swap...done.
[  103.426906] EXT3 FS on sda2, internal journal
Checking root fi[  103.581612] loop: module loaded
le system...fsck from util-linux-ng 2.17.2
/dev/sda2: clean, 47587/61440 files, 205847/245760 blocks
done.
Cleaning up ifupdown....
Loading kernel modules..
INIT: Entering runlevel: 2

Using makefile-style concurrent boot in runlevel 2.
Starting NFS common utilities: statd.
Starting advanced IEEE 802.11 management: hostapdrmd[  105.645794] Open vSwitch 1.1.0pre2, built Nov 17 2010 05:20:29
ir[ctrl_interfac[  105.730022] device dp0 entered promiscuous mode
e]: No such file[  105.874069] e100 0000:00:05.0: firmware: requesting e100/d101s_ucode.bin
 or directory
 [  105.915101] e100: eth0: e100_request_firmware: Failed to load firmware "e100/d101s_ucode.bin": -2
[  105.947099] device eth0 entered promiscuous mode
[  105.970023] e100 0000:00:05.0: firmware: requesting e100/d101s_ucode.bin
[  105.980922] e100: eth0: e100_request_firmware: Failed to load firmware "e100/d101s_ucode.bin": -2
^[[31mfailed!^[[39;49m
APTYPE 0 OF_UPLINK_IF=eth0
Starting portmap daemon...Already running..
Starting enhancedApr 01 06:45:56|00006|rconn|INFO|dp0<->tcp:172.27.74.152:6634: connection timed out
Apr 01 06:45:56|00007|rconn|INFO|dp0<->tcp:172.27.74.152:6634: waiting 1 seconds before reconnect

Apr 01 06:45:57|00008|rconn|INFO|dp0<->tcp:172.27.74.152:6634: connecting...
Debian GNU/Linux squeeze/sid openflow-ap ttyS0

Apr 01 06:45:58|00009|rconn|INFO|dp0<->tcp:172.27.74.152:6634: connection timed out
Apr 01 06:45:58|00010|rconn|INFO|dp0<->tcp:172.27.74.152:6634: waiting 2 seconds before reconnect
openflow-ap login: Apr 01 06:46:00|00011|rconn|INFO|dp0<->tcp:172.27.74.152:6634: connecting...
Apr 01 06:46:02|00012|rconn|INFO|dp0<->tcp:172.27.74.152:6634: connection timed out
Apr 01 06:46:02|00013|rconn|INFO|dp0<->tcp:172.27.74.152:6634: waiting 4 seconds before reconnect
Apr 01 06:46:06|00014|rconn|INFO|dp0<->tcp:172.27.74.152:6634: connecting...
Apr 01 06:46:06|00015|rconn|INFO|dp0<->tcp:172.27.74.152:6634: connection failed (No route to host)
Apr 01 06:46:06|00016|rconn|INFO|dp0<->tcp:172.27.74.152:6634: continuing to retry connections in the background but suppressing further logging
Apr 01 06:46:10|00017|fail_open|WARN|Could not connect to controller (or switch failed controller's post-connection admission control policy) for 15 seconds, failing open

Debian GNU/Linux squeeze/sid openflow-ap ttyS0

FreeBSD in FUSE : だいたいの流れメモ

AsiaBSDCon2012 3日目 P6A: FUSE and FreeBSDなるセッションを受けて、FUSEの内部実装を追いかける気力が(FreeBSDに関しては)復活したので軽く流れを追いかけて見るテスト。

対象となるコードは下記のパッチ

RFC: FUSE kernel module for the kernel...
http://lists.freebsd.org/pipermail/freebsd-current/2012-March/032374.html

※ なお、上記パッチは2012/3/8に投稿されたものでありその後RFCへの応答によっては一部書き換わっている可能性があります。


一番の興味がカーネル <-> ユーザランドの通信部分なので、そこのフローを重点的に書き起こしてみる。シナリオはユーザプロセスが、FUSEで作られたファイルシステム(実体はユーザランドのデーモンプロセス)からデータをreadするときにどういうパスをたどるか。基本的な条件として、readはO_DIRECTフラグ付きであると仮定(おいかけるの楽だから)。

エセ・シーケンス図でなんとなく書いてみるとこんな感じ？

ユーザからのI/Oが発生した際はこれをキューに詰み待機、デーモン側での/dev/fuse*へのread時にこれを取得、writeで応答してたたき起こすというフローらしい。

メモ: 9front MP Kernel panics on KVM

MP対応な9frontカーネル様がKVM環境でブート時にパニックしたのでメモ。
ここでは手前でコンパイルして配置したpcfカーネルを利用。
pccpufカーネルだと引っかからないらしい。
実機試験はPlan 9の方のみ実施。こちらではpcfカーネルでもきちんと動くようだ (結局別のところでおかしくなったけど)



再現方法 (またはMP対応有効化)
通常、MP対応は無効になっているのでブート時にこれを有効にする必要がある。
例の如くplan9.iniに設定を突っ込めばいい。
9front向けplan9.iniのマニュアルによると以下のオプション行が必要とのこと。
既に記述はあるが、1 (=無効)になっているので0 (=有効)にする必要がある。

*nomp=
          A multiprocessor machine will enable all processors by
          default.  Setting *nomp restricts the kernel to starting
          only one processor and using the traditional interrupt con-
          troller.

ブートコンフィグたるplan9.iniは9fat領域に納められている。
Plan 9ではここをマウントする時には以下のコマンドを使っていた。ところがこれは9frontでは存在しない。

term% 9fat:

そのかわりに9fsコマンドを使って/n/9fat/の位置にマウントする。

term% 9fs 9fat


この状態でKVMで起動すると以下のようにパニックする。

cpu0: 3193MHz Genuine Intel Atom (cpuid: AX 0x106C2 DX 0xFCBFBF9)
....
panic: lapic clock 999812570 > cpu clock > 205454592

追っかけ
dumpstackなんてまるっきり読めないので, panicメッセージを手がかりに
落ちている場所をさがしてみる。以下の関数の155行目らしい。

/sys/src/9/pc/apic.c
129 /*
130  *  use the i8253 clock to figure out our lapic timer rate.
131  */
132 static void
133 lapictimerinit(void)                                                                                                                                                                                                           
134 {
135         uvlong x, v, hz;
136 
137         v = m->cpuhz/1000;
138         lapicw(LapicTDCR, LapicX1);
139         lapicw(LapicTIMER, ApicIMASK|LapicCLKIN|LapicONESHOT|(VectorPIC+IrqTIMER));
140 
141         if(lapictimer.hz == 0ULL){
142                 x = fastticks(&hz);
143                 x += hz/10;
144                 lapicw(LapicTICR, 0xffffffff);
145                 do{
146                         v = fastticks(nil);
147                 }while(v < x);
148 
149                 lapictimer.hz = (0xffffffffUL-lapicr(LapicTCCR))*10;
150                 lapictimer.max = lapictimer.hz/HZ;
151                 lapictimer.min = lapictimer.hz/(100*HZ);
152 
153                 if(lapictimer.hz > hz-(hz/10)){
154                         if(lapictimer.hz > hz+(hz/10))
155                                 panic("lapic clock %lld > cpu clock > %lld\n",
156                                         lapictimer.hz, hz);
157                         lapictimer.hz = hz;
158                 }
159                 lapictimer.div = hz/lapictimer.hz;
160         }
161 }

Local APIC Timerのクロックレートを調べているらしい。
手順としては以下の流れになっている。

  1. lapicタイマの初期値を0xffffffffに設定
  2. fastticks()を使って100msecの間ループ
  3. lapicタイマの現在値と初期値との差分計算、lapicタイマのクロックレートの計算
  4. hz (= cpu clock ? )と比べる
  5. 落ちる

改めてパニック時に出力されているlapictimer.hzとhzを眺めてみる

lapic clock = lapictimer.hz = 999812570 = 999MHz
cpu clock = hz = 205454592 = 205MHz

あきらかにCPUのクロックレートじゃないよね... 上に3192MHzって出てるし...
それもそのはずで、関数の上のコメントにもあるようにここでfastticks()を用いて
取得できるhzにはi8253、つまりPITのクロックレートが渡されるようだ。
i8253はだいたい200MHzなのでまさにそうなっている模様。



panic()の中身を信じるならばここにはcpuのクロックレートが入っているハズだが....
どうも単純に比較先を間違えているのか、何かクロック周りを間違えているのか。
あるいはKVM環境だとlapic clock周りで特殊な事情があるのでわ！？とも考えられる。
local apicのクロックレートの適正値とかよくわからない。ここらへんは実機で試して見ないとなんとも。


とりあえず比較対象をhzから、m->cpuhz(CPUのクロックレートが入っているはず)に
変えたところ、正常に起動するのを確認。
コードの変更はこんな感じ : https://github.com/enukane/9front-work/commit/79807778262f3f7ec174a4ca97f1c99a5138e010
果たして同じコードで実機動作するのか。

とりあえずこれでMSI周りを叩けるようになりましたとさ。



補足：fastticks() ?
pccpufカーネルだと引っかからないという当たりが腑に落ちないので少し中身を追いかけてみた。対象はfastticks()。

/sys/src/9/pc/devarch.c
1039 /*
1040  *  return value and speed of timer set in arch->clockenable
1041  */
1042 uvlong
1043 fastticks(uvlong *hz)                                                                                                                                                                                                         
1044 {
1045         return (*arch->fastclock)(hz);
1046 }

通常、x86アーキテクチャにてfastclockはi8253のクロックレートを参照している。
これはMPカーネルでも同様で、archの中身は以下のようになっている。

59 PCArch archmp = {
60 .id= "_MP_",
61 .ident= identify,
62 .reset= mpshutdown,
63 .intrinit= mpinit,
64 .intrenable= mpintrenable,
65 .intron= lapicintron,
66 .introff= lapicintroff,
67 .fastclock= i8253read,
68 .timerset= lapictimerset,
69 };

i8253read()ではではクロックレートを引数hzのアドレスに突っ込んで返す。
これを用いて先ほどのhz≒200MHzを取得している。これが一般的なフロー。

ところが、場合によってはこの部分が書き換わる。

/sys/src/9/pc/archmp.c
 71 static int
 72 identify(void)
 73 {
 74         char *cp;
 75         PCMP *pcmp;
 76         uchar *p, sum;
 77         ulong length;
 78 
 79         if((cp = getconf("*nomp")) != nil && strtol(cp, 0, 0) != 0)
 80                 return 1;
 81 
 82         /*
 83          * Search for an MP configuration table. For now,
 84          * don't accept the default configurations (physaddr == 0).
 85          * Check for correct signature, calculate the checksum and,
 86          * if correct, check the version.
 87          * To do: check extended table checksum.
 88          */
 89         if((_mp_ = mpsearch()) == 0 || _mp_->physaddr == 0)
 90                 return 1;
 91 
 92         pcmp = KADDR(_mp_->physaddr);
 93         if(memcmp(pcmp, "PCMP", 4))
 94                 return 1;
 95 
 96         length = pcmp->length;
 97         sum = 0;
 98         for(p = (uchar*)pcmp; length; length--)                                                                                                                                                                                
 99                 sum += *p++;
100 
101         if(sum || (pcmp->version != 1 && pcmp->version != 4))
102                 return 1;
103 
104         if(cpuserver && m->havetsc)
105                 archmp.fastclock = tscticks;
106         return 0;
107 }

上記104行目で、cpuserverかつTSCが有効な場合にtsticks()とかいう関数に置き換わる。
cpuserverはpccpufカーネルの時有効。
tscticks()は以下に挙げてあるように、CPUのクロックレートそのもので動作する。

/sys/src/9/pc/archmp.c
131 uvlong
132 tscticks(uvlong *hz)
133 {
134         if(hz != nil)
135                 *hz = m->cpuhz;
136 
137         cycles(&m->tscticks);   /* Uses the rdtsc instruction */                                                                                                                                   
138         return m->tscticks;
139 }

これなら比較されても大丈夫だったね！ ってかわざわざcpuserverに限定するのはどうしてなんだ...

カーネル/VM Advent Calendar 8日目 : Plan9で作るお手軽 Packet Recorder & Generator　　　　　　　の予定でしたorz

この記事はカーネル/VM Advent Calendar2011のためにかかれたものです。

前回に引き続き今年もPlan 9なネタでいきたいと思います。


が、残念ながら完成までこぎ着けられなかったので、出来たあたりまでのお話をしたいと思います
m(_ _)m


''ことのあらまし''
ネットワーク周りを弄っていると、いろいろなテストを目的として出来る限りのトラフィックを流したいという場合があります。えっ、ないって？

OKANEMOCHIならトラフィックジェネレータ箱を買って云々といった事も考えられます。しかし我々貧乏人はiperf、flood ping、tcpreplayなどのソフトウェアに頼るしかありません。とはいえこれらのソフトは9には無かったりといろいろ困ったものです。

また、iperfやpingについてはあくまで計測用のトラフィックでありそれっぽい多彩な(どんなだ)パケットが流れないといった懸念もあります。さらに、ネットワークをいぢめぬくという観点では, トラフィックレコードを利用するにあたってもいくつか工夫が必要です。

そこで今回は, 9向けに簡単なトラフィックレコーダ&負荷発生向けパケットジェネレータを作ってみます。出来る限り全力でパケットを投げつけるために、試しにドライバレベルでこれを行ってみました。


''環境''
ドライバレベルで、という制約のためどこでも動くという訳にはいきません。今回はPlan 9用実験マシンとして使っているThinkpad X60を用います。
この子にはNICとしてintelの82573が載っています。ちょうど良い具合にPlan 9ではこの82573向けのドライバがether82563.cとして用意されているので、これを改造するところから始めます。


''ぼくの考えたさいきょーのぱけっとじぇねれーた in 9''
ドライバレベルのパケットジェネレータということで、ここでは以下のような運用モデルを考えます。Plan 9なのでもちろんインタフェイスはファイルです

  1. "echo rec > packetgencmd" でパケットのレコード開始
  2. 適当に通信をしてトラフィックを流す
  3. "echo recstop > packetgencmd"でパケットのレコード終了
  4. "echo start > packetgencmd"で記録したパケットを全力で送信開始
  5. いぢめる
  6. "echo stop > packetgencmd"でパケットの送信を終了


''やってみる''
今回のそれはいろいろてきとーな実装なのでいくつか制限があります。

  1. 記録は128個まで! recstopはなし! 一杯になったら上書き! ジェネレート開始しても自動終了!
  2. パケットの送信は何らかの通信を契機に開始!
  3. 全部 on memory! きちんとしたメモリの考慮なにそれおいしいの

いろいろと屑いですがまぁなんとかやってみましょう

目的として、出来る限り全力でパケットを送り続けて貰いたいわけですが、ひとまず送信処理を継続して行い続けるあたりから始めてみます。


''ドライバの中身''
ドライバのソース自体はここにあります.

主な変更点は以下の3つです。

  • レコード&ジェネレートの操作インタフェイス追加
  • ドライバ側の送信処理での、キューが空の場合の動作
  • ドライバ側の送信済みデータの扱い


''使い方''
まずはソースを落としてきましょう。これはpc(x86)向けのドライバなので/sys/src/9/pc以下にコピーします。

次にカーネルのコンフィグファイルを編集します。今回のデバイスドライバは''devpackgen''という名前なので''packgen''デバイスを/sys/src/9/pc/pcfに組み込むよう設定します。

さてカーネルをコンパイルしましょう. pcfカーネルなので、9pcfというイメージができあがっているハズです。

% cd /sys/src/9/pc
% mk 'CONF=pcf'
% ls 9pcf
9pcf

これを起動できるように設定します。ここでは起動時に, pg9pcfという名前で表示されるようにリネーム等を行っています。

% cd /sys/src/9/pc
[ 9fat領域 (カーネルイメージをしまっておく場所 ) を/n/9fat以下にマウント ] 
% 9fat:
% ls /n/9fat
....

[ 先ほど生成したカーネルをここにコピー (pg9pcfにリネーム) ]
% cp 9pcf /n/9fat/pg9pcf

[ 起動時に選択肢に現れるように/n/9fat/plan9.iniに以下の行を追加 ]
bootfile=sdC0!9fat!pg9pcf

カーネルの配置が終わったら再起動し、pg9pcfカーネルを起動します。



実際にレコード&ジェネレートをするには, packgenドライバをロードする必要があります。このために、まずこのデバイスのファイルツリーを適当な位置にマウントします。

% bind -a '#G' /mnt/pg
% ls /mnt/pg
/mnt/pg/packgencmd

これでドライバのロードが完了です。


''やってみた''
さて、実際に動かしてどんなものなのかみてみましょう。まずは以下のコマンドでパケットの記録を開始します。

% echo rec > /mnt/pg/packgencmd

その後、適当に通信をしてなんとなく記録した気分になりましょう。

次に実際にパケットのジェネレーションを開始します。

%echo start > /mnt/pg/packgencmd

これでパケットの送信を開始
といきたいところですが、パケット送出をキックする部分が送信処理の一部に組み込まれているため、ping一発程度を打ってやる必要があります。


現状、残念ながらある程度パケットを送り出した後にパニックするので使い物になりませんorz



お粗末様でした。



''終わりに''
アイディアをくださった@rshさんに感謝！

Storyline your Repository

ツール

見える化がトレンドな昨今、開発状況のそれをよりビビッドにやってくれる楽しいツールにevolinesというものがあります。
ここではその導入の仕方をメモっておきます。

必要なもの

  1. Processing
  2. Javaが使える環境
  3. JUNG (Java Universal Network/Graph Framework)
  4. そこそこ人が多くいそうなリポジトリの目処

それぞれProcessing, JUNGは公式ページからzipを落としてきて, 適当な場所に配置しておきます.

ライブラリとかの準備

まずはevolinesのソースを適当な場所に展開しましょう

% svn checkout http://evolines.googlecode.com/svn/trunk/ evolines-read-only

おそらくこんな感じのディレクトリツリーができあがっていることでしょう.

次にevolinesが利用しているJUNGを組み込むための手順が必要です.
Storylinesディレクトリの直下にcodeというディレクトリを作成し, そこにJUNGに含まれるjarファイルを突っ込みます.*1

リポジトリログの取得

よさげなリポジトリは見つけましたか？
ではそこからグラフを作るための材料になるログをゲットしましょう。
通常git log やsvn log等のコマンドでリポジトリのログが取得できると思いますが, これだと様々なVCSでばらばらのため非常にやりづらいです.
このやりづらさを解消し、一発でまとめてあつかうためのスクリプトがあります。evolinesの作者さんが別のプロジェクトで作っているものです*2. これを持ってきてログを整形します.
スクリプト自体は以下のURLにあるので適当に引っ張ってきましょう

% wget http://codeswarm.googlecode.com/svn/trunk/convert_logs/convert_logs.py


さて、ではログを採取します. ここではfrsyuki先生のmsgpackのリポジトリを試して見ます.

% git clone https://github.com/msgpack/msgpack.git
...
% cd msgpack
% git log --name-status --pretty=format:'%n------------------------------------------------------------------------ %nr%h | %ae | %ai (%aD) | x lines%nChanged paths:'  > ~/msgpack.log
% cd $HOME
% python convert_logs.py -g ~/msgpack.log -o ~/msgpack_log.xml

svnだと"svn log -v"ぐらいで済むのですが、gitだと少しオプションを調整してやる必要があるようです.
なおsvnの場合はconvert_logs.pyを実行する際に"-g"ではなく"-s"を用います.

コンフィグ

ログの採取が終わったら、あとはどのような出力をするか、を決めてやる必要があります.
先ほど展開したevolinesディレクトリ内のStorylines/config/sample.configを弄りましょう.
SVGで出力した方が楽しいのでここではこのための設定を記述しています. 他にもProcessing 上でインタラクティブに触ったり, PDFに出力したりといったことができます.
今回はこれくらいの設定で充分でしょう

ProjectName=msgpack

# Data input : 先ほどゲットしたXMLファイルへのパス
RepositoryFile=/path/to/msgpack_log.xml

# Output
WriteToPDF=false
WriteToSVG=true
# Output File Prefix : 出力先ファイル名(拡張子が内部分)
OutputPrefix=msgpack-repo

# Visual variables
ScreenWidth=1200
ScreenHeight=800

さて実行！　とその前に

さて、Processingを起動してStorylines/Storylines.pdeを読み込んでRunボタンで実行すれば終了！


と、行きたいところなのですがいくつか上手くいかないところがあったのでメモ.

1. Arrayがなんかおかしー

以下のスクショの部分で引っかかる場合があります.

Processing側のライブラリではなく, java側のライブラリを呼び出そうとしているのが原因のようです. 以下の一行をCluster.pdeの先頭に付け加えると上手く動きます.

import java.util.Arrays;
2. ぬるぽ

第二のエラーはこれです。ぬるぽ

問題はStorylines.pdeの969行目にあります

967    if ( line.startsWith( "<event" ) )
968    {
969      XMLElement eventXML = new XMLElement( line );

ここで969行目はlineに含まれるeventタグからXMLElementのインスタンスを生成しようとしています. しかしXMLElementのコンストラクタはXML文字列を受け取りません。結果、eventXMLが きちんと生成されないのです。
ここでは以下のように書き換えてやる必要があります。

969     XMLElement eventXML = XMLElement.parse( line );

これで、コンフィグが間違ってなければ動くはず!

出力結果

しばらく待つとconfigファイルのOutputPrefixで指定した名前のファイルができあがります。
大きなプロジェクトだと数分から数十分かかる場合がありますが、辛抱強く待ちましょう

なかなか色が綺麗で観ていても楽しいのですが, このSVGファイルを対応ブラウザで開くともう少し楽しめます。たとえば適当なラインにマウスをオーバーラップさせるとこんな感じになります。ある人の活動履歴だけを協調表示できたりするのでした。

おしまい

*1:本来的にはCLASSPATHにあるところならどこでも良いらしいのですが, めんどくさい&うまくいかなかったので...

*2:なおこちらのcodeswarmもなかなかおもしろい

DNSテスト自動化 in Ruby

メモ ツール Ruby

DNSのテストといえば相場はdigかnslookupと決まってるわけですが、毎回手で打つのも癪なので自動化しましょ、というお話。
シェルスクリプトが未だ書けないおばかなのでRubyでごにょごにょする方法。

dnsrubyのインストール

rubygemsにはnet-dnsやらpNet-DNSやらいくつかDNS向けっぽいパッケージが転がっていますが、主にDNSSEC対応がある程度出来ているという理由で"dnsruby"を採用。まぎらわしいことに"Dnsruby"とかいうのもあるので注意。

% sudo gem search -r dnsruby

*** REMOTE GEMS ***

dnsruby (1.52)
Dnsruby (1.0)      <= まぎらわしい

% sudo gem install dnsruby

とりあえず書いてみる

  1 require "rubygems"
  2 require "dnsruby"
  3 
  4 TARGETNAME="twitter.com"
  5 NAMESERVER="8.8.8.8"
  6 
  7 resolver = Dnsruby::Resolver.new(:nameserver=>NAMESERVER)
  8 
  9 answers = resolver.query(TARGETNAME).answer
 10 answers.each do |answer|
 11   print "#{answer.type.to_s} : #{answer.to_s}\n"
 12 end
 13

これを実行するとこんな出力が得られる

 % ruby test.rb
A : twitter.com.	29	IN	A	199.59.148.10
A : twitter.com.	29	IN	A	199.59.149.198
A : twitter.com.	29	IN	A	199.59.148.82

細かくいろいろ

他にも

  • クエリのタイプを指定したり
  • DNSキャッシュを切ったり
  • DNSSECを有効化したり
  1 require "rubygems"
  2 require "dnsruby"
  3 
  4 TARGETNAME="jprs.co.jp"
  5 NAMESERVER="8.8.8.8"
  6 
  7 resolver = Dnsruby::Resolver.new(:nameserver=>NAMESERVER)
  8 
  9 # キャッシュとかいらないですしおすし
 10 resolver.do_caching = false
 11 
 12 # DNSSEC有効化 ( デフォルトtrue )
 13 resolver.dnssec = true
 14
 15 recvmsg = resolver.query(TARGETNAME, Dnsruby::Types.AAAA) # レコードタイプの指定
 16 
 17 # DNSSECで投げたクエリに対する応答の検証結果
 18 print "verified? : #{recvmsg.verified?}\n"                                                                                                                                                                                                                                  
 19                     
 20 recvmsg.answer.each do |record|
 21   print "#{record.type.to_s} "
 22   if record.type == Dnsruby::Types.AAAA then
 23     print ": #{record.address}\n"
 24   elsif record.type == Dnsruby::Types.RRSIG then
 25     print ": #{record.type_covered.to_s}, #{record.algorithm}, #{record.signature}\n"
 26   end               
 27 end

これを実行するとこんな感じ

% ruby test.rb
verified? : false
AAAA : 2001:DF0:8:7::80
RRSIG : AAAA, RSASHA256, Z??*??(?{??%??Y?n?1d?m&#1409;bpkO?r&mDk р?6?(???|?
zs

  ?OΔJ.??7}?&????k?&#1946;?X~??=<;?dh?J,?? ?a I?Yx??J?=?&#1744;???&#1573;J5??l

シグネチャ表示してる当たりはまぁ化け化けですね…

ちなみにここで検証の結果が失敗しているのはjprsとかぐーぐるがさぼってるからではなく、ここ*1の注意書きにあるようにこちらがわでいろいろやらねばならぬところをサボってるからと思われます。recvmsg.security_levelをみてみると以下のようになっており、そもそも検証自体が行われていないのでした。残念。

>> recvmsg.security_level
=> UNCHECKED

*1:http://dnsruby.rubyforge.org/classes/Dnsruby/Dnssec.html