Kernelshark: funcgraph_exit events don't seem to exit?

Kernelshark: funcgraph_exit events don't seem to exit?

[Matteo Bertolino]

Dear community, 
In order to explain my problem, I need to ask you to have a look to the visual trace in my github (I cannot attach it to the mail nor using an image uploading service): https://github.com/the-red-robin/trace-cmd-experiments/blob/main/README.md 

In the trace, we have one CPU, CPU0. On it:
- `Task3` runs `foo5()` at time 8.000000 cycles
- `Task2` takes place running `foo3()` at time 8.010000 cycles.
- `Task1` takes place running `foo1()` at time 8.060000 cycles.
For now, everything OK.
Then, I wish to `exit` the three tasks.

- `Task1` exits at 8.090000 cycles. Here the trace does not show what I expect, namely `Task1` (in red) shall end at 8.090000 cycles. Instead, there is a red trace until the beginning of the next exit event, `Task2` at 8.130000.

This doesn't seem an `exit` event. Do you have any suggestions to show what I wish on Kernelshark?

Best Regards,
Matteo

Re: Kernelshark: funcgraph_exit events don't seem to exit?

[Yordan Karadzhov]

Hi Matteo,
Thanks for reporting this issue!

I understand what you would like to see being visualized, but 
unfortunately this is different from the implemented generic logic of 
the visualization model that changes the color at the place of the first 
event that belongs to the new task. Note that this generic logic is 
expected to provide adequate visualization for all types of events, 
while the behavior that you would like to see makes sense only for very 
specific events.

However, what you want is actually very easy to achieve. You just have 
to write a kernelshark plugin for funcgraph_exit events. If you are 
interested in contributing such plugin to kernelshark, I can send you 
instructions what has to be done. It will be really trivial work.

cheers,
Yordan


On 9/6/22 12:29, Matteo Bertolino wrote:
> Dear community,
> In order to explain my problem, I need to ask you to have a look to the visual trace in my github (I cannot attach it to the mail nor using an image uploading service): https://github.com/the-red-robin/trace-cmd-experiments/blob/main/README.md
> 
> In the trace, we have one CPU, CPU0. On it:
> - `Task3` runs `foo5()` at time 8.000000 cycles
> - `Task2` takes place running `foo3()` at time 8.010000 cycles.
> - `Task1` takes place running `foo1()` at time 8.060000 cycles.
> For now, everything OK.
> Then, I wish to `exit` the three tasks.
> 
> - `Task1` exits at 8.090000 cycles. Here the trace does not show what I expect, namely `Task1` (in red) shall end at 8.090000 cycles. Instead, there is a red trace until the beginning of the next exit event, `Task2` at 8.130000.
> 
> This doesn't seem an `exit` event. Do you have any suggestions to show what I wish on Kernelshark?
> 
> Best Regards,
> Matteo

RE: Kernelshark: funcgraph_exit events don't seem to exit?

[Matteo Bertolino]

Dear Yordan,
Thanks for your reply!

I would like to do a double check to be sure that we're on the same rail. 
Can you please take my screenshot again? Between 8.090000 and 8.130000 the trace doesn't provide any information.

We don't know whether:
A) task1 continues after the end of foo1 running something else that is not traced
Or
B) The CPU is idle/a non-traced task is running.

Today, the default behavior of kernelshark is A). Indeed, in my screenshot, the bar indicated by the light-blue arrow is red.

Instead, I wish to code a plugin with a third option:
C) when we do not know what happens, just color with gray.

Do your instructions cover this case? 
If so, I would like to have some hints and I will try to implement it :-)

Best Regards,
Matteo

-----Original Message-----
From: Yordan Karadzhov [mailto:y.karadz@gmail.com] 
Sent: Tuesday, September 6, 2022 12:45 PM
To: Matteo Bertolino <matteo.bertolino@huawei.com>; linux-trace-users@vger.kernel.org
Subject: Re: Kernelshark: funcgraph_exit events don't seem to exit?

Hi Matteo,
Thanks for reporting this issue!

I understand what you would like to see being visualized, but 
unfortunately this is different from the implemented generic logic of 
the visualization model that changes the color at the place of the first 
event that belongs to the new task. Note that this generic logic is 
expected to provide adequate visualization for all types of events, 
while the behavior that you would like to see makes sense only for very 
specific events.

However, what you want is actually very easy to achieve. You just have 
to write a kernelshark plugin for funcgraph_exit events. If you are 
interested in contributing such plugin to kernelshark, I can send you 
instructions what has to be done. It will be really trivial work.

cheers,
Yordan


