performance tests

Wed Sep 14 23:32:38 UTC 2005

I was hoping to capture some data re: the issue with enabling then later
disabling the audit subsystem.  My data is inconclusive, and doesn't
clearly point to any issue.  So perhaps someone who is able to show the
performance hit can run with this.  Attached is the script I used to
run the tests, and at the bottom are URLs with raw data.

I ran 3 rounds of tests back-to-back on two separate kernels.  The first
kernel is unpatched mainline kernel, the second is patched with the
TIF_SYSCALL_AUDIT patch that Steve and I were tossing about last week.
On each kernel I boot without audit enabled and run the first round of
tests, enable audit and run second round of tests, disable audit and
run third round of tests.  Each round of tests simply run lmbench, then
build a kernel.  Each stage gets fresh oprofile data capture.

Here's some basic highlights:

LMBench
Processor, Processes - times in microseconds - smaller is better
------------------------------------------------------------------------------
Host                 OS   Mhz null null      open slct sig  sig  fork exec sh  
                              call  I/O stat clos TCP  inst hndl proc proc proc
------------------------ ---- ---- ---- ---- ---- ---- ---- ---- ---- ---- ----
unpatched audit disabled 1994 0.09 0.26 16.1 18.6 9.26 0.22 2.31 554. 1018 2508
unpatched audit enabled  1994 0.33 0.60 16.6 19.3 19.7 0.48 2.87 601. 1083 2772
unpatched audit disabled 1994 0.09 0.25 16.0 18.4 11.8 0.22 2.47 577. 1055 2668

patched audit disabled   1994 0.09 0.23 16.4 18.4 12.9 0.22 2.39 551. 1007 2510
patched audit enabled    1994 0.42 0.60 16.8 19.3 8.61 0.47 2.91 573. 1075 2719
patched audit disabled   1994 0.09 0.30 16.5 18.9 12.6 0.22 2.49 562. 1036 2575

This excerpt of lmbench suggests fork/exec/sh tests, for example,
are sensitive and show effects that are possibly improved by the
TIF_SYSCALL_AUDIT patch (reduce a ~6.4% overhead to a ~2.6% overhead).
However, the full lmbench run generates profile data which suggests the
penalty is in the noise (granted, I've got some debugging enabled that
may hide other subtle effects).

samples %       symbol name|samples %       symbol name|samples  %       symbol name
1513465 22.3901 copy_user_g|1338383 19.8526 copy_user_g|1336757  20.2344 copy_user_g
1259839 18.6379 check_poiso|1171051 17.3705 check_poiso|1248209  18.8940 check_poiso
 269874  3.9925 memset     | 323399  4.7971 memset     | 274733   4.1586 memset
 160374  2.3726 clear_page | 188499  2.7961 sub_preemp | 165920   2.5115 clear_page
 136696  2.0223 sub_preemp | 167853  2.4898 clear_page | 144600   2.1888 sub_preemp
 127345  1.8839 add_preemp | 155483  2.3063 add_preemp | 139349   2.1093 add_preemp
 124938  1.8483 schedule   | 116873  1.7336 schedule   |  126961  1.9218 schedule
  87354  1.2923 getrusage  |  87297  1.2949 audit_sysc_exi|91651  1.3873 find_get_pa
...
  61105  0.9040 try_to_wake|  61626  0.9141 audit_filt_sys|61749  0.9347 try_to_wake
...
  41928  0.6203 acpi_proces|  47810  0.7092 audit_sysc_ent|44019  0.6663 do_select
...
   7179  0.1062 tcp_select_|   7749  0.1149 audit_serial  | 7124  0.1078 tcp_v4_do_r
...
      6  8.9e-05 audit_allo|     7  1.0e-04 __free_pages_|    7  1.1e-04 sprintf
...
      6  8.9e-05 dx_probe  |     7  1.0e-04  cdrom_decode|    6  9.1e-05 audit_alloc
...

kernbench

Unpatched		Patched

audit disabled (never enabled)
real	5m47.271s	real	5m44.002s
user	5m1.911s	user	5m3.067s
sys	0m51.271s	sys	0m50.835s

audit enabled
real	5m45.999s	real	5m45.162s
user	5m2.647s	user	5m3.443s
sys	0m52.499s	sys	0m52.203s

audit disabled (after enabled)
real	5m46.010s	real	5m48.170s
user	5m1.371s	user	5m2.247s
sys	0m51.871s	sys	0m51.719s

The data here shows that within margin of error, disable after enable
has no cost.  The profile data similarly shows no effect.

Raw data is here:

http://developer.osdl.org/chrisw/audit-perf-test/
http://developer.osdl.org/chrisw/audit-perf-test/lmbench.out (self-expanatory)
http://developer.osdl.org/chrisw/audit-perf-test/perftest-noperf2.out (unpatched)
http://developer.osdl.org/chrisw/audit-perf-test/perftest.ti4140/ (profile data for unpatched run)
http://developer.osdl.org/chrisw/audit-perf-test/perftest-perf2.out (patched)
http://developer.osdl.org/chrisw/audit-perf-test/perftest.Wq4156 (profile data for patched run)
http://developer.osdl.org/chrisw/audit-perf-test/audit-performance.patch (patch)
http://developer.osdl.org/chrisw/audit-perf-test/perftest.sh (script)
-------------- next part --------------
A non-text attachment was scrubbed...
Name: perftest.sh
Type: application/x-sh
Size: 923 bytes
Desc: not available
URL: <http://listman.redhat.com/archives/linux-audit/attachments/20050914/67404c76/attachment.sh>