Re: [RFC PATCH 5/5] tracing: Add the osnoise tracer
On 4/14/21 7:14 PM, Steven Rostedt wrote: > On Thu, 8 Apr 2021 16:13:23 +0200 > Daniel Bristot de Oliveira wrote: > >> In the context of high-performance computing (HPC), the Operating System >> Noise (osnoise) refers to the interference experienced by an application >> due to activities inside the operating system. In the context of Linux, >> NMIs, IRQs, SoftIRQs, and any other system thread can cause noise to the >> system. Moreover, hardware-related jobs can also cause noise, for example, >> via SMIs. >> >> hwlat_detector is one of the tools used to identify the most complex >> source of noise: hardware noise. >> >> In a nutshell, the hwlat_detector creates a thread that runs >> periodically for a given period. At the beginning of a period, the thread >> disables interrupt and starts sampling. While running, the hwlatd >> thread reads the time in a loop. As interrupts are disabled, threads, >> IRQs, and SoftIRQs cannot interfere with the hwlatd thread. Hence, the >> cause of any gap between two different reads of the time roots either on >> NMI or in the hardware itself. At the end of the period, hwlatd enables >> interrupts and reports the max observed gap between the reads. It also >> prints an NMI occurrence counter. If the output does not report NMI >> executions, the user can conclude that the hardware is the culprit for >> the latency. The hwlat detects the NMI execution by observing >> the entry and exit of an NMI. >> >> The osnoise tracer leverages the hwlat_detector by running a >> similar loop with preemption, SoftIRQs and IRQs enabled, thus allowing >> all the sources of osnoise during its execution. Using the same approach >> of hwlat, osnoise takes note of the entry and exit point of any >> source of interferences, increasing a per-cpu interference counter. The >> osnoise tracer also saves an interference counter for each source of >> interference. The interference counter for NMI, IRQs, SoftIRQs, and >> threads is increased anytime the tool observes these interferences' entry >> events. When a noise happens without any interference from the operating >> system level, the hardware noise counter increases, pointing to a >> hardware-related noise. In this way, osnoise can account for any >> source of interference. At the end of the period, the osnoise tracer >> prints the sum of all noise, the max single noise, the percentage of CPU >> available for the thread, and the counters for the noise sources. >> >> Usage >> >> Write the ASCII text osnoise into the current_tracer file of the >> tracing system (generally mounted at /sys/kernel/tracing or >> /sys/kernel/debug/tracing). >> >> For example:: >> >> [root@f32 ~]# cd /sys/kernel/tracing/ >> [root@f32 tracing]# echo osnoise > current_tracer >> >> It is possible to follow the trace by reading the trace trace file:: >> >> [root@f32 tracing]# cat trace >> # tracer: osnoise >> # >> #_-=> irqs-off >> # / _=> need-resched >> # | / _---=> hardirq/softirq >> # || / _--=> preempt-depth >> MAX >> # || / >>SINGLE Interference counters: >> # RUNTIME NOISE >> % OF CPU NOISE+-+ >> # TASK-PID CPU# TIMESTAMPIN US IN US >> AVAILABLE IN US HWNMIIRQ SIRQ THREAD >> # | | | | | | >>|| | | | | | >><...>-859 [000] 81.637220: 100190 >> 99.98100 9 18 0 1007 18 1 >><...>-860 [001] 81.638154: 100656 >> 99.93440 74 23 0 1006 16 3 >><...>-861 [002] 81.638193: 100 5675 >> 99.43250 202 6 0 1013 25 21 >><...>-862 [003] 81.638242: 100125 >> 99.98750 45 1 0 1011 23 0 >><...>-863 [004] 81.638260: 100 1721 >> 99.82790 168 7 0 1002 49 41 >><...>-864 [005] 81.638286: 100263 >> 99.97370 57 6 0 1006 26 2 >><...>-865 [006] 81.638302: 100109 >> 99.98910 21 3 0 1006 18 1 >><...>-866 [007] 81.638326: 100 7816 >> 99.21840 107 8 0 1016 39 19 >> >> In addition to the regular trace fields (from TASK-PID to TIMESTAMP), the >> tracer prints a message at the end of each period
Re: [RFC PATCH 5/5] tracing: Add the osnoise tracer
On Thu, 8 Apr 2021 16:13:23 +0200 Daniel Bristot de Oliveira wrote: > In the context of high-performance computing (HPC), the Operating System > Noise (osnoise) refers to the interference experienced by an application > due to activities inside the operating system. In the context of Linux, > NMIs, IRQs, SoftIRQs, and any other system thread can cause noise to the > system. Moreover, hardware-related jobs can also cause noise, for example, > via SMIs. > > hwlat_detector is one of the tools used to identify the most complex > source of noise: hardware noise. > > In a nutshell, the hwlat_detector creates a thread that runs > periodically for a given period. At the beginning of a period, the thread > disables interrupt and starts sampling. While running, the hwlatd > thread reads the time in a loop. As interrupts are disabled, threads, > IRQs, and SoftIRQs cannot interfere with the hwlatd thread. Hence, the > cause of any gap between two different reads of the time roots either on > NMI or in the hardware itself. At the end of the period, hwlatd enables > interrupts and reports the max observed gap between the reads. It also > prints an NMI occurrence counter. If the output does not report NMI > executions, the user can conclude that the hardware is the culprit for > the latency. The hwlat detects the NMI execution by observing > the entry and exit of an NMI. > > The osnoise tracer leverages the hwlat_detector by running a > similar loop with preemption, SoftIRQs and IRQs enabled, thus allowing > all the sources of osnoise during its execution. Using the same approach > of hwlat, osnoise takes note of the entry and exit point of any > source of interferences, increasing a per-cpu interference counter. The > osnoise tracer also saves an interference counter for each source of > interference. The interference counter for NMI, IRQs, SoftIRQs, and > threads is increased anytime the tool observes these interferences' entry > events. When a noise happens without any interference from the operating > system level, the hardware noise counter increases, pointing to a > hardware-related noise. In this way, osnoise can account for any > source of interference. At the end of the period, the osnoise tracer > prints the sum of all noise, the max single noise, the percentage of CPU > available for the thread, and the counters for the noise sources. > > Usage > > Write the ASCII text osnoise into the current_tracer file of the > tracing system (generally mounted at /sys/kernel/tracing or > /sys/kernel/debug/tracing). > > For example:: > > [root@f32 ~]# cd /sys/kernel/tracing/ > [root@f32 tracing]# echo osnoise > current_tracer > > It is possible to follow the trace by reading the trace trace file:: > > [root@f32 tracing]# cat trace > # tracer: osnoise > # > #_-=> irqs-off > # / _=> need-resched > # | / _---=> hardirq/softirq > # || / _--=> preempt-depth > MAX > # || / > SINGLE Interference counters: > # RUNTIME NOISE > % OF CPU NOISE+-+ > # TASK-PID CPU# TIMESTAMPIN US IN US > AVAILABLE IN US HWNMIIRQ SIRQ THREAD > # | | | | | | > || | | | | | ><...>-859 [000] 81.637220: 100190 > 99.98100 9 18 0 1007 18 1 ><...>-860 [001] 81.638154: 100656 > 99.93440 74 23 0 1006 16 3 ><...>-861 [002] 81.638193: 100 5675 > 99.43250 202 6 0 1013 25 21 ><...>-862 [003] 81.638242: 100125 > 99.98750 45 1 0 1011 23 0 ><...>-863 [004] 81.638260: 100 1721 > 99.82790 168 7 0 1002 49 41 ><...>-864 [005] 81.638286: 100263 > 99.97370 57 6 0 1006 26 2 ><...>-865 [006] 81.638302: 100109 > 99.98910 21 3 0 1006 18 1 ><...>-866 [007] 81.638326: 100 7816 > 99.21840 107 8 0 1016 39 19 > > In addition to the regular trace fields (from TASK-PID to TIMESTAMP), the > tracer prints a message at the end of each period for each CPU that is > running an osnoise/ thread. The osnoise specific fields report: > > - The RUNTIME IN USE reports t
Re: [RFC PATCH 5/5] tracing: Add the osnoise tracer
On 4/8/21 5:58 PM, Jonathan Corbet wrote: > Daniel Bristot de Oliveira writes: > > A quick nit: > >> Documentation/trace/osnoise_tracer.rst | 149 ++ >> include/linux/ftrace_irq.h | 16 + >> include/trace/events/osnoise.h | 141 ++ >> kernel/trace/Kconfig | 34 + >> kernel/trace/Makefile |1 + >> kernel/trace/trace.h |9 +- >> kernel/trace/trace_entries.h | 27 + >> kernel/trace/trace_osnoise.c | 1714 >> kernel/trace/trace_output.c| 72 +- >> 9 files changed, 2159 insertions(+), 4 deletions(-) >> create mode 100644 Documentation/trace/osnoise_tracer.rst >> create mode 100644 include/trace/events/osnoise.h >> create mode 100644 kernel/trace/trace_osnoise.c > When you create a new RST file, you need to add it to an index.rst (or > similar) file so that it gets incorporated into the docs build. ack! > > The document itself looks good on a quick read. If you're making > another pass over it, you might consider reducing the ``markup noise`` a > bit; we try to keep that to a minimum in the kernel docs. But otherwise > thanks for writing it! Thanks for the review, Jon. I will reduce the `` markup (on this, and on some other docs that are about to come :-)) -- Daniel > jon >
Re: [RFC PATCH 5/5] tracing: Add the osnoise tracer
Daniel Bristot de Oliveira writes: A quick nit: > Documentation/trace/osnoise_tracer.rst | 149 ++ > include/linux/ftrace_irq.h | 16 + > include/trace/events/osnoise.h | 141 ++ > kernel/trace/Kconfig | 34 + > kernel/trace/Makefile |1 + > kernel/trace/trace.h |9 +- > kernel/trace/trace_entries.h | 27 + > kernel/trace/trace_osnoise.c | 1714 > kernel/trace/trace_output.c| 72 +- > 9 files changed, 2159 insertions(+), 4 deletions(-) > create mode 100644 Documentation/trace/osnoise_tracer.rst > create mode 100644 include/trace/events/osnoise.h > create mode 100644 kernel/trace/trace_osnoise.c When you create a new RST file, you need to add it to an index.rst (or similar) file so that it gets incorporated into the docs build. The document itself looks good on a quick read. If you're making another pass over it, you might consider reducing the ``markup noise`` a bit; we try to keep that to a minimum in the kernel docs. But otherwise thanks for writing it! jon
[RFC PATCH 5/5] tracing: Add the osnoise tracer
In the context of high-performance computing (HPC), the Operating System Noise (osnoise) refers to the interference experienced by an application due to activities inside the operating system. In the context of Linux, NMIs, IRQs, SoftIRQs, and any other system thread can cause noise to the system. Moreover, hardware-related jobs can also cause noise, for example, via SMIs. hwlat_detector is one of the tools used to identify the most complex source of noise: hardware noise. In a nutshell, the hwlat_detector creates a thread that runs periodically for a given period. At the beginning of a period, the thread disables interrupt and starts sampling. While running, the hwlatd thread reads the time in a loop. As interrupts are disabled, threads, IRQs, and SoftIRQs cannot interfere with the hwlatd thread. Hence, the cause of any gap between two different reads of the time roots either on NMI or in the hardware itself. At the end of the period, hwlatd enables interrupts and reports the max observed gap between the reads. It also prints an NMI occurrence counter. If the output does not report NMI executions, the user can conclude that the hardware is the culprit for the latency. The hwlat detects the NMI execution by observing the entry and exit of an NMI. The osnoise tracer leverages the hwlat_detector by running a similar loop with preemption, SoftIRQs and IRQs enabled, thus allowing all the sources of osnoise during its execution. Using the same approach of hwlat, osnoise takes note of the entry and exit point of any source of interferences, increasing a per-cpu interference counter. The osnoise tracer also saves an interference counter for each source of interference. The interference counter for NMI, IRQs, SoftIRQs, and threads is increased anytime the tool observes these interferences' entry events. When a noise happens without any interference from the operating system level, the hardware noise counter increases, pointing to a hardware-related noise. In this way, osnoise can account for any source of interference. At the end of the period, the osnoise tracer prints the sum of all noise, the max single noise, the percentage of CPU available for the thread, and the counters for the noise sources. Usage Write the ASCII text osnoise into the current_tracer file of the tracing system (generally mounted at /sys/kernel/tracing or /sys/kernel/debug/tracing). For example:: [root@f32 ~]# cd /sys/kernel/tracing/ [root@f32 tracing]# echo osnoise > current_tracer It is possible to follow the trace by reading the trace trace file:: [root@f32 tracing]# cat trace # tracer: osnoise # #_-=> irqs-off # / _=> need-resched # | / _---=> hardirq/softirq # || / _--=> preempt-depth MAX # || / SINGLE Interference counters: # RUNTIME NOISE % OF CPU NOISE+-+ # TASK-PID CPU# TIMESTAMPIN US IN US AVAILABLE IN US HWNMIIRQ SIRQ THREAD # | | | | | | || | | | | | <...>-859 [000] 81.637220: 100190 99.98100 9 18 0 1007 18 1 <...>-860 [001] 81.638154: 100656 99.93440 74 23 0 1006 16 3 <...>-861 [002] 81.638193: 100 5675 99.43250 202 6 0 1013 25 21 <...>-862 [003] 81.638242: 100125 99.98750 45 1 0 1011 23 0 <...>-863 [004] 81.638260: 100 1721 99.82790 168 7 0 1002 49 41 <...>-864 [005] 81.638286: 100263 99.97370 57 6 0 1006 26 2 <...>-865 [006] 81.638302: 100109 99.98910 21 3 0 1006 18 1 <...>-866 [007] 81.638326: 100 7816 99.21840 107 8 0 1016 39 19 In addition to the regular trace fields (from TASK-PID to TIMESTAMP), the tracer prints a message at the end of each period for each CPU that is running an osnoise/ thread. The osnoise specific fields report: - The RUNTIME IN USE reports the amount of time in microseconds that the osnoise thread kept looping reading the time. - The NOISE IN US reports the sum of noise in microseconds observed by the osnoise tracer during the associated runtime. - The % OF CPU AVAILABLE report