On 9/6/22 12:29, Matteo Bertolino wrote:
> Dear community,
> In order to explain my problem, I need to ask you to have a look to the visual trace in my github (I cannot attach it to the mail nor using an image uploading service): https://github.com/the-red-robin/trace-cmd-experiments/blob/main/README.md
> 
> In the trace, we have one CPU, CPU0. On it:
> - `Task3` runs `foo5()` at time 8.000000 cycles
> - `Task2` takes place running `foo3()` at time 8.010000 cycles.
> - `Task1` takes place running `foo1()` at time 8.060000 cycles.
> For now, everything OK.
> Then, I wish to `exit` the three tasks.
> 
> - `Task1` exits at 8.090000 cycles. Here the trace does not show what I expect, namely `Task1` (in red) shall end at 8.090000 cycles. Instead, there is a red trace until the beginning of the next exit event, `Task2` at 8.130000.
> 
> This doesn't seem an `exit` event. Do you have any suggestions to show what I wish on Kernelshark?
> 
> Best Regards,
> Matteo

Re: Kernelshark: funcgraph_exit events don't seem to exit?

[Yordan Karadzhov]

Hi Matteo,

I confirm that the logic that you want can be implemented via plugin. 
However, there is even simpler way to accomplish what you want. When 
recording your trace, enable the 'sched_switch' events. This way in your 
data you will know exactly when the execution switches form one task to 
another (or to idle). The good thing here is that KernelShark already 
has a plugin for 'sched_switch' end you will see a the behavior that you 
expect.

cheers,
Y.


On 9/6/22 14:57, Matteo Bertolino wrote:
> Dear Yordan,
> Thanks for your reply!
> 
> I would like to do a double check to be sure that we're on the same rail.
> Can you please take my screenshot again? Between 8.090000 and 8.130000 the trace doesn't provide any information.
> 
> We don't know whether:
> A) task1 continues after the end of foo1 running something else that is not traced
> Or
> B) The CPU is idle/a non-traced task is running.
> 
> Today, the default behavior of kernelshark is A). Indeed, in my screenshot, the bar indicated by the light-blue arrow is red.
> 
> Instead, I wish to code a plugin with a third option:
> C) when we do not know what happens, just color with gray.
> 
> Do your instructions cover this case?
> If so, I would like to have some hints and I will try to implement it :-)
> 
> Best Regards,
> Matteo
> 
> -----Original Message-----
> From: Yordan Karadzhov [mailto:y.karadz@gmail.com]
> Sent: Tuesday, September 6, 2022 12:45 PM
> To: Matteo Bertolino <matteo.bertolino@huawei.com>; linux-trace-users@vger.kernel.org
> Subject: Re: Kernelshark: funcgraph_exit events don't seem to exit?
> 
> Hi Matteo,
> Thanks for reporting this issue!
> 
> I understand what you would like to see being visualized, but
> unfortunately this is different from the implemented generic logic of
> the visualization model that changes the color at the place of the first
> event that belongs to the new task. Note that this generic logic is
> expected to provide adequate visualization for all types of events,
> while the behavior that you would like to see makes sense only for very
> specific events.
> 
> However, what you want is actually very easy to achieve. You just have
> to write a kernelshark plugin for funcgraph_exit events. If you are
> interested in contributing such plugin to kernelshark, I can send you
> instructions what has to be done. It will be really trivial work.
> 
> cheers,
> Yordan
> 
> 
> On 9/6/22 12:29, Matteo Bertolino wrote:
>> Dear community,
>> In order to explain my problem, I need to ask you to have a look to the visual trace in my github (I cannot attach it to the mail nor using an image uploading service): https://github.com/the-red-robin/trace-cmd-experiments/blob/main/README.md
>>
>> In the trace, we have one CPU, CPU0. On it:
>> - `Task3` runs `foo5()` at time 8.000000 cycles
>> - `Task2` takes place running `foo3()` at time 8.010000 cycles.
>> - `Task1` takes place running `foo1()` at time 8.060000 cycles.
>> For now, everything OK.
>> Then, I wish to `exit` the three tasks.
>>
>> - `Task1` exits at 8.090000 cycles. Here the trace does not show what I expect, namely `Task1` (in red) shall end at 8.090000 cycles. Instead, there is a red trace until the beginning of the next exit event, `Task2` at 8.130000.
>>
>> This doesn't seem an `exit` event. Do you have any suggestions to show what I wish on Kernelshark?
>>
>> Best Regards,
>> Matteo

RE: Kernelshark: funcgraph_exit events don't seem to exit?

[Matteo Bertolino]

Hello Yordan,
Thanks again for your precious answers!

I got your point. Honestly, I would like to avoid to register the `sched_switch`. 
Because of my current needs, I prefer to record few things (with strong filters).

So, often, I may have in my trace big temporal gaps in which I don't know whether a task X
is still running with a function that I don't record, or a task Y that I don't record at all, or idle.

In all these `uncertain` cases, I'd like to simply color the timebar with a gray shape.

If that doesn't annoy you too much, may you give me some hints about writing a Kernelshark's plugin? 
Thanks!
Matteo

-----Original Message-----
From: Yordan Karadzhov [mailto:y.karadz@gmail.com] 
Sent: Tuesday, September 6, 2022 8:01 PM
To: Matteo Bertolino <matteo.bertolino@huawei.com>; linux-trace-users@vger.kernel.org
Subject: Re: Kernelshark: funcgraph_exit events don't seem to exit?

