Re: Watch Performance

[Amy Griffis <amy.griffis@hp.com>]

Steve,

In order for these numbers to be meaningful, a little more information
is needed:

1) what audit rules did you use?
2) what system call(s) did you measure?

Steve Grubb wrote:  [Sat Apr 08 2006, 12:21:57PM EDT]
> Hello,
> 
> Over the last day or two, I re-worked the user space audit code to be able to 
> control the new file system audit subsystem. As I was doing the work, I 
> became concerned about the performance impact since it appears to be using 
> the syscall exit filter.
> 
> The syscall exit filter (and entry filter) is expensive to use except in cases 
> where you need to use it. This is because each rule in it must be examined 
> during each syscall to see if the current syscall is of interest. The current 
> lspp configuration has 10 syscall audit rules. 
> 
> I became curious what the measured impact would be with the current file 
> system audit implementation. I decide to run the same performance test that I 
> tested the audit system with a couple weeks ago when inode and IPC problems 
> were noticed. I used the lspp.16 kernel with profile=2 boot param. The 
> following table shows the results:
> 
> rules  seconds
> 0        49
> 10      56
> 25      75
> 50      115
> 75      143
> 90      185

3) how many operations were completed in N seconds?

> 
> 
> 0 rules had this for function usage:
> 
>   1284 __d_lookup                                 4.7380
>   1170 __link_path_walk                         0.3098
>   1065 avc_has_perm_noaudit                1.2144
>    706 _atomic_dec_and_lock                 8.4048
>    612 do_path_lookup                            0.8204
>    561 dput                                          1.2986
>    509 _raw_spin_lock                            2.1477
> 
> 10 rules had this:
> 
>   1295 __d_lookup                                 4.7786
>   1089 audit_filter_syscall                       6.3684
>   1081 __link_path_walk                           0.2862
>    889 avc_has_perm_noaudit                   1.0137
>    676 audit_getname                              2.6000
>    658 do_path_lookup                             0.8820
>    596 _atomic_dec_and_lock                  7.0952
> 
> 25 rules had this:
> 
>   3193 audit_filter_rules                         3.0009
>   2178 audit_filter_syscall                      12.7368
>   1280 __d_lookup                                 4.7232
>   1131 __link_path_walk                           0.2994
>    956 avc_has_perm_noaudit                  1.0901
>    652 _atomic_dec_and_lock                  7.7619
>    530 dput                                          1.2269
> 
> 50 rules had this:
> 
>  11213 audit_filter_rules                        10.5385
>   4654 audit_filter_syscall                      27.2164
>   4100 selinux_task_ctxid                       141.3793
>   1212 __d_lookup                                 4.4723
>   1103 __link_path_walk                           0.2920
>   1012 avc_has_perm_noaudit                  1.1539
>    788 _atomic_dec_and_lock                   9.3810
> 
> 75 had this:
> 
>  15351 audit_filter_rules                        14.4276
>   6032 audit_filter_syscall                      35.2749
>   2066 selinux_task_ctxid                        71.2414
>   1237 __d_lookup                                 4.5646
>   1184 __link_path_walk                           0.3135
>   1014 avc_has_perm_noaudit                  1.1562
>    592 _atomic_dec_and_lock                   7.0476
> 
> and 90 rules had this:
> 
>  18287 audit_filter_rules                        17.1870
>   9173 audit_filter_syscall                      53.6433
>   4346 selinux_task_ctxid                       149.8621
>   1314 __link_path_walk                           0.3479
>   1218 __d_lookup                                 4.4945
>   1070 avc_has_perm_noaudit                  1.2201
>    682 _atomic_dec_and_lock                   8.1190
> 
> 
> As you can see, the audit_filter_rules and audit_filter_syscall overwhelmed 
> the profile quickly. It would not be unreasonable for a system to have 40 
> watches. The lspp rules have 56 of them. With 10 syscall rules added, the 
> performance of a correctly configured lspp machine will be similar to the 75 
> rules test. This represents a 186% performance hit compared to no audit 
> rules.
> 
> I do not believe optimizing the audit_filter_rules function will solve the 
> problem. I think the file system audit algorithm needs to be re-thought. It 
> simply cannot penalize every syscall.
> 
> There are several ways to solve the problem. Maybe what we need to do is use 
> the watch list to store watches on and add a new field to the context. If a 
> watch is triggered it sets the flag in the context. When syscall exit is 
> done, it checks the flag and if set, does both the watch list and the exit 
> list. Otherwise, it skips the watch list. I don't know if this is feasible, 
> or a preferred solution, but we need to start looking at how to decouple the 
> exit list and watches.
> 
> -Steve
> 
> --
> Linux-audit mailing list
> Linux-audit@redhat.com
> https://www.redhat.com/mailman/listinfo/linux-audit
>