tech-kern archive
[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index][Old Index]
9.1: boot-time delay?
I'm dealing with a turnkey product running under 9.1/amd64. On certain
hardware, there is a pause, almost exactly 22 seconds, during autoconf.
I'm trying to eliminate it. A sufficiently cut-down kernel does the
job, but another cut-down kernel doesn't. I'm trying to track down
what's responsible. (The kernel that eliminates the pause is used by
the installer; the one that doesn't is the one that's used in normal
operation. Unless it turns out to be something essential for
operation, I'd like to cut it out of the operational kernel.)
I could perhaps do it by subsetting the differences and looking at
which ones exhibit the delay. I'm trying to do it a bit more
intelligently.
In a "normal" multi-user boot on the relevant hardware with a
general-purpose kernel, the delay occurs here:
[ 3.288539] uhub2: 4 ports with 4 removable, self powered
[ 3.288539] uhub3: 6 ports with 6 removable, self powered
[ 25.272567] wd0 at atabus0 drive 0
[ 25.273568] wd0: <ST500DM002-1BD142>
(full dmesg available, or I can quote subsets if someone can tell me
what subsets are of interest).
My first guess was that some driver's ca_match routine was taking
unreasonably long. I added code to config_match, in subr_autoconf.c,
and according to that that's not it, or at least if it is then it's not
being called via config_match.
I did build a kernel with ddb and broke into it during the pause. A
backtrace was singularly unhelpful
db{0}> tr
breakpoint() at netbsd:breakpoint+0x5
comintr() at netbsd:comintr+0x8ab
Xhandle_ioapic_edge7() at netbsd:Xhandle_ioapic_edge7+0x66
--- interrupt ---
x86_mwait() at netbsd:x86_mwait+0xd
acpicpu_cstate_idle_enter() at netbsd:acpicpu_cstate_idle_enter+0xdb
acpicpu_cstate_idle() at netbsd:acpicpu_cstate_idle+0x6d
idle_loop() at netbsd:idle_loop+0xcc
db{0}>
(the innermost few frames vary depending on video versus serial
console; the above is, of course, for serial).
ps doesn't say anything useful to me, possibly because I'm not familiar
enough with 9.1, possibly because it doesn't have anything useful to
say:
db{0}> ps
PID LID S CPU FLAGS STRUCT LWP * NAME WAIT
1 1 3 0 0 ffff836fd0dc2b20 init lbolt
0 66 3 0 200 ffff836fd0c56a20 usb1 usbevt
0 65 3 0 200 ffff836fd0d14600 usb0 usbevt
0 64 3 1 200 ffff836fd0df32c0 npfgc0 npfgcw
0 63 3 1 200 ffff836fd0dc26e0 rt_free rt_free
0 62 3 1 200 ffff836fd0dc22a0 unpgc unpgc
0 61 3 1 200 ffff836fd0dceb00 key_timehandler key_timehandler
0 60 3 1 200 ffff836fd0dce6c0 icmp6_wqinput/1 icmp6_wqinput
0 59 3 0 200 ffff836fd0dce280 icmp6_wqinput/0 icmp6_wqinput
0 58 3 1 200 ffff836fd0d92ae0 nd6_timer nd6_timer
0 57 3 1 200 ffff836fd0d926a0 carp6_wqinput/1 carp6_wqinput
0 56 3 0 200 ffff836fd0d92260 carp6_wqinput/0 carp6_wqinput
0 55 3 1 200 ffff836fd0d7eac0 carp_wqinput/1 carp_wqinput
0 54 3 0 200 ffff836fd0d7e680 carp_wqinput/0 carp_wqinput
0 53 3 1 200 ffff836fd0d7e240 icmp_wqinput/1 icmp_wqinput
0 52 3 0 200 ffff836fd0cf01e0 icmp_wqinput/0 icmp_wqinput
0 51 3 1 200 ffff836fd0cf0a60 rt_timer rt_timer
0 50 3 0 200 ffff836fd0d34200 vmem_rehash vmem_rehash
0 49 3 0 200 ffff836fd0d18aa0 coretemp1 coretemp1
0 48 3 0 200 ffff836fd0d18660 coretemp0 coretemp0
0 47 3 0 200 ffff836fd0d18220 acpitz2 acpitz2
0 46 3 0 200 ffff836fd0d34a80 acpitz1 acpitz1
0 45 3 0 200 ffff836fd0d34640 acpitz0 acpitz0
0 38 5 1 200 ffff836fd0d141c0 (zombie)
0 36 3 1 200 ffff836fd0c565e0 atabus3 atainitq
0 35 3 0 200 ffff836fd0c561a0 atabus2 atadrdy
0 34 3 1 200 ffff836fd0c3aa00 iic0 iicintr
0 33 3 0 200 ffff836fd0c3a5c0 atabus1 atainitq
0 32 3 1 200 ffff836fd0c3a180 atabus0 atadrdy
0 31 3 1 200 ffff836fd0bad9e0 wm1TxRx/1 wm1TxRx
0 30 3 0 200 ffff836fd0bad5a0 wm1TxRx/0 wm1TxRx
0 29 3 1 200 ffff836fd0bad160 usbtask-dr usbtsk
0 28 3 1 200 ffff836fd0b859c0 usbtask-hc usbtsk
0 27 3 1 200 ffff836fd0b85580 wm0TxRx/1 wm0TxRx
0 26 3 0 200 ffff836fd0b85140 wm0TxRx/0 wm0TxRx
0 25 3 1 200 ffff836fcfa2c9a0 xcall/1 xcall
0 24 1 1 200 ffff836fcfa2c560 softser/1
0 23 1 1 200 ffff836fcfa2c120 softclk/1
0 22 1 1 200 ffff836fcfa11980 softbio/1
0 21 1 1 200 ffff836fcfa11540 softnet/1
0 > 20 7 1 201 ffff836fcfa11100 idle/1
0 19 3 0 200 ffff83700791b960 lnxpwrwq lnxpwrwq
0 18 3 0 200 ffff83700791b520 lnxlngwq lnxlngwq
0 17 3 0 200 ffff83700791b0e0 lnxsyswq lnxsyswq
0 16 3 0 200 ffff837007912940 lnxrcugc lnxrcugc
0 15 3 0 200 ffff837007912500 sysmon smtaskq
0 14 3 0 200 ffff8370079120c0 pmfsuspend pmfsuspend
0 13 3 0 200 ffff837007a32920 pmfevent pmfevent
0 12 3 0 200 ffff837007a324e0 sopendfree sopendfr
0 11 3 1 200 ffff837007a320a0 nfssilly nfssilly
0 10 3 0 200 ffff837007f4e900 cachegc cachegc
0 9 3 0 200 ffff837007f4e4c0 vdrain vdrain
0 8 3 0 200 ffff837007f4e080 modunload mod_unld
0 7 3 0 200 ffff837007f6c8e0 xcall/0 xcall
0 6 1 0 200 ffff837007f6c4a0 softser/0
0 5 1 0 200 ffff837007f6c060 softclk/0
0 4 1 0 200 ffff837007f868c0 softbio/0
0 3 1 0 200 ffff837007f86480 softnet/0
0 > 2 7 0 201 ffff837007f86040 idle/0
0 1 3 1 200 ffffffff8145d140 swapper cfgmisc
db{0}>
The above are from a general-purpose kernel, not either of the
specialized kernels. But the delay in question appears identical
between the general-purpose kernel and the specialized operational
kernel. I can capture analogous info from the cut-back kernel if
anyone thinks it might help.
I'm going to be trying the subsetting approach, for lack of anything
else, but I expect that to take significant time; if anyone has any
thoughts that might speed the process up I'd much appreciate them.
/~\ The ASCII Mouse
\ / Ribbon Campaign
X Against HTML mouse%rodents-montreal.org@localhost
/ \ Email! 7D C8 61 52 5D E7 2D 39 4E F1 31 3E E8 B3 27 4B
Home |
Main Index |
Thread Index |
Old Index