Possible performance bug

[Linda Knippers]

Thanks for the data.  This is from an x86 box?
I would guess that the syscall performance hit in the 3 cases is even
more apparent with a syscall that doesn't do a pathname lookup.

-- ljk

Steve Grubb wrote:
> On Thursday 08 September 2005 21:44, Steve Grubb wrote:
> 
>>>Profiles would be helpful. Actually, it'd be interesting to see overhead
>>>of audit turned on, but not generating any records (no rules loaded, no
>>>avc messages).
>>
>>True. I'll see if we can get those.
> 
> 
> OK, I do have some profile data from booting with profile=1. When audit was 
> never enabled, the test ran in 22.6 seconds. When audit had run and been 
> disabled, the test ran in 23.8 seconds. With audit enabled, the test took 
> 24.7 seconds. This is repeatable. 
> 
> Now some data...from audit not enabled:
> 
>  22579 total                                      0.0088
>   2987 __d_lookup                                 4.1602
>   2939 system_call                               58.7800
>   2477 __link_path_walk                           0.5132
>   2139 strncpy_from_user                         23.7667
>   1129 inode_has_perm                             8.8898
>   1120 avc_has_perm_noaudit                       5.3589
>    959 kmem_cache_alloc                          13.1370
>    913 kmem_cache_free                           19.4255
>    807 dput                                       0.4667
>    763 selinux_inode_permission                   4.6524
>    731 _atomic_dec_and_lock                       2.2562
>    614 memcpy                                    14.9756
>    571 permission                                 3.1547
>    485 __might_sleep                              2.8869
> 
> boot with audit, then disabled:
>  23841 total                                      0.0093
>   2729 strncpy_from_user                         30.3222
>   2584 __d_lookup                                 3.5989
>   2525 system_call                               50.5000
>   2358 __link_path_walk                           0.4885
>   1222 inode_has_perm                             9.6220
>   1131 avc_has_perm_noaudit                       5.4115
>   1103 kmem_cache_alloc                          15.1096
>    995 kmem_cache_free                           21.1702
>    752 memcpy                                    18.3415
>    693 _atomic_dec_and_lock                       2.1389
>    663 __might_sleep                              3.9464
>    640 syscall_exit_work                         26.6667
>    606 permission                                 3.3481
>    591 dput                                       0.3418
>    546 selinux_inode_permission                   3.3293
>    511 avc_lookup                                 3.3399
> 
> And audit on:
>  24672 total                                      0.0096
>   3198 system_call                               63.9600
>   2764 __d_lookup                                 3.8496
>   2556 __link_path_walk                           0.5295
>   1427 strncpy_from_user                         15.8556
>   1303 kmem_cache_free                           27.7234
>   1112 audit_syscall_exit                         0.8355
>   1013 avc_has_perm_noaudit                       4.8469
>    974 inode_has_perm                             7.6693
>    974 _atomic_dec_and_lock                       3.0062
>    812 kmem_cache_alloc                          11.1233
>    665 dput                                       0.3846
>    624 syscall_exit_work                         26.0000
>    545 memcpy                                    13.2927
>    464 selinux_inode_permission                   2.8293
>    463 __might_sleep                              2.7560
> 
> 
> The big difference between 1 & 2 is more kmem_cache_alloc & free, and 
> syscall_exit_work. The syscall_exit_work comes from this test:
> 
> 227         movl TI_flags(%ebp), %ecx
> 228         testw $_TIF_ALLWORK_MASK, %cx
> 229         jne syscall_exit_work
> 
> So, Amy is right, the TIF_AUDIT flag has some bearing on the benchmarks.
> 
> The big difference between runs 2 & 3 are _atomic_dec_and_lock being higher 
> and audit_syscall_exit showing up. system_syscall was higher, too. Not sure 
> where it picked up cycles. I think all of these increases are to be expected.
> 
> These are run with no rules loaded.
> 
> -Steve
> 
> --
> Linux-audit mailing list
> Linux-audit at redhat.com
> http://www.redhat.com/mailman/listinfo/linux-audit
>