[PATCH] trace/hwlat: Do not restart per-cpu threads if they are already running

[PATCH] trace/hwlat: Do not restart per-cpu threads if they are already running

[Tero Kristo]

Check if the hwlatd thread for the cpu is already running, before
starting a new one. This avoids running multiple instances of the same
CPU thread on the system. Also, do not wipe the contents of the
per-cpu kthread data when starting the tracer, as this can completely
forget about already running instances and start new additional per-cpu
threads. Fixes issues where fiddling with either the mode of the hwlat
tracer or doing cpu-hotplugs messes up the internal book-keeping
resulting in stale hwlatd threads.

Signed-off-by: Tero Kristo <tero.kristo@linux.intel.com>
---
 kernel/trace/trace_hwlat.c | 7 ++++---
 1 file changed, 4 insertions(+), 3 deletions(-)

diff --git a/kernel/trace/trace_hwlat.c b/kernel/trace/trace_hwlat.c
index d440ddd5fd8b..c4945f8adc11 100644
--- a/kernel/trace/trace_hwlat.c
+++ b/kernel/trace/trace_hwlat.c
@@ -492,6 +492,10 @@ static int start_cpu_kthread(unsigned int cpu)
 {
 	struct task_struct *kthread;
 
+	/* Do not start a new hwlatd thread if it is already running */
+	if (per_cpu(hwlat_per_cpu_data, cpu).kthread)
+		return 0;
+
 	kthread = kthread_run_on_cpu(kthread_fn, NULL, cpu, "hwlatd/%u");
 	if (IS_ERR(kthread)) {
 		pr_err(BANNER "could not start sampling thread\n");
@@ -584,9 +588,6 @@ static int start_per_cpu_kthreads(struct trace_array *tr)
 	 */
 	cpumask_and(current_mask, cpu_online_mask, tr->tracing_cpumask);
 
-	for_each_online_cpu(cpu)
-		per_cpu(hwlat_per_cpu_data, cpu).kthread = NULL;
-
 	for_each_cpu(cpu, current_mask) {
 		retval = start_cpu_kthread(cpu);
 		if (retval)
-- 
2.25.1

Re: [PATCH] trace/hwlat: Do not restart per-cpu threads if they are already running

[Daniel Bristot de Oliveira]

Hi Tero,

On 3/2/23 08:36, Tero Kristo wrote:
> Check if the hwlatd thread for the cpu is already running, before
> starting a new one. This avoids running multiple instances of the same
> CPU thread on the system. Also, do not wipe the contents of the
> per-cpu kthread data when starting the tracer, as this can completely
> forget about already running instances and start new additional per-cpu
> threads. Fixes issues where fiddling with either the mode of the hwlat
> tracer or doing cpu-hotplugs messes up the internal book-keeping
> resulting in stale hwlatd threads.

Thanks for your patch.

Would you mind explaining how do you hit the problem? that is, how can
I reproduce the same problem you faced.

I tried reproducing it by dispatching the hwlat tracer in two instances,
but the system already blocks me...

[root@vm tracing]# echo hwlat > current_tracer 
[root@vm tracing]# cd instances/
[root@vm instances]# mkdir hwlat_2
[root@vm instances]# cd hwlat_2/
[root@vm hwlat_2]# echo hwlat > current_tracer 
-bash: echo: write error: Device or resource busy

[root@vm hwlat_2]# cd ../../
[root@vm tracing]# echo nop > current_tracer 
[root@vm tracing]# cd instances/hwlat_2/
[root@vm hwlat_2]# echo hwlat > current_tracer 
[root@vm hwlat_2]# cd ..
[root@vm instances]# mkdir hwlat_1
[root@vm instances]# cd hwlat_1/
[root@vm hwlat_1]# echo hwlat > current_tracer 
-bash: echo: write error: Device or resource busy
[root@vm hwlat_1]# 

Having a reproducer helps us to think better about the problem.

-- Daniel

> Signed-off-by: Tero Kristo <tero.kristo@linux.intel.com>
> ---
>  kernel/trace/trace_hwlat.c | 7 ++++---
>  1 file changed, 4 insertions(+), 3 deletions(-)
> 
> diff --git a/kernel/trace/trace_hwlat.c b/kernel/trace/trace_hwlat.c
> index d440ddd5fd8b..c4945f8adc11 100644
> --- a/kernel/trace/trace_hwlat.c
> +++ b/kernel/trace/trace_hwlat.c
> @@ -492,6 +492,10 @@ static int start_cpu_kthread(unsigned int cpu)
>  {
>  	struct task_struct *kthread;
>  
> +	/* Do not start a new hwlatd thread if it is already running */
> +	if (per_cpu(hwlat_per_cpu_data, cpu).kthread)
> +		return 0;
> +
>  	kthread = kthread_run_on_cpu(kthread_fn, NULL, cpu, "hwlatd/%u");
>  	if (IS_ERR(kthread)) {
>  		pr_err(BANNER "could not start sampling thread\n");
> @@ -584,9 +588,6 @@ static int start_per_cpu_kthreads(struct trace_array *tr)
>  	 */
>  	cpumask_and(current_mask, cpu_online_mask, tr->tracing_cpumask);
>  
> -	for_each_online_cpu(cpu)
> -		per_cpu(hwlat_per_cpu_data, cpu).kthread = NULL;
> -
>  	for_each_cpu(cpu, current_mask) {
>  		retval = start_cpu_kthread(cpu);
>  		if (retval)

Re: [PATCH] trace/hwlat: Do not restart per-cpu threads if they are already running

[Tero Kristo]

Hi,

On 02/03/2023 13:49, Daniel Bristot de Oliveira wrote:
> Hi Tero,
>
> On 3/2/23 08:36, Tero Kristo wrote:
>> Check if the hwlatd thread for the cpu is already running, before
>> starting a new one. This avoids running multiple instances of the same
>> CPU thread on the system. Also, do not wipe the contents of the
>> per-cpu kthread data when starting the tracer, as this can completely
>> forget about already running instances and start new additional per-cpu
>> threads. Fixes issues where fiddling with either the mode of the hwlat
>> tracer or doing cpu-hotplugs messes up the internal book-keeping
>> resulting in stale hwlatd threads.
> Thanks for your patch.
>
> Would you mind explaining how do you hit the problem? that is, how can
> I reproduce the same problem you faced.

For example, this script snippet reproduces it for me every time:

#!/bin/sh
cd /sys/kernel/debug/tracing
echo 0 > tracing_on
echo hwlat > current_tracer
echo per-cpu > hwlat_detector/mode
echo 100000 > hwlat_detector/width
echo 200000 > hwlat_detector/window
echo 200 > tracing_thresh
echo 1 > tracing_on

Another case where something wonky happens is if you offline/online a 
large number of CPUs (which takes a lot of time), and you start/disable 
the hwlat tracer at the same time.

-Tero


>
> I tried reproducing it by dispatching the hwlat tracer in two instances,
> but the system already blocks me...
>
> [root@vm tracing]# echo hwlat > current_tracer
> [root@vm tracing]# cd instances/
> [root@vm instances]# mkdir hwlat_2
> [root@vm instances]# cd hwlat_2/
> [root@vm hwlat_2]# echo hwlat > current_tracer
> -bash: echo: write error: Device or resource busy
>
> [root@vm hwlat_2]# cd ../../
> [root@vm tracing]# echo nop > current_tracer
> [root@vm tracing]# cd instances/hwlat_2/
> [root@vm hwlat_2]# echo hwlat > current_tracer
> [root@vm hwlat_2]# cd ..
> [root@vm instances]# mkdir hwlat_1
> [root@vm instances]# cd hwlat_1/
> [root@vm hwlat_1]# echo hwlat > current_tracer
> -bash: echo: write error: Device or resource busy
> [root@vm hwlat_1]#
>
> Having a reproducer helps us to think better about the problem.
>
> -- Daniel
>
>> Signed-off-by: Tero Kristo <tero.kristo@linux.intel.com>
>> ---
>>   kernel/trace/trace_hwlat.c | 7 ++++---
>>   1 file changed, 4 insertions(+), 3 deletions(-)
>>
>> diff --git a/kernel/trace/trace_hwlat.c b/kernel/trace/trace_hwlat.c
>> index d440ddd5fd8b..c4945f8adc11 100644
>> --- a/kernel/trace/trace_hwlat.c
>> +++ b/kernel/trace/trace_hwlat.c
>> @@ -492,6 +492,10 @@ static int start_cpu_kthread(unsigned int cpu)
>>   {
>>   	struct task_struct *kthread;
>>   
>> +	/* Do not start a new hwlatd thread if it is already running */
>> +	if (per_cpu(hwlat_per_cpu_data, cpu).kthread)
>> +		return 0;
>> +
>>   	kthread = kthread_run_on_cpu(kthread_fn, NULL, cpu, "hwlatd/%u");
>>   	if (IS_ERR(kthread)) {
>>   		pr_err(BANNER "could not start sampling thread\n");
>> @@ -584,9 +588,6 @@ static int start_per_cpu_kthreads(struct trace_array *tr)
>>   	 */
>>   	cpumask_and(current_mask, cpu_online_mask, tr->tracing_cpumask);
>>   
>> -	for_each_online_cpu(cpu)
>> -		per_cpu(hwlat_per_cpu_data, cpu).kthread = NULL;
>> -
>>   	for_each_cpu(cpu, current_mask) {
>>   		retval = start_cpu_kthread(cpu);
>>   		if (retval)

Re: [PATCH] trace/hwlat: Do not restart per-cpu threads if they are already running

[Steven Rostedt]

On Thu, 2 Mar 2023 14:02:37 +0200
Tero Kristo <tero.kristo@linux.intel.com> wrote:

> Hi,
> 
> On 02/03/2023 13:49, Daniel Bristot de Oliveira wrote:
> > Hi Tero,
> >
> > On 3/2/23 08:36, Tero Kristo wrote:  
> >> Check if the hwlatd thread for the cpu is already running, before
> >> starting a new one. This avoids running multiple instances of the same
> >> CPU thread on the system. Also, do not wipe the contents of the
> >> per-cpu kthread data when starting the tracer, as this can completely
> >> forget about already running instances and start new additional per-cpu
> >> threads. Fixes issues where fiddling with either the mode of the hwlat
> >> tracer or doing cpu-hotplugs messes up the internal book-keeping
> >> resulting in stale hwlatd threads.  
> > Thanks for your patch.
> >
> > Would you mind explaining how do you hit the problem? that is, how can
> > I reproduce the same problem you faced.  
> 
> For example, this script snippet reproduces it for me every time:
> 
> #!/bin/sh
> cd /sys/kernel/debug/tracing
> echo 0 > tracing_on
> echo hwlat > current_tracer
> echo per-cpu > hwlat_detector/mode
> echo 100000 > hwlat_detector/width
> echo 200000 > hwlat_detector/window
> echo 200 > tracing_thresh
> echo 1 > tracing_on

I did the above and saw this:

 # ps aux | grep hwlat
root        1410 36.2  0.0      0     0 ?        R    18:10   0:22 [hwlatd/0]
root        1411 36.7  0.0      0     0 ?        R    18:10   0:22 [hwlatd/1]
root        1412 36.4  0.0      0     0 ?        R    18:10   0:22 [hwlatd/2]
root        1413 36.7  0.0      0     0 ?        R    18:10   0:22 [hwlatd/3]
root        1414 36.7  0.0      0     0 ?        R    18:10   0:22 [hwlatd/4]
root        1415 36.5  0.0      0     0 ?        R    18:10   0:22 [hwlatd/5]
root        1417 36.4  0.0      0     0 ?        R    18:10   0:22 [hwlatd/6]
root        1418 36.6  0.0      0     0 ?        S    18:10   0:22 [hwlatd/7]
root        1426 33.1  0.0      0     0 ?        R    18:10   0:11 [hwlatd/0]
root        1427 33.1  0.0      0     0 ?        R    18:10   0:11 [hwlatd/1]
root        1428 32.9  0.0      0     0 ?        R    18:10   0:11 [hwlatd/2]
root        1429 32.9  0.0      0     0 ?        R    18:10   0:11 [hwlatd/3]
root        1430 32.8  0.0      0     0 ?        R    18:10   0:11 [hwlatd/4]
root        1431 33.2  0.0      0     0 ?        R    18:10   0:11 [hwlatd/5]
root        1432 33.2  0.0      0     0 ?        R    18:10   0:11 [hwlatd/6]
root        1433 33.2  0.0      0     0 ?        S    18:10   0:11 [hwlatd/7]
root        1521  0.0  0.0   6332  2048 pts/0    S+   18:22   0:00 grep hwlat

Which I'm guessing is bad (having two of each hwlatd/#).

> 
> Another case where something wonky happens is if you offline/online a 
> large number of CPUs (which takes a lot of time), and you start/disable 
> the hwlat tracer at the same time.
> 

After applying the patch and running the same commands,  I have this:

 # ps aux | grep hwlat
root         768 40.7  0.0      0     0 ?        S    18:23   0:10 [hwlatd/0]
root         769 39.7  0.0      0     0 ?        R    18:23   0:10 [hwlatd/1]
root         770 39.8  0.0      0     0 ?        R    18:23   0:10 [hwlatd/2]
root         771 39.4  0.0      0     0 ?        R    18:23   0:10 [hwlatd/3]
root         772 40.5  0.0      0     0 ?        S    18:23   0:10 [hwlatd/4]
root         773 40.5  0.0      0     0 ?        R    18:23   0:10 [hwlatd/5]
root         775 41.0  0.0      0     0 ?        S    18:23   0:10 [hwlatd/6]
root         776 41.3  0.0      0     0 ?        R    18:23   0:10 [hwlatd/7]
root         781  0.0  0.0   6332  2048 pts/0    S+   18:25   0:00 grep hwlat

Looks as if this does fix the issue.

> >> diff --git a/kernel/trace/trace_hwlat.c b/kernel/trace/trace_hwlat.c
> >> index d440ddd5fd8b..c4945f8adc11 100644
> >> --- a/kernel/trace/trace_hwlat.c
> >> +++ b/kernel/trace/trace_hwlat.c
> >> @@ -492,6 +492,10 @@ static int start_cpu_kthread(unsigned int cpu)
> >>   {
> >>   	struct task_struct *kthread;
> >>   
> >> +	/* Do not start a new hwlatd thread if it is already running */
> >> +	if (per_cpu(hwlat_per_cpu_data, cpu).kthread)
> >> +		return 0;
> >> +
> >>   	kthread = kthread_run_on_cpu(kthread_fn, NULL, cpu, "hwlatd/%u");
> >>   	if (IS_ERR(kthread)) {
> >>   		pr_err(BANNER "could not start sampling thread\n");
> >> @@ -584,9 +588,6 @@ static int start_per_cpu_kthreads(struct trace_array *tr)
> >>   	 */
> >>   	cpumask_and(current_mask, cpu_online_mask, tr->tracing_cpumask);
> >>   
> >> -	for_each_online_cpu(cpu)
> >> -		per_cpu(hwlat_per_cpu_data, cpu).kthread = NULL;
> >> -

I believe this is two different bugs (the two hunks). This should be two
patches.

Please add the reproducer above to the commit log in a v2.

Thanks,

-- Steve


> >>   	for_each_cpu(cpu, current_mask) {
> >>   		retval = start_cpu_kthread(cpu);
> >>   		if (retval)