Date: Wed, 14 Apr 2004 07:54:11 +0100 From: Colin Percival <colin.percival@wadham.ox.ac.uk> To: Peter Jeremy <PeterJeremy@optushome.com.au> Cc: current@freebsd.org Subject: Re: Optimizing RCng execution speed ? Message-ID: <6.0.1.1.1.20040414065121.039cde20@imap.sfu.ca> In-Reply-To: <20040413200013.GC53327@cirb503493.alcatel.com.au> References: <11095.1081621779@critter.freebsd.dk> <407B1EBC.6050405@freebsd.org> <407B234D.7070209@kientzle.com> <20040413160331.GM6308@numachi.com> <20040413200013.GC53327@cirb503493.alcatel.com.au>
next in thread | previous in thread | raw e-mail | index | archive | help
At 21:00 13/04/2004, Peter Jeremy wrote:
>The time-consuming bits are starting a new shell and sourcing the
>config files.
Not quite. The main configuration files don't get re-sourced
each time -- rc.subr uses an "_rc_conf_loaded" variable to avoid
this. However, rc.subr itself gets re-sourced, which seems quite
unnecessary; removing this (via an _rc_subr_loaded variable) gives
a roughly 20% speedup.
>If someone wants to have a look at this,
>the place to start is to profile the complete system during startup
>and see where the time is going.
On my 5.2.1 system (with the mentioned don't-reload-rc.subr patch):
Starting RC scripts: kern.cp_time: 1 0 44 2 53
RC done: /etc/rc.d/initdiskless: kern.cp_time: 3 0 67 2 60
RC done: /etc/rc.d/rcconf.sh: kern.cp_time: 3 0 70 2 61
RC done: /etc/rc.d/initrandom: kern.cp_time: 3 0 125 2 66
RC done: /etc/rc.d/dumpon: kern.cp_time: 3 0 127 2 66
RC done: /etc/rc.d/vinum: kern.cp_time: 4 0 128 2 66
RC done: /etc/rc.d/gbde: kern.cp_time: 4 0 132 2 66
RC done: /etc/rc.d/ccd: kern.cp_time: 4 0 134 2 66
RC done: /etc/rc.d/swap1: kern.cp_time: 5 0 138 2 67
RC done: /etc/rc.d/early.sh: kern.cp_time: 5 0 140 2 67
RC done: /etc/rc.d/fsck: kern.cp_time: 7 0 226 2 115
RC done: /etc/rc.d/root: kern.cp_time: 8 0 238 2 122
RC done: /etc/rc.d/sppp: kern.cp_time: 8 0 240 2 122
RC done: /etc/rc.d/serial: kern.cp_time: 8 0 242 2 122
RC done: /etc/rc.d/mountcritlocal: kern.cp_time: 9 0 300 2 241
RC done: /etc/rc.d/atm1: kern.cp_time: 9 0 301 2 242
RC done: /etc/rc.d/pccard: kern.cp_time: 9 0 302 2 243
RC done: /etc/rc.d/kldxref: kern.cp_time: 9 0 303 2 244
RC done: /etc/rc.d/ipsec: kern.cp_time: 9 0 304 2 245
RC done: /etc/rc.d/hostname: kern.cp_time: 9 0 307 2 250
RC done: /etc/rc.d/diskless: kern.cp_time: 9 0 308 2 251
RC done: /etc/rc.d/cleanvar: kern.cp_time: 9 0 315 2 278
RC done: /etc/rc.d/random: kern.cp_time: 11 0 323 2 298
RC done: /etc/rc.d/addswap: kern.cp_time: 11 0 324 2 299
RC done: /etc/rc.d/sysctl: kern.cp_time: 11 0 326 2 301
RC done: /etc/rc.d/adjkerntz: kern.cp_time: 12 0 327 2 303
RC done: /etc/rc.d/ipmon: kern.cp_time: 13 0 327 2 304
RC done: /etc/rc.d/ipfilter: kern.cp_time: 14 0 328 2 306
RC done: /etc/rc.d/ipnat: kern.cp_time: 14 0 329 2 307
RC done: /etc/rc.d/ipfs: kern.cp_time: 14 0 330 2 308
RC done: /etc/rc.d/netif: kern.cp_time: 14 0 335 2 333
RC done: /etc/rc.d/isdnd: kern.cp_time: 14 0 336 2 334
RC done: /etc/rc.d/ip6addrctl: kern.cp_time: 15 0 337 2 336
RC done: /etc/rc.d/dhclient: kern.cp_time: 16 0 338 2 338
RC done: /etc/rc.d/atm2: kern.cp_time: 16 0 339 2 339
RC done: /etc/rc.d/ppp-user: kern.cp_time: 16 0 341 2 349
RC done: /etc/rc.d/atm3: kern.cp_time: 17 0 341 2 350
RC done: /etc/rc.d/routing: kern.cp_time: 19 0 341 2 354
RC done: /etc/rc.d/ipfw: kern.cp_time: 23 0 343 2 370
RC done: /etc/rc.d/routed: kern.cp_time: 23 0 344 2 371
RC done: /etc/rc.d/mrouted: kern.cp_time: 23 0 345 2 372
RC done: /etc/rc.d/ip6fw: kern.cp_time: 23 0 347 2 374
RC done: /etc/rc.d/network_ipv6: kern.cp_time: 24 0 347 2 375
RC done: /etc/rc.d/route6d: kern.cp_time: 24 0 348 2 376
RC done: /etc/rc.d/mroute6d: kern.cp_time: 24 0 349 2 377
RC done: /etc/rc.d/NETWORKING: kern.cp_time: 24 0 350 2 378
RC done: /etc/rc.d/pppoed: kern.cp_time: 24 0 351 2 379
RC done: /etc/rc.d/kerberos: kern.cp_time: 24 0 352 2 380
RC done: /etc/rc.d/devd: kern.cp_time: 24 0 354 2 382
RC done: /etc/rc.d/mountcritremote: kern.cp_time: 24 0 359 2 387
RC done: /etc/rc.d/kadmind: kern.cp_time: 24 0 359 2 387
RC done: /etc/rc.d/ttys: kern.cp_time: 24 0 362 2 396
RC done: /etc/rc.d/quota: kern.cp_time: 24 0 363 2 397
RC done: /etc/rc.d/nfsserver: kern.cp_time: 24 0 364 2 398
RC done: /etc/rc.d/motd: kern.cp_time: 26 0 367 2 421
RC done: /etc/rc.d/lomac: kern.cp_time: 26 0 368 2 422
RC done: /etc/rc.d/ldconfig: kern.cp_time: 26 0 372 2 446
RC done: /etc/rc.d/kpasswdd: kern.cp_time: 26 0 373 2 447
RC done: /etc/rc.d/dmesg: kern.cp_time: 26 0 376 2 450
RC done: /etc/rc.d/cleartmp: kern.cp_time: 26 0 379 2 463
RC done: /etc/rc.d/accounting: kern.cp_time: 26 0 380 2 464
RC done: /etc/rc.d/virecover: kern.cp_time: 26 0 383 2 479
RC done: /etc/rc.d/syslogd: kern.cp_time: 26 0 393 3 696
RC done: /etc/rc.d/savecore: kern.cp_time: 26 0 394 3 697
RC done: /etc/rc.d/pwcheck: kern.cp_time: 27 0 394 3 698
RC done: /etc/rc.d/ntpdate: kern.cp_time: 28 0 394 3 699
RC done: /etc/rc.d/SERVERS: kern.cp_time: 28 0 395 3 700
RC done: /etc/rc.d/named: kern.cp_time: 28 0 396 3 701
RC done: /etc/rc.d/ipxrouted: kern.cp_time: 28 0 397 3 702
RC done: /etc/rc.d/rpcbind: kern.cp_time: 29 0 398 3 704
RC done: /etc/rc.d/nisdomain: kern.cp_time: 29 0 399 3 705
RC done: /etc/rc.d/nfsclient: kern.cp_time: 29 0 400 3 706
RC done: /etc/rc.d/mountd: kern.cp_time: 29 0 401 3 707
RC done: /etc/rc.d/ypxfrd: kern.cp_time: 29 0 402 3 708
RC done: /etc/rc.d/ypserv: kern.cp_time: 29 0 403 3 709
RC done: /etc/rc.d/nfsd: kern.cp_time: 29 0 404 3 710
RC done: /etc/rc.d/ypupdated: kern.cp_time: 29 0 404 4 711
RC done: /etc/rc.d/ypbind: kern.cp_time: 30 0 404 4 712
RC done: /etc/rc.d/nfslocking: kern.cp_time: 30 0 405 4 713
RC done: /etc/rc.d/ypset: kern.cp_time: 31 0 405 4 714
RC done: /etc/rc.d/yppasswdd: kern.cp_time: 31 0 406 4 715
RC done: /etc/rc.d/keyserv: kern.cp_time: 31 0 407 4 716
RC done: /etc/rc.d/amd: kern.cp_time: 31 0 408 4 717
RC done: /etc/rc.d/DAEMON: kern.cp_time: 31 0 409 4 718
RC done: /etc/rc.d/watchdogd: kern.cp_time: 31 0 410 4 719
RC done: /etc/rc.d/usbd: kern.cp_time: 31 0 411 4 720
RC done: /etc/rc.d/timed: kern.cp_time: 31 0 412 4 721
RC done: /etc/rc.d/rwho: kern.cp_time: 32 0 412 4 722
RC done: /etc/rc.d/rtadvd: kern.cp_time: 32 0 413 4 723
RC done: /etc/rc.d/rarpd: kern.cp_time: 33 0 414 4 725
RC done: /etc/rc.d/ntpd: kern.cp_time: 33 0 415 4 726
RC done: /etc/rc.d/moused: kern.cp_time: 33 0 416 4 727
RC done: /etc/rc.d/lpd: kern.cp_time: 33 0 417 4 728
RC done: /etc/rc.d/local: kern.cp_time: 34 0 417 4 729
RC done: /etc/rc.d/bootparams: kern.cp_time: 35 0 417 4 730
RC done: /etc/rc.d/apm: kern.cp_time: 35 0 419 4 732
RC done: /etc/rc.d/apmd: kern.cp_time: 35 0 420 4 733
RC done: /etc/rc.d/LOGIN: kern.cp_time: 35 0 420 4 733
RC done: /etc/rc.d/syscons: kern.cp_time: 35 0 422 4 741
RC done: /etc/rc.d/sshd: kern.cp_time: 35 0 431 4 806
RC done: /etc/rc.d/sendmail: kern.cp_time: 36 0 432 4 808
RC done: /etc/rc.d/pcvt: kern.cp_time: 39 0 433 4 808
RC done: /etc/rc.d/othermta: kern.cp_time: 40 0 434 4 808
RC done: /etc/rc.d/msgs: kern.cp_time: 43 0 434 4 809
RC done: /etc/rc.d/jail: kern.cp_time: 44 0 435 4 809
RC done: /etc/rc.d/inetd: kern.cp_time: 46 0 435 4 809
RC done: /etc/rc.d/devfs: kern.cp_time: 50 0 438 4 810
RC done: /etc/rc.d/cron: kern.cp_time: 57 0 440 4 813
RC done: /etc/rc.d/archdep: kern.cp_time: 59 0 442 4 813
RC done: /etc/rc.d/bgfsck: kern.cp_time: 61 0 444 4 813
RC done: /etc/rc.d/abi: kern.cp_time: 64 0 447 4 813
RC done: /etc/rc.d/localpkg: kern.cp_time: 70 0 451 5 816
RC done: /etc/rc.d/netoptions: kern.cp_time: 71 0 452 5 816
RC done: /etc/rc.d/securelevel: kern.cp_time: 71 0 455 5 819
RC scripts done: kern.cp_time: 71 0 455 5 819
Out of the total 4.88 seconds the major consumers are:
syslogd 0.89 s
mountcritlocal 0.70 s
fsck 0.53 s
sshd 0.29 s
initrandom 0.24 s
cleanvar 0.13 s
netif 0.12 s
motd 0.11 s
ldconfig 0.11 s
Also note that the 35 conecutive scripts {savecore ... LOGIN} which
do nothing take under 0.01 seconds each (which is mostly overhead
from reading the cp_time statistics); thus, any optimization should
probably be targetted at scripts which actually do something. :-)
Colin Percival
Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?6.0.1.1.1.20040414065121.039cde20>