<html><body><div style="font-family: arial, helvetica, sans-serif; font-size: 12pt; color: #000000"><div><br></div><div><span id="zwchr" data-marker="__DIVIDER__">----- On Nov 26, 2015, at 10:58 AM, Luetkebohle Ingo (CR/AEA2) <Ingo.Luetkebohle@de.bosch.com> wrote:<br></span></div><div data-marker="__QUOTED_TEXT__"><blockquote style="border-left:2px solid #1010FF;margin-left:5px;padding-left:5px;color:#000;font-weight:normal;font-style:normal;text-decoration:none;font-family:Helvetica,Arial,sans-serif;font-size:12pt;"><style style="display:none"><!--P{margin-top:0;margin-bottom:0;} @font-face
{font-family:"Cambria Math"}
@font-face
{font-family:Calibri}
p.MsoNormal, li.MsoNormal, div.MsoNormal
{margin:0cm;
margin-bottom:.0001pt;
font-size:11.0pt;
font-family:"Calibri",sans-serif}
a:link, span.MsoHyperlink
{color:#0563C1;
text-decoration:underline}
a:visited, span.MsoHyperlinkFollowed
{color:#954F72;
text-decoration:underline}
span.EmailStyle17
{font-family:"Arial",sans-serif;
color:windowtext;
font-weight:normal;
font-style:normal}
.MsoChpDefault
{font-family:"Calibri",sans-serif}
@page WordSection1
{margin:70.85pt 70.85pt 2.0cm 70.85pt}
div.WordSection1
{}--></style><p>Hi Mathieu,</p><p><br></p><p>thank you for the explanation! </p><p><br></p><p>This would suggest that the problem only occurs for scheduler events, because only then we have this situation that the currently scheduled task is not the one that the tracepoint relates that. Am I interpreting that correctly?</p></blockquote><div>AFAIK, only the scheduler tracepoints pass a task struct as parameter (the one being<br></div><div>acted upon) that can differ from the current task. So yes, this kind of situation where a<br></div><div>tracepoint receives a task other than current as parameter pretty much only happens</div><div>in the scheduler instrumentation.<br data-mce-bogus="1"></div><blockquote style="border-left:2px solid #1010FF;margin-left:5px;padding-left:5px;color:#000;font-weight:normal;font-style:normal;text-decoration:none;font-family:Helvetica,Arial,sans-serif;font-size:12pt;"><p><br></p><p><br></p><p>If yes, this would certainly ease my concerns, because for most tracepoints, I get the expected behavior. I can also get the information that I want right now by looking at comm instead.<br></p><p><br></p><p>However, for future development of LTTng: Isn't the intuitive context that of the *tracepoint*? In other words, isn't it wrong to always use the currently scheduled task?</p></blockquote><div>By definition, the "current" task holds the current context, which is the<br></div><div>one saved in the tid/procname lttng context.<br data-mce-bogus="1"></div><div><br data-mce-bogus="1"></div><div>The task passed as parameter to the tracepoint is the task acted upon</div><div>in this case, not the currently running one anymore. Therefore, the "context" of the<br data-mce-bogus="1"></div><div>tracepoint _is_ the currently running task, not the one passed as parameter.<br data-mce-bogus="1"></div><div><br data-mce-bogus="1"></div><div>This highlights something that might not be obvious at first: when the scheduler<br data-mce-bogus="1"></div><div>puts a task into a sleeper queue, it does so while running in the context of the</div><div>newly scheduled task.<br data-mce-bogus="1"></div><div><br data-mce-bogus="1"></div><div>Thanks,<br data-mce-bogus="1"></div><div><br data-mce-bogus="1"></div><div>Mathieu<br data-mce-bogus="1"></div><div><br data-mce-bogus="1"></div><blockquote style="border-left:2px solid #1010FF;margin-left:5px;padding-left:5px;color:#000;font-weight:normal;font-style:normal;text-decoration:none;font-family:Helvetica,Arial,sans-serif;font-size:12pt;"><p><br></p><p><br></p><p>cheers,<br></p><p><br></p><div id="Signature"><div style="font-family:Calibri,Arial,Helvetica,sans-serif; font-size:; margin:0"><span style="color: black; font-family: Calibri,Arial,Helvetica,sans-serif; font-size: medium;" data-mce-style="color: black; font-family: Calibri,Arial,Helvetica,sans-serif; font-size: medium;" face="Calibri,Arial,Helvetica,sans-serif" color="black" size="3"><span dir="ltr" style="font-size:12pt; background-color:white"><span style="font-family: Arial,sans-serif; font-size: small;" data-mce-style="font-family: Arial,sans-serif; font-size: small;" face="Arial,sans-serif" size="2"><span style="font-size:10pt" lang="de"><b>Dr.
</b></span></span><span style="font-family: Arial,sans-serif; font-size: small;" data-mce-style="font-family: Arial,sans-serif; font-size: small;" face="Arial,sans-serif" size="2"><span style="font-size:10pt" lang="en-US"><b>Ingo Lütkebohle</b></span></span><span style="font-family: Arial,sans-serif; font-size: small;" data-mce-style="font-family: Arial,sans-serif; font-size: small;" face="Arial,sans-serif" size="2"><span style="font-size:10pt" lang="en-US"><b><br>
</b></span></span><span style="font-family: Arial,sans-serif; font-size: small;" data-mce-style="font-family: Arial,sans-serif; font-size: small;" face="Arial,sans-serif" size="2"><span style="font-size:10pt" lang="en-US">Software Design and Analysis -- Robotics (CR/AEA2)
</span></span><span style="font-family: Arial,sans-serif; font-size: small;" data-mce-style="font-family: Arial,sans-serif; font-size: small;" face="Arial,sans-serif" size="2"><span style="font-size:10pt" lang="en-US"><br>
</span></span><span style="font-family: Arial,sans-serif; font-size: small;" data-mce-style="font-family: Arial,sans-serif; font-size: small;" face="Arial,sans-serif" size="2"><span style="font-size:10pt" lang="en-US"><br>
Tel. </span></span><span style="font-family: Arial,sans-serif; font-size: small;" data-mce-style="font-family: Arial,sans-serif; font-size: small;" face="Arial,sans-serif" size="2"><span style="font-size:10pt" lang="de">+49(711)811-12248
</span></span><span style="font-family: Arial,sans-serif; font-size: small;" data-mce-style="font-family: Arial,sans-serif; font-size: small;" face="Arial,sans-serif" size="2"><span style="font-size:10pt" lang="de"><br>
Fax +49(711)811-0 </span></span><span style="font-family: Arial,sans-serif; font-size: small;" data-mce-style="font-family: Arial,sans-serif; font-size: small;" face="Arial,sans-serif" size="2"><span style="font-size:10pt" lang="de"><br>
Mobil +49-1525-8813417 </span></span><span style="font-family: Arial,sans-serif; font-size: small;" data-mce-style="font-family: Arial,sans-serif; font-size: small;" face="Arial,sans-serif" size="2"><span style="font-size:10pt" lang="de"><br>
</span></span><a id="NoLP" target="_blank" href="mailto:Ingo.Luetkebohle@de.bosch.com" tabindex="0"><span style="font-family: Calibri,sans-serif; font-size: small;" data-mce-style="font-family: Calibri,sans-serif; font-size: small;" face="Calibri,sans-serif" size="2"><span style="font-size:11pt" lang="de"><span style="font-family: Arial,sans-serif; font-size: small;" data-mce-style="font-family: Arial,sans-serif; font-size: small;" face="Arial,sans-serif" size="2"><span style="font-size:10pt">Ingo.Luetkebohle@de.bosch.com</span></span></span></span></a></span></span><br data-mce-bogus="1"></div></div><div style="color: rgb(33, 33, 33);"><hr style="display:inline-block; width:98%"><div id="divRplyFwdMsg" dir="ltr"><span style="font-size: 11pt; color: #000000; font-family: Calibri,sans-serif;" data-mce-style="font-size: 11pt; color: #000000; font-family: Calibri,sans-serif;" face="Calibri, sans-serif" color="#000000"><b>Von:</b> Mathieu Desnoyers <mathieu.desnoyers@efficios.com><br>
<b>Gesendet:</b> Donnerstag, 26. November 2015 16:21<br>
<b>An:</b> Luetkebohle Ingo (CR/AEA2)<br>
<b>Cc:</b> lttng-dev<br>
<b>Betreff:</b> Re: [lttng-dev] faulty context for sched_stat_ tracepoints?</span></div><div><div style="font-family:arial,helvetica,sans-serif; font-size:12pt; color:#000000"><div><span id="zwchr">---- On Nov 26, 2015, at 7:34 AM, Luetkebohle Ingo (CR/AEA2) <Ingo.Luetkebohle@de.bosch.com> wrote:<br>
</span></div><div><blockquote style="border-left:2px solid #1010FF; margin-left:5px; padding-left:5px; color:#000; font-weight:normal; font-style:normal; text-decoration:none; font-family:Helvetica,Arial,sans-serif; font-size:12pt"><style>
<!--
@font-face
{font-family:"Cambria Math"}
@font-face
{font-family:Calibri}
p.MsoNormal, li.MsoNormal, div.MsoNormal
{margin:0cm;
margin-bottom:.0001pt;
font-size:11.0pt;
font-family:"Calibri",sans-serif}
a:link, span.MsoHyperlink
{color:#0563C1;
text-decoration:underline}
a:visited, span.MsoHyperlinkFollowed
{color:#954F72;
text-decoration:underline}
span.EmailStyle17
{font-family:"Arial",sans-serif;
color:windowtext;
font-weight:normal;
font-style:normal}
.MsoChpDefault
{font-family:"Calibri",sans-serif}
@page WordSection1
{margin:70.85pt 70.85pt 2.0cm 70.85pt}
div.WordSection1
{}
-->
</style><div class="WordSection1"><p class="MsoNormal"><span style="font-size:10.0pt; font-family:"Arial",sans-serif" lang="EN-US">Hi,</span></p><p class="MsoNormal"><span style="font-size:10.0pt; font-family:"Arial",sans-serif" lang="EN-US"> </span></p><p class="MsoNormal"><span style="font-size:10.0pt; font-family:"Arial",sans-serif" lang="EN-US">I noticed that the “procname” and “tid” *<b>context</b>* variables can differ from the “comm” and “tid” variables of the sched_stat_-tracepoints (e.g., for sched_stat_runtime).</span></p><p class="MsoNormal"><span style="font-size:10.0pt; font-family:"Arial",sans-serif" lang="EN-US"> </span></p><p class="MsoNormal"><span style="font-size:10.0pt; font-family:"Arial",sans-serif" lang="EN-US">For example, see the following two outputs:</span></p><p class="MsoNormal"><span style="font-size:10.0pt; font-family:"Arial",sans-serif" lang="EN-US">[15:49:33.674072890] (+0.000029771) rng2070 sched_stat_sleep: { cpu_id = 4 }, { pid = 26974, procname = "amcl", tid = 26975 }, { comm = "lttng-sessiond", tid =
798, delay = 194122524 }</span></p><p class="MsoNormal"><span style="font-size:10.0pt; font-family:"Arial",sans-serif" lang="EN-US">[15:49:33.722894563] (+0.000004851) rng2070 sched_stat_sleep: { cpu_id = 0 }, { pid = 0, procname = "swapper/0", tid = 0 }, { comm = "amcl", tid = 27078, delay
= 10043658 }</span></p><p class="MsoNormal"><span style="font-size:10.0pt; font-family:"Arial",sans-serif" lang="EN-US"> </span></p><p class="MsoNormal"><span style="font-size:10.0pt; font-family:"Arial",sans-serif" lang="EN-US">In both cases, procname differs from comm. I’ve looked at the kernel source code, and the “comm” variable is taken from task_struct.filename. Barring renames,
this would be the correct one, so I’m assuming that the context is sometimes incorrect.</span></p><p class="MsoNormal"><span style="font-size:10.0pt; font-family:"Arial",sans-serif" lang="EN-US"> </span></p><p class="MsoNormal"><span style="font-size:10.0pt; font-family:"Arial",sans-serif" lang="EN-US">Now, for this particular case, I can take the correct variables from the tracepoint, but of course, this makes me worried that the context might also be wrong in
other cases… Do you have any idea what could be going on here?</span></p><p class="MsoNormal"><span style="font-size:10.0pt; font-family:"Arial",sans-serif" lang="EN-US"> </span></p><p class="MsoNormal"><span style="font-size:10.0pt; font-family:"Arial",sans-serif" lang="EN-US">LTTng is Version 2.7.x+stable+bzr2948+pack17+201511192116~ubuntu14.04.1 and this is on a 3.19.0-33-generic kernel (btw, that’s not the default kernel for Ubuntu
14.04, but the LTS vivid backport kernel).</span></p></div></blockquote><div>Hi,<br></div><div><br></div><div>Looking at lttng-modules lttng-context-tid.c tid_record(), we see that it uses task_pid_nr(current).<br></div><div>It therefore gets the tid of the currently scheduled task. This is similar for procname.<br></div><div><br></div><div>Now looking at the Linux kernel kernel/sched/fair.c: enqueue_sleeper(), which calls<br></div><div>trace_sched_stat_sleep(), we see that it passes "tsk" as parameter to the tracepoint.<br></div><div>Already here, nothing seems to ensure that "tsk" is the currently scheduled task. It's<br></div><div>rather a task that is being put to sleep. Looking at the callers of enqueue_sleeper(),<br></div><div>we can understand that the current task is first scheduled out before being enqueued<br></div><div>as a sleeper. This is why, when we hit the sched_stat_sleep tracepoint, the current<br></div><div>task is not "tsk", which explains the difference between the context information<br></div><div>and the tracepoint payload information: they really target different tasks.<br></div><div><br></div><div>Does this help solve your concerns ?<br></div><div><br></div><div>Thanks,<br></div><div><br></div><div>Mathieu<br></div><div><br></div><blockquote style="border-left:2px solid #1010FF; margin-left:5px; padding-left:5px; color:#000; font-weight:normal; font-style:normal; text-decoration:none; font-family:Helvetica,Arial,sans-serif; font-size:12pt"><div class="WordSection1"><p class="MsoNormal"><span style="font-size:10.0pt; font-family:"Arial",sans-serif" lang="EN-US"> </span></p><p class="MsoNormal"><span style="font-size:10.0pt; font-family:"Arial",sans-serif; color:black" lang="EN-US">Mit freundlichen Grüßen / Best regards
<br>
<br>
<b>Ingo Luetkebohle<br>
</b><br>
Application Software (CR/AEA2) <br>
Tel. +49(711)811-12248 | Fax +49(711)811-0 | </span><span style="font-size:10.0pt; font-family:"Arial",sans-serif; color:black"><a href="mailto:Ingo.Luetkebohle@de.bosch.com" target="_blank"><span style="color:blue" lang="EN-US">Ingo.Luetkebohle@de.bosch.com</span></a></span><span style="font-size:10.0pt; font-family:"Arial",sans-serif; color:black">
</span><span style="font-size:8.0pt; font-family:"Arial",sans-serif; color:black" lang="EN-US"><br>
</span><span style="font-size:10.0pt; font-family:"Arial",sans-serif; color:black" lang="EN-US"><br>
<br>
</span></p></div><br>
_______________________________________________<br>
lttng-dev mailing list<br>
lttng-dev@lists.lttng.org<br>
http://lists.lttng.org/cgi-bin/mailman/listinfo/lttng-dev<br></blockquote></div><div><br></div><div>-- <br></div><div>Mathieu Desnoyers<br>
EfficiOS Inc.<br>
http://www.efficios.com</div></div></div></div><br></blockquote></div><div><br></div><div data-marker="__SIG_POST__">-- <br></div><div>Mathieu Desnoyers<br>EfficiOS Inc.<br>http://www.efficios.com</div></div></body></html>