On Thursday 07 April 2011 21:31, Ed W wrote:
> Hi, I have a significant performance problem with busybox 1.18.3 modprobe.
>
> Quick benchmark, 20 iterations of: "modprobe iptables -q"
>
> Busybox: 1.15s
> module-init-tools: 0.12s
>
> This is hitting me in two areas, one is boot speed is slower than expected,
> but
> more importantly it's crucified my iptables performance. Inexplicably
> iptables (1.4.10)
> calls modprobe something like 21 times each time it's run (makes firewall init
> a multi-minute process)
>
> Obviously fixing iptables is desirable, but is it possible to improve
> performance
> of busybox modprobe? Looking at strace the big difference seems to be the
> read of the various files, busybox apparently using lots of getc()?
>
> Any thoughts on a solution?
Apparently upstream tools now use some sort of binary indexed files
which allow search to be sped up:
> First modprobe from module-init-tools
>
> $ strace -tt /sbin/modprobe iptables -q
> 18:27:05.785024 execve("/sbin/modprobe", ["/sbin/modprobe", "iptables",
> "-q"], [/* 13 vars */]) = 0
...
> 18:27:05.829249 open("/lib/modules/2.6.37-grsec/modules.dep.bin", O_RDONLY) =
> 3
^^^^
> 18:27:05.829646 ioctl(3, SNDCTL_TMR_TIMEBASE or TCGETS, 0xbf7dd048) = -1
> ENOTTY (Inappropriate ioctl for device)
> 18:27:05.829995 _llseek(3, 0, [0], SEEK_SET) = 0
> 18:27:05.830329 read(3, "\260\7\372W", 4) = 4
> 18:27:05.830662 read(3, " \0T\227", 4) = 4
> 18:27:05.830997 _llseek(3, 21655, [21655], SEEK_SET) = 0
> 18:27:05.831325 read(3, "aw \0\10+ \0\17\37 \0\24\333\300\0\25A \0\27\305
> \0\30\301\300\0\30\313 \0"..., 4096) = 94
> 18:27:05.831797 _llseek(3, 10998, [10998], SEEK_SET) = 0
> 18:27:05.832124 read(3,
> "fw\300\0\33\233\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"...,
> 4096) = 4096
> 18:27:05.833415 _llseek(3, 10058, [10058], SEEK_SET) = 0
> 18:27:05.833776 read(3, "_a \0&\210\0\0\0\0\300\0&\312945 /lib/modules/2"...,
> 4096) = 4096
> 18:27:05.834203 close(3) = 0
> 18:27:05.834556 open("/lib/modules/2.6.37-grsec/modules.alias.bin", O_RDONLY)
> = 3
^^^^
> 18:27:05.834950 ioctl(3, SNDCTL_TMR_TIMEBASE or TCGETS, 0xbf7dd038) = -1
> ENOTTY (Inappropriate ioctl for device)
> 18:27:05.835372 _llseek(3, 0, [0], SEEK_SET) = 0
> 18:27:05.835721 read(3, "\260\7\372W", 4) = 4
> 18:27:05.836060 read(3, " \1\271\357", 4) = 4
> 18:27:05.836398 _llseek(3, 113135, [113135], SEEK_SET) = 0
> 18:27:05.836725 read(3, "bu\240\0\0(
> \0\1c\240\0\1\235\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\300\0"..., 4096) = 82
> 18:27:05.837217 _llseek(3, 467, [467], SEEK_SET) = 0
> 18:27:05.837550 read(3, "wl4965 iwlagn\0 atm\0 pppoe\0 can\0000"..., 4096) =
> 4096
> 18:27:05.838008 close(3) = 0
> 18:27:05.838347 exit_group(1) = ?
Of course this will be faster than reading the entire file:
> Now busybox modprobe:
>
> root@localhost $ strace -tt busybox modprobe iptables -q
> 18:27:18.587989 execve("/bin/busybox", ["busybox", "modprobe", "iptables",
> "-q"], [/* 13 vars */]) = 0
...
> 18:27:18.641616 open("modules.dep", O_RDONLY|O_LARGEFILE) = 3
> 18:27:18.641958 ioctl(3, SNDCTL_TMR_TIMEBASE or TCGETS, 0xbadc5388) = -1
> ENOTTY (Inappropriate ioctl for device)
> 18:27:18.642308 read(3, "/lib/modules/2.6.37-grsec/kernel"..., 4096) = 4096
> 18:27:18.643614 read(3, "rial/usbserial.ko\n/lib/modules/2"..., 4096) = 4096
> 18:27:18.644619 read(3, ".6.37-grsec/kernel/net/mac80211/"..., 4096) = 4096
> 18:27:18.645630 read(3, "37-grsec/kernel/drivers/pps/clie"..., 4096) = 4096
> 18:27:18.647765 read(3, "_pe_sip.ko: /lib/modules/2.6.37-"..., 4096) = 201
> 18:27:18.648217 read(3, "", 4096) = 0
> 18:27:18.648552 close(3) = 0
> 18:27:18.648881 lstat64("modules.alias", {st_mode=S_IFREG|0644,
> st_size=137268, ...}) = 0
> 18:27:18.649351 open("modules.alias", O_RDONLY|O_LARGEFILE) = 3
> 18:27:18.649703 ioctl(3, SNDCTL_TMR_TIMEBASE or TCGETS, 0xbadc51a8) = -1
> ENOTTY (Inappropriate ioctl for device)
> 18:27:18.650061 read(3, "# Aliases extracted from modules"..., 4096) = 4096
> 18:27:18.651629 read(3, "ort\nalias usb:v1608p0011d*dc*dsc"..., 4096) = 4096
> 18:27:18.653837 read(3, "p* pl2303\nalias usb:v067Bp0612d*"..., 4096) = 4096
> 18:27:18.655583 read(3, "*dsc*dp*ic*isc*ip* io_ti\nalias u"..., 4096) = 4096
> 18:27:18.657243 read(3, "p*ic*isc*ip* ftdi_sio\nalias usb:"..., 4096) = 4096
> 18:27:18.658848 read(3, "EEd*dc*dsc*dp*ic*isc*ip* ftdi_si"..., 4096) = 4096
> 18:27:18.660996 read(3, "usb:v0403pF068d*dc*dsc*dp*ic*isc"..., 4096) = 4096
> 18:27:18.662628 read(3, "i_sio\nalias usb:v0C52p2413d*dc*d"..., 4096) = 4096
> 18:27:18.664235 read(3, "*isc*ip* ftdi_sio\nalias usb:v1B3"..., 4096) = 4096
> 18:27:18.665833 read(3, "dc*dsc*dp*ic*isc*ip* ftdi_sio\nal"..., 4096) = 4096
> 18:27:18.667967 read(3, "v1B3Dp012Bd*dc*dsc*dp*ic*isc*ip*"..., 4096) = 4096
> 18:27:18.669758 read(3, "o\nalias usb:v0403p6001d*dc*dsc*d"..., 4096) = 4096
> 18:27:18.671389 read(3, "*dsc*dp*icFFiscFFipFF* option\nal"..., 4096) = 4096
> 18:27:18.672996 read(3, "1147d*dc*dsc*dp*icFFiscFFipFF* o"..., 4096) = 4096
> 18:27:18.675146 read(3, "b:v19D2p1071d*dc*dsc*dp*icFFiscF"..., 4096) = 4096
> 18:27:18.676777 read(3, "alias usb:v19D2p0052d*dc*dsc*dp*"..., 4096) = 4096
> 18:27:18.678384 read(3, "ion\nalias usb:v16D5p6502d*dc*dsc"..., 4096) = 4096
> 18:27:18.680011 read(3, "2D1p142Fd*dc*dsc*dp*icFFiscFFipF"..., 4096) = 4096
> 18:27:18.682189 read(3, "b:v0AF0p6000d*dc*dsc*dp*ic*isc*i"..., 4096) = 4096
> 18:27:18.683871 read(3, "d*dc*dsc*dp*ic*isc*ip* ipaq\nalia"..., 4096) = 4096
> 18:27:18.685543 read(3, "sc*ip* ipaq\nalias usb:v0BB4p0A34"..., 4096) = 4096
> 18:27:18.687702 read(3, "s usb:v05E0p2004d*dc*dsc*dp*ic*i"..., 4096) = 4096
> 18:27:18.689482 read(3, "d*dc*dsc*dp*ic*isc*ip* ipaq\nalia"..., 4096) = 4096
> 18:27:18.691164 read(3, "sc*ip* ipaq\nalias usb:v045Ep0404"..., 4096) = 4096
> 18:27:18.692802 read(3, "\nalias usb:v10C4p8477d*dc*dsc*dp"..., 4096) = 4096
> 18:27:18.694965 read(3, "p8027d*dc*dsc*dp*ic*isc*ip* keys"..., 4096) = 4096
> 18:27:18.696591 read(3, "pFF* cdc_acm\nalias usb:v0421p04C"..., 4096) = 4096
> 18:27:18.698223 read(3, "lias usb:v0DB0p3871d*dc*dsc*dp*i"..., 4096) = 4096
> 18:27:18.699794 read(3, "000Bd*dc*dsc*dp*ic*isc*ip* rt280"..., 4096) = 4096
> 18:27:18.701906 read(3, "rt73usb\nalias usb:v0769p31F3d*dc"..., 4096) = 4096
> 18:27:18.703567 read(3, "b:v0769p11F2d*dc*dsc*dp*ic*isc*i"..., 4096) = 4096
> 18:27:18.705157 read(3, "s pci:v00008086d0000008Bsv*sd000"..., 4096) = 4096
> 18:27:18.706734 read(3, "agn\nalias pci:v00008086d00004237"..., 4096) = 4096
> 18:27:18.708913 read(3, "so\nalias usb:v0AF0p7701d*dc*dsc*"..., 4096) = 2100
> 18:27:18.710049 read(3, "", 4096) = 0
> 18:27:18.710386 close(3) = 0
> 18:27:18.710719 open("modules.dep", O_RDONLY|O_LARGEFILE) = 3
> 18:27:18.711070 ioctl(3, SNDCTL_TMR_TIMEBASE or TCGETS, 0xbadc5388) = -1
> ENOTTY (Inappropriate ioctl for device)
> 18:27:18.711426 read(3, "/lib/modules/2.6.37-grsec/kernel"..., 4096) = 4096
> 18:27:18.712522 read(3, "rial/usbserial.ko\n/lib/modules/2"..., 4096) = 4096
> 18:27:18.713515 read(3, ".6.37-grsec/kernel/net/mac80211/"..., 4096) = 4096
> 18:27:18.715106 read(3, "37-grsec/kernel/drivers/pps/clie"..., 4096) = 4096
> 18:27:18.716398 read(3, "_pe_sip.ko: /lib/modules/2.6.37-"..., 4096) = 201
> 18:27:18.716827 read(3, "", 4096) = 0
> 18:27:18.717157 close(3) = 0
> 18:27:18.717514 exit_group(1) = ?
There is no fast fix for this: we will need to implement indexed binary files
to match upstream speed.
--
vda
_______________________________________________
busybox mailing list
[email protected]
http://lists.busybox.net/mailman/listinfo/busybox