Hi Matteo,

I confirm that the logic that you want can be implemented via plugin. 
However, there is even simpler way to accomplish what you want. When recording your trace, enable the 'sched_switch' events. This way in your data you will know exactly when the execution switches form one task to another (or to idle). The good thing here is that KernelShark already has a plugin for 'sched_switch' end you will see a the behavior that you expect.

cheers,
Y.


On 9/6/22 14:57, Matteo Bertolino wrote:
> Dear Yordan,
> Thanks for your reply!
> 
> I would like to do a double check to be sure that we're on the same rail.
> Can you please take my screenshot again? Between 8.090000 and 8.130000 the trace doesn't provide any information.
> 
> We don't know whether:
> A) task1 continues after the end of foo1 running something else that 
> is not traced Or
> B) The CPU is idle/a non-traced task is running.
> 
> Today, the default behavior of kernelshark is A). Indeed, in my screenshot, the bar indicated by the light-blue arrow is red.
> 
> Instead, I wish to code a plugin with a third option:
> C) when we do not know what happens, just color with gray.
> 
> Do your instructions cover this case?
> If so, I would like to have some hints and I will try to implement it 
> :-)
> 
> Best Regards,
> Matteo
> 
> -----Original Message-----
> From: Yordan Karadzhov [mailto:y.karadz@gmail.com]
> Sent: Tuesday, September 6, 2022 12:45 PM
> To: Matteo Bertolino <matteo.bertolino@huawei.com>; 
> linux-trace-users@vger.kernel.org
> Subject: Re: Kernelshark: funcgraph_exit events don't seem to exit?
> 
> Hi Matteo,
> Thanks for reporting this issue!
> 
> I understand what you would like to see being visualized, but 
> unfortunately this is different from the implemented generic logic of 
> the visualization model that changes the color at the place of the 
> first event that belongs to the new task. Note that this generic logic 
> is expected to provide adequate visualization for all types of events, 
> while the behavior that you would like to see makes sense only for 
> very specific events.
> 
> However, what you want is actually very easy to achieve. You just have 
> to write a kernelshark plugin for funcgraph_exit events. If you are 
> interested in contributing such plugin to kernelshark, I can send you 
> instructions what has to be done. It will be really trivial work.
> 
> cheers,
> Yordan
> 
> 
> On 9/6/22 12:29, Matteo Bertolino wrote:
>> Dear community,
>> In order to explain my problem, I need to ask you to have a look to 
>> the visual trace in my github (I cannot attach it to the mail nor 
>> using an image uploading service): 
>> https://github.com/the-red-robin/trace-cmd-experiments/blob/main/READ
>> ME.md
>>
>> In the trace, we have one CPU, CPU0. On it:
>> - `Task3` runs `foo5()` at time 8.000000 cycles
>> - `Task2` takes place running `foo3()` at time 8.010000 cycles.
>> - `Task1` takes place running `foo1()` at time 8.060000 cycles.
>> For now, everything OK.
>> Then, I wish to `exit` the three tasks.
>>
>> - `Task1` exits at 8.090000 cycles. Here the trace does not show what I expect, namely `Task1` (in red) shall end at 8.090000 cycles. Instead, there is a red trace until the beginning of the next exit event, `Task2` at 8.130000.
>>
>> This doesn't seem an `exit` event. Do you have any suggestions to show what I wish on Kernelshark?
>>
>> Best Regards,
>> Matteo

Re: Kernelshark: funcgraph_exit events don't seem to exit?

[Yordan Karadzhov]

Hi Matteo,

On 9/7/22 11:08, Matteo Bertolino wrote:
> If that doesn't annoy you too much, may you give me some hints about writing a Kernelshark's plugin?

As I already mentioned, we have a plugin for sched events, so you can 
use this plugin as starting point, despite that your plugin will be by 
far simpler.

Have a look here
https://git.kernel.org/pub/scm/utils/trace-cmd/kernel-shark.git/tree/src/plugins/sched_events.h

and here
https://git.kernel.org/pub/scm/utils/trace-cmd/kernel-shark.git/tree/src/plugins/sched_events.c

and see how you can define a context object for your plugin and how you 
can register a plugin action that will be executed over each entry in 
the data that is event of a given type. Example of such action for 
sched_switch events:
https://git.kernel.org/pub/scm/utils/trace-cmd/kernel-shark.git/tree/src/plugins/sched_events.c#n102

As a first step, try to register a plugin action for the 
'funcgraph_exit' event that will set the 'pid' of the entry to 'idle'

entry->pid = stream->idle_pid

This will be enough to have half of the work done.

You can build your plugin, using the 'BUILD_PLUGIN' macro here:
https://git.kernel.org/pub/scm/utils/trace-cmd/kernel-shark.git/tree/src/plugins/CMakeLists.txt

Let me know when you are ready with this and we will figure out how to 
implement the other features that you want.

cheers,
Yordan