Re: Optimizing RCng execution speed ?

From: Colin Percival (colin.percival_at_wadham.ox.ac.uk)
Date: 04/14/04

  • Next message: Stijn Hoop: "Re: HEADS UP: PCI Changes"
    Date: Wed, 14 Apr 2004 07:54:11 +0100
    To: Peter Jeremy <PeterJeremy@optushome.com.au>
    
    

    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

    _______________________________________________
    freebsd-current@freebsd.org mailing list
    http://lists.freebsd.org/mailman/listinfo/freebsd-current
    To unsubscribe, send any mail to "freebsd-current-unsubscribe@freebsd.org"


  • Next message: Stijn Hoop: "Re: HEADS UP: PCI Changes"

    Relevant Pages