[ltt-dev] Degression from "fix-x86_64-sysenter-trace-race"

[zhaolei@cn.fujitsu.com (Zhaolei)]

* Zhaolei Wrote:
> Mathieu Desnoyers Wrote:
>> * Zhaolei (zhaolei at cn.fujitsu.com) wrote:
>>> * Mathieu Desnoyers Wrote:
>>>> * Zhaolei (zhaolei at cn.fujitsu.com) wrote:
>>>>> Hello,
>>>>>
>>>>> I tested lttng's performance by tbench program in x86_64 platform.
>>>>> And I found patch named "fix-x86_64-sysenter-trace-race" makes large
>>>>> degression(about 5%).
>>>>> Here is test result:
>>>>>
>>>>> [----------PATCH----------]                     [TBENCH]
>>>>> lttng-kernel-trace-thread-flag-s390		1317.08
>>>>> lttng-kernel-trace-thread-flag-sh		1315.61
>>>>> lttng-kernel-trace-thread-flag-sparc		1305.02
>>>>> lttng-kernel-trace-thread-flag-sparc64		1314.06
>>>>> lttng-kernel-trace-thread-flag-um		1316.35
>>>>> fix-x86_64-sysenter-trace-race			1250.89
>>>>> lttng-kernel-trace-thread-flag-x86		1259.07
>>>>> lttng-kernel-trace-thread-flag-xtensa		1252.86
>>>>> lttng-kernel-trace-thread-flag-api		1253.35
>>>>> lttng-use-kernel-trace-thread-flag-api		1251.9
>>>>> stringify-support-commas			1247.11
>>>>>
>>>>> And if I remove this patch, degression is not happened:
>>>>> [----------PATCH----------]                     [TBENCH]
>>>>> lttng-kernel-trace-thread-flag-s390		1307.73
>>>>> lttng-kernel-trace-thread-flag-sh		1317.33
>>>>> lttng-kernel-trace-thread-flag-sparc		1306.85
>>>>> lttng-kernel-trace-thread-flag-sparc64		1303.62
>>>>> lttng-kernel-trace-thread-flag-um		1312.08
>>>>> lttng-kernel-trace-thread-flag-x86		1308.5
>>>>> lttng-kernel-trace-thread-flag-xtensa		1310.77
>>>>> lttng-kernel-trace-thread-flag-api		1309.05
>>>>> lttng-use-kernel-trace-thread-flag-api		1310.26
>>>>> stringify-support-commas			1307.69
>>>>>
>>>>> I want to know system's benchmark when lttng turn off,
>>>>> so test environment is following:
>>>>> - Compile kernel with lttng patch up to given one and default config,
>>>>> - Install kernel, Reboot system,
>>>>>   (don't load any lttng module, don't run ltt-arm or lttctl)
>>>>> - Begin tbench test.
>>>>>
>>>>> Plarform is RHEL5.2 root filesystem with linux-2.6.27.7 and lttng-0.60 patchs.
>>>>> Hardware is 4 * Intel(R) Xeon(R) X5260 at 3.33GHz with 4G memory.
>>>>>
>>>>> I think [fix-x86_64-sysenter-trace-race] should not leads so large degression,
>>>>> But I tested several times and result is near.
>>>>>
>>>> Hrm, interesting. Can you give your full kernel .config ? I'd like to
>>>> see if the _TIF_SYSCALL_AUDIT or _TIF_SECCOMP bits are set.
>>> Hello, Mathieu
>>>
>>> kernel config is send as attachment.
>>> I use RHEL's default config with ltt support.
>>>
>> OK, I see that you have 
>>
>> CONFIG_AUDIT=y
>> CONFIG_AUDITSYSCALL=y
>>
>> (therefore _TIF_SYSCALL_AUDIT is probably on)
>>
>> One way we could lessen the impact on your system when tracing is not
>> active is to target more specifically the bit which should be tested at
>> this second test location (when returning to userspace). Can you try
>> changing :
>>
>> sysret_careful:
>>         testl $(_TIF_SYSCALL_TRACE|_TIF_KERNEL_TRACE|_TIF_SYSCALL_AUDIT|_TIF_SECCOMP),%edx
>>         jnz ret_from_sys_call_trace
>>
>> (this is after the lttng-instrumentation-x86.patch patch has been
>> applied)
>>
>> for
>>
>> sysret_careful:
>>         testl $_TIF_KERNEL_TRACE,%edx
>>         jnz ret_from_sys_call_trace
>>
>> The logic is that only the _TIF_KERNEL_TRACE thread flag needs to be
>> tested at syscall return because it is the only flag which may be
>> changed concurrently wrt thread execution.
>>
> Hello, Mathieu
> 
> I finished this test, result is following:
> 	[lttng-instrumentation-x86.patc]	[only test _TIF_KERNEL_TRACE]
> step1	1250.55					1301.41
> step2	1255.47					1300.72
> 
> It seems degression is gone when remove _TIF_SYSCALL_TRACE|_TIF_SYSCALL_AUDIT|_TIF_SECCOMP check.
> 
> I'll check which flag (_TIF_SYSCALL_TRACE or _TIF_SYSCALL_AUDIT or _TIF_SECCOMP) cause degression.
Hello, Mathieu

Now I finished test.
degression is caused by _TIF_SYSCALL_AUDIT.

Detail is following:
[testl flag]								[Step1]	[Step2]
_TIF_SYSCALL_TRACE|_TIF_SYSCALL_AUDIT|_TIF_KERNEL_TRACE|_TIF_SECCOMP	1250.88	1241.51
_TIF_SYSCALL_TRACE|_TIF_SYSCALL_AUDIT|_TIF_KERNEL_TRACE			1253.68	1248.58
_TIF_SYSCALL_TRACE|_TIF_SYSCALL_AUDIT					1251.53	1247.91
_TIF_SYSCALL_TRACE							1311.41	1312.19
0									1315.96	1295.93

B.R.
Zhaolei

> 
> B.R.
> Zhaolei
> 
>> If we see that this helps, we might want to dig further and try to find
>> a way that would help not having the runtime penality cost even when
>> tracing is enabled.
>>
>> Mathieu
>>
>>
>>> B.R.
>>> Zhaolei
>>>
>>>> If you have a better way to support asynchronously changing the thread
>>>> flags and still have the affected running threads running correctly, I'm
>>>> willing to consider it.
>>>>
>>>> Mathieu
>>>>
>>>>> B.R.
>>>>> Zhaolei
>>>>>
>>>>>
>>>>> _______________________________________________
>>>>> ltt-dev mailing list
>>>>> ltt-dev at lists.casi.polymtl.ca
>>>>> http://lists.casi.polymtl.ca/cgi-bin/mailman/listinfo/ltt-dev
>>>>>
>>> #
>>> # Automatically generated make config: don't edit
>>> # Linux kernel version: 2.6.27.7
>>> # Fri Dec 12 20:32:16 2008
>>> #
>>> CONFIG_64BIT=y
>>> # CONFIG_X86_32 is not set
>>> CONFIG_X86_64=y
>>> CONFIG_X86=y
>>> CONFIG_ARCH_DEFCONFIG="arch/x86/configs/x86_64_defconfig"
>>> # CONFIG_GENERIC_LOCKBREAK is not set
>>> CONFIG_GENERIC_TIME=y
>>> CONFIG_GENERIC_CMOS_UPDATE=y
>>> CONFIG_CLOCKSOURCE_WATCHDOG=y
>