Port-m68k archive
[Date Prev][Date Next][Thread Prev][Thread Next][Date Index][Thread Index][Old Index]
Re: 7.0 slow multiuser boot
On Thu, 5 Feb 2015 13:56:24 +0000
David Brownlee <abs%absd.org@localhost> wrote:
> > First NetBSD 6.1.5. Takes 2 minutes and 39 seconds:
> > [...]
> >
> > Now NetBSD 7.0beta (from last week). Takes 4 minutes and 51 seconds.
> > [...]
> >
> > There are no individual scripts which take longer, but all scripts take
> > longer. The runtime is at least doubled for every single script! So
> > there must be a general problem.
> > Also the amount of allocated memory is much higher: 23 MB instead 16 MB.
> >
> > I don't think that it is caused by the kernel, because I remember I have
> > seen the same effect with a 6.1.5 kernel running on 7.0 userland.
>
> Did you mean 7.0 kernel and 6.1.5 userland?
No. I started the old 6.1.5 kernel with a recent userland.
BTW, I just realized userland is not 7.0beta, but 7.99.4.
> Do you have the numbers
> for the same boot for that for direct comparison?
Sure. Here are the numbers for a 6.1.5 kernel running 7.99.4 userland:
[/etc/rc starting at Fri Feb 6 16:17:21 CET 2015]
16:17:23 [running rcorder] 4720 82848
16:17:26 [running /etc/rc.d/wdogctl] 5776 81744
16:17:27 [running /etc/rc.d/fsck_root] 5608 81936
Starting root file system check:
/dev/rwd1a: file system is clean; not checking
16:17:30 [running /etc/rc.d/root] 6048 81360
16:17:32 [running /etc/rc.d/ccd] 5928 81512
16:17:34 [running /etc/rc.d/rndctl] 5704 81768
16:17:36 [running /etc/rc.d/cgd] 5704 81768
[NOTE: Output from /etc/rc.d/cgd is not logged]
16:17:38 [running /etc/rc.d/lvm] 6112 81296
16:17:40 [running /etc/rc.d/raidframe] 6144 81232
16:17:41 [running /etc/rc.d/DISKS] 6144 81264
16:17:43 [running /etc/rc.d/swap1] 6200 81176
swapctl: adding /dev/wd0b as swap device at priority 0
16:17:45 [running /etc/rc.d/fsck] 5720 81744
Starting file system checks:
16:17:47 [running /etc/rc.d/mountcritlocal] 6128 81272
[NOTE: Optional file system /var is not present]
16:17:50 [running /etc/rc.d/random_seed] 6272 81104
Loaded entropy from /var/db/entropy-file.
16:17:53 [running /etc/rc.d/bootconf.sh] 5944 81424
[NOTE: Output from /etc/rc.d/bootconf.sh is not logged]
16:17:55 [running /etc/rc.d/ttys] 6376 80928
Setting tty flags.
16:17:58 [running /etc/rc.d/pf_boot] 6584 80648
16:18:00 [running /etc/rc.d/ipsec] 6400 80864
16:18:02 [running /etc/rc.d/ipfilter] 6088 81208
16:18:03 [running /etc/rc.d/sysctl] 6488 80744
Setting sysctl variables:
ddb.onpanic: 1 -> 0
16:18:05 [running /etc/rc.d/network] 6712 80520
Starting network.
Hostname: aquila
IPv6 mode: host
Configuring network interfaces: le0.
Adding interface aliases:.
add net default: gateway 192.168.0.254
Waiting for DAD completion for statically configured addresses...
16:18:15 [running /etc/rc.d/wpa_supplicant] 6512 80672
16:18:16 [running /etc/rc.d/dhclient] 6592 80560
16:18:18 [running /etc/rc.d/dhcpcd] 6184 81032
16:18:20 [running /etc/rc.d/ldpd] 6184 81032
16:18:22 [running /etc/rc.d/npf] 6032 81184
16:18:23 [running /etc/rc.d/pf] 6592 80560
16:18:25 [running /etc/rc.d/route6d] 6592 80560
16:18:27 [running /etc/rc.d/routed] 6592 80560
16:18:29 [running /etc/rc.d/rtsold] 6592 80560
16:18:30 [running /etc/rc.d/staticroute] 6624 80528
16:18:32 [running /etc/rc.d/NETWORKING] 6592 80560
16:18:34 [running /etc/rc.d/mountcritremote] 6624 80528
[NOTE: Optional file system /usr is not present]
16:18:36 [running /etc/rc.d/sysdb] 6088 81128
Building databases: dev, utmp, utmpx.
16:18:43 [running /etc/rc.d/newsyslog] 6824 79024
16:18:44 [running /etc/rc.d/wscons] 6696 79152
16:18:46 [running /etc/rc.d/syslogd] 6528 79320
Starting syslogd.
16:18:52 [running /etc/rc.d/ppp] 8824 76896
16:18:54 [running /etc/rc.d/named] 8576 77144
16:18:56 [running /etc/rc.d/rtclocaltime] 8824 76896
16:18:58 [running /etc/rc.d/ntpdate] 8824 76896
16:18:59 [running /etc/rc.d/rpcbind] 8416 77368
16:19:01 [running /etc/rc.d/ypserv] 8824 76896
16:19:03 [running /etc/rc.d/ypbind] 8824 76896
16:19:05 [running /etc/rc.d/yppasswdd] 8640 77112
16:19:06 [running /etc/rc.d/mountall] 8416 77368
Mounting all file systems...
16:19:09 [running /etc/rc.d/perusertmp] 8824 76896
16:19:11 [running /etc/rc.d/cleartmp] 8416 77368
Clearing temporary files.
16:19:13 [running /etc/rc.d/xfs] 8872 76784
16:19:15 [running /etc/rc.d/accounting] 8872 76784
16:19:16 [running /etc/rc.d/amd] 8680 76960
16:19:18 [running /etc/rc.d/dmesg] 8464 77240
16:19:21 [running /etc/rc.d/fccache] 8896 76744
Updating fontconfig cache: done.
16:19:29 [running /etc/rc.d/veriexec] 9904 75440
16:19:31 [running /etc/rc.d/ldconfig] 9904 75440
Creating a.out runtime link editor directory cache.
16:19:37 [running /etc/rc.d/quota] 12064 73104
Checking quotas: done.
16:19:40 [running /etc/rc.d/mountd] 12696 72408
16:19:42 [running /etc/rc.d/nfsd] 12696 72408
16:19:43 [running /etc/rc.d/nfslocking] 12464 72672
16:19:45 [running /etc/rc.d/pwcheck] 12280 72888
16:19:47 [running /etc/rc.d/gpio] 12144 73024
16:19:49 [running /etc/rc.d/ipnat] 12696 72408
16:19:51 [running /etc/rc.d/securelevel] 12288 72880
Setting securelevel: kern.securelevel: 0 -> 1
16:19:53 [running /etc/rc.d/swap2] 12696 72408
16:19:55 [running /etc/rc.d/virecover] 12696 72408
Starting virecover.
16:19:57 [running /etc/rc.d/altqd] 12296 72872
16:19:59 [running /etc/rc.d/ifwatchd] 12656 72448
16:20:01 [running /etc/rc.d/isdnd] 12672 72432
16:20:03 [running /etc/rc.d/ipfs] 12296 72872
16:20:05 [running /etc/rc.d/ipmon] 12296 72872
16:20:06 [running /etc/rc.d/kdc] 12704 72400
16:20:08 [running /etc/rc.d/pflogd] 12704 72400
16:20:10 [running /etc/rc.d/racoon] 12296 72872
16:20:12 [running /etc/rc.d/savecore] 12296 72872
Checking for core dump...
savecore: /dev/rwd1b: Device not configured
16:20:14 [running /etc/rc.d/SERVERS] 12368 72792
16:20:16 [running /etc/rc.d/DAEMON] 12776 72320
16:20:17 [running /etc/rc.d/apmd] 12776 72320
16:20:19 [running /etc/rc.d/bluetooth] 12368 72792
16:20:21 [running /etc/rc.d/bootparams] 12776 72320
16:20:22 [running /etc/rc.d/devpubd] 12776 72320
16:20:24 [running /etc/rc.d/dhcpd] 12776 72320
16:20:26 [running /etc/rc.d/dhcrelay] 12776 72320
16:20:28 [running /etc/rc.d/ftp_proxy] 12368 72792
16:20:30 [running /etc/rc.d/irdaattach] 12368 72792
16:20:31 [running /etc/rc.d/local] 12776 72320
Starting local daemons:.
16:20:34 [running /etc/rc.d/lpd] 12824 72200
16:20:35 [running /etc/rc.d/makemandb] 12824 72200
16:20:37 [running /etc/rc.d/mopd] 12416 72672
16:20:39 [running /etc/rc.d/motd] 12824 72200
Updating motd.
16:20:42 [running /etc/rc.d/mrouted] 12496 72592
16:20:43 [running /etc/rc.d/ntpd] 12688 72336
16:20:45 [running /etc/rc.d/powerd] 12880 72144
16:20:47 [running /etc/rc.d/rarpd] 12496 72592
16:20:49 [running /etc/rc.d/rbootd] 12496 72592
16:20:50 [running /etc/rc.d/rtadvd] 12904 72120
16:20:52 [running /etc/rc.d/rwho] 12904 72120
16:20:54 [running /etc/rc.d/screenblank] 12496 72592
16:20:55 [running /etc/rc.d/timed] 12856 72168
16:20:57 [running /etc/rc.d/tpctl] 12904 72120
16:20:59 [running /etc/rc.d/LOGIN] 12496 72592
16:21:01 [running /etc/rc.d/xdm] 12880 72144
16:21:02 [running /etc/rc.d/wsmoused] 12904 72120
16:21:04 [running /etc/rc.d/sshd] 12760 72264
16:21:06 [running /etc/rc.d/raidframeparity] 12496 72592
16:21:08 [running /etc/rc.d/postfix] 12904 72120
16:21:54 [running /etc/rc.d/ndbootd] 21232 62920
16:21:57 [running /etc/rc.d/moused] 22704 61496
16:21:58 [running /etc/rc.d/mixerctl] 23120 61008
16:22:00 [running /etc/rc.d/mdnsd] 23120 61008
16:22:02 [running /etc/rc.d/isibootd] 23120 61008
16:22:04 [running /etc/rc.d/iscsi_target] 23120 61008
16:22:05 [running /etc/rc.d/inetd] 22632 61560
Starting inetd.
16:22:08 [running /etc/rc.d/identd] 23232 60928
16:22:10 [running /etc/rc.d/httpd] 23456 60672
16:22:11 [running /etc/rc.d/hostapd] 23600 60488
16:22:13 [running /etc/rc.d/ftpd] 23640 60448
16:22:15 [running /etc/rc.d/envsys] 23672 60384
16:22:17 [running /etc/rc.d/cron] 23640 60416
Starting cron.
[/etc/rc finished at Fri Feb 6 16:22:18 CET 2015]
Nearly 5 minutes. The numbers are equally bad with a 6.1.5 kernel running
7.99.4 userland as with a 7.0beta kernel running 7.99.4 userland.
Also 23MB are allocated again (which was expected).
> Was this a 4.8 or 4.5 compiled 7.0?
4.5
> How much memory was in the machine?
96 MB Fast RAM and 2 MB Chip RAM.
> Could it be the 16->23MB memory usage is pushing it into paging?
I doubt that.
> Apologies if I seem like I'm just suggesting you do even more work,
> but I don't have a usable m68k box available... (I have a nice TT030
> but in storage quite some way away :/
A 68030 system would be completely unusable with a V7 userland. I tried
it with my A1200 68030/42MHz and it took more than 15 minutes to boot.
There is something which I noticed during the last tests, which might be
an important hint:
When you press CTRL-t during multiuser boot from time to time, then you
see the currently executed command. With 6.1.5 userland everything is
normal. But with 7.99.4 (and most likely 7.0 as well) you see very frequently
"cmd: sleep [nanosleep]" !
Seems that it is now sleeping half of the boot process. But why?
--
Frank Wille
Home |
Main Index |
Thread Index |
Old Index