[PATCH 0/3] trace: seperate cold path of trace

[PATCH 0/3] trace: seperate cold path of trace

[Tanish Desai]

This patch continues the optimize fast trace paths started in previous patch (trace/simple: seperate hot paths of tracing fucntions), which optimized the simple backend by moving its hot path to the header. Here, we apply the same pattern to the log, ftrace, and syslog backends.
The fast path remains in the header with minimal inline checks, while the backend-specific logic is now handled in dedicated `_log_trace_vhost_commit()`, `_ftrace_trace_vhost_commit()`, and `_syslog_trace_vhost_commit()` functions in the .c file.
While this doesn’t yield the same level of optimization as the simple backend , it improves performance on compilers where inlining is less reliable and reduces header bloat.
This change also improves code organization:
- All trace event checks are now centralized in headers
- All backend logic is contained in clearly named functions in the .c file
This makes the tracing infrastructure cleaner, more maintainable, and better optimized for diverse compiler behaviors.

Tanish Desai (3):
  trace/syslog: seperate cold paths of tracing functions
  trace/ftrace: seperate cold paths of tracing functions
  trace/log: seperate cold path of tracing functions

 scripts/tracetool/backend/ftrace.py | 44 +++++++++++++++++++++--------
 scripts/tracetool/backend/log.py    | 26 +++++++++++++++--
 scripts/tracetool/backend/syslog.py | 36 ++++++++++++++++++-----
 3 files changed, 85 insertions(+), 21 deletions(-)

-- 
2.34.1

[PATCH 1/3] trace/syslog: seperate cold paths of tracing functions

[Tanish Desai]

inline: move hot paths from .c to .h for better performance
Moved frequently used hot paths from the .c file to the .h file to enable inlining
and improve performance. This approach is inspired by past QEMU optimizations,
where performance-critical code was inlined based on profiling results.

Signed-off-by: Tanish Desai <tanishdesai37@gmail.com>
---
 scripts/tracetool/backend/syslog.py | 36 +++++++++++++++++++++++------
 1 file changed, 29 insertions(+), 7 deletions(-)

diff --git a/scripts/tracetool/backend/syslog.py b/scripts/tracetool/backend/syslog.py
index 012970f6cc..52b8ff65ea 100644
--- a/scripts/tracetool/backend/syslog.py
+++ b/scripts/tracetool/backend/syslog.py
@@ -21,8 +21,12 @@
 
 
 def generate_h_begin(events, group):
-    out('#include <syslog.h>',
-        '')
+    out('#include <syslog.h>')
+    for event in events:
+        out('void _syslog_%(api)s(%(args)s);',
+            api=event.api(),
+            args=event.args)
+    out('')
 
 
 def generate_h(event, group):
@@ -37,17 +41,35 @@ def generate_h(event, group):
         cond = "trace_event_get_state(%s)" % ("TRACE_" + event.name.upper())
 
     out('    if (%(cond)s) {',
-        '#line %(event_lineno)d "%(event_filename)s"',
-        '        syslog(LOG_INFO, "%(name)s " %(fmt)s %(argnames)s);',
-        '#line %(out_next_lineno)d "%(out_filename)s"',
+            '       _syslog_%(api)s(%(args)s);',
         '    }',
         cond=cond,
         event_lineno=event.lineno,
         event_filename=os.path.relpath(event.filename),
         name=event.name,
         fmt=event.fmt.rstrip("\n"),
-        argnames=argnames)
-
+        argnames=argnames,
+        api=event.api(),
+        args=", ".join(event.args.names()))
+
+
+def generate_c(event, group):
+        argnames = ", ".join(event.args.names())
+        if len(event.args) > 0:
+            argnames = ", " + argnames
+        out('void _syslog_%(api)s(%(args)s){',
+        '   #line %(event_lineno)d "%(event_filename)s"',
+        '            syslog(LOG_INFO, "%(name)s " %(fmt)s %(argnames)s);',
+        '   #line %(out_next_lineno)d "%(out_filename)s"',
+        '}',
+        '',
+        event_lineno=event.lineno,
+        event_filename=os.path.relpath(event.filename),
+        name=event.name,
+        fmt=event.fmt.rstrip("\n"),
+        argnames=argnames,
+        api=event.api(),
+        args=event.args)    
 
 def generate_h_backend_dstate(event, group):
     out('    trace_event_get_state_dynamic_by_id(%(event_id)s) || \\',
-- 
2.34.1

Re: [PATCH 1/3] trace/syslog: seperate cold paths of tracing functions

[Stefan Hajnoczi]

[-- Attachment #1: Type: text/plain, Size: 3006 bytes --]

On Sun, Jun 01, 2025 at 06:12:29PM +0000, Tanish Desai wrote:
> inline: move hot paths from .c to .h for better performance
> Moved frequently used hot paths from the .c file to the .h file to enable inlining
> and improve performance. This approach is inspired by past QEMU optimizations,
> where performance-critical code was inlined based on profiling results.
> 
> Signed-off-by: Tanish Desai <tanishdesai37@gmail.com>
> ---
>  scripts/tracetool/backend/syslog.py | 36 +++++++++++++++++++++++------
>  1 file changed, 29 insertions(+), 7 deletions(-)

This commit description doesn't match what the patch does.

What is the purpose of creating a _syslog_trace_foo() function in the .c
file instead of calling syslog() directly from the .h file?

> 
> diff --git a/scripts/tracetool/backend/syslog.py b/scripts/tracetool/backend/syslog.py
> index 012970f6cc..52b8ff65ea 100644
> --- a/scripts/tracetool/backend/syslog.py
> +++ b/scripts/tracetool/backend/syslog.py
> @@ -21,8 +21,12 @@
>  
>  
>  def generate_h_begin(events, group):
> -    out('#include <syslog.h>',
> -        '')
> +    out('#include <syslog.h>')
> +    for event in events:
> +        out('void _syslog_%(api)s(%(args)s);',
> +            api=event.api(),
> +            args=event.args)
> +    out('')
>  
>  
>  def generate_h(event, group):
> @@ -37,17 +41,35 @@ def generate_h(event, group):
>          cond = "trace_event_get_state(%s)" % ("TRACE_" + event.name.upper())
>  
>      out('    if (%(cond)s) {',
> -        '#line %(event_lineno)d "%(event_filename)s"',
> -        '        syslog(LOG_INFO, "%(name)s " %(fmt)s %(argnames)s);',
> -        '#line %(out_next_lineno)d "%(out_filename)s"',
> +            '       _syslog_%(api)s(%(args)s);',
>          '    }',
>          cond=cond,
>          event_lineno=event.lineno,
>          event_filename=os.path.relpath(event.filename),
>          name=event.name,
>          fmt=event.fmt.rstrip("\n"),
> -        argnames=argnames)
> -
> +        argnames=argnames,
> +        api=event.api(),
> +        args=", ".join(event.args.names()))
> +
> +
> +def generate_c(event, group):
> +        argnames = ", ".join(event.args.names())
> +        if len(event.args) > 0:
> +            argnames = ", " + argnames
> +        out('void _syslog_%(api)s(%(args)s){',
> +        '   #line %(event_lineno)d "%(event_filename)s"',
> +        '            syslog(LOG_INFO, "%(name)s " %(fmt)s %(argnames)s);',
> +        '   #line %(out_next_lineno)d "%(out_filename)s"',
> +        '}',
> +        '',
> +        event_lineno=event.lineno,
> +        event_filename=os.path.relpath(event.filename),
> +        name=event.name,
> +        fmt=event.fmt.rstrip("\n"),
> +        argnames=argnames,
> +        api=event.api(),
> +        args=event.args)    
>  
>  def generate_h_backend_dstate(event, group):
>      out('    trace_event_get_state_dynamic_by_id(%(event_id)s) || \\',
> -- 
> 2.34.1
> 

[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 488 bytes --]

Re: [PATCH 1/3] trace/syslog: seperate cold paths of tracing functions

[Tanish Desai]

[-- Attachment #1: Type: text/plain, Size: 4212 bytes --]

Yes, you're right—there was a mistake in the original commit description.
In this change, we're moving cold paths out of the header (.h) files and
into corresponding source (.c) files. The primary motivation is to avoid
replicating the cold path logic across every translation unit that includes
trace.h (which includes trace-*.h headers).
For the syslog backend, which involves only a single function call, this
change won't have a noticeable impact. However, for the ftrace and log
backends, where functions like _ftrace_trace_foo() and _log_trace_foo() contain
more complex logic, this avoids significant duplication. By centralizing
the implementation in .c files, we expect to save memory and reduce binary
size.
Paolo and I are still experimenting to quantify these memory savings. So
far, we haven’t observed substantial gains, but we're refining our
measurements and isolating symbols more carefully to get accurate binary
size comparisons.

On Tue, Jun 3, 2025 at 3:56 AM Stefan Hajnoczi <stefanha@redhat.com> wrote:

> On Sun, Jun 01, 2025 at 06:12:29PM +0000, Tanish Desai wrote:
> > inline: move hot paths from .c to .h for better performance
> > Moved frequently used hot paths from the .c file to the .h file to
> enable inlining
> > and improve performance. This approach is inspired by past QEMU
> optimizations,
> > where performance-critical code was inlined based on profiling results.
> >
> > Signed-off-by: Tanish Desai <tanishdesai37@gmail.com>
> > ---
> >  scripts/tracetool/backend/syslog.py | 36 +++++++++++++++++++++++------
> >  1 file changed, 29 insertions(+), 7 deletions(-)
>
> This commit description doesn't match what the patch does.
>
> What is the purpose of creating a _syslog_trace_foo() function in the .c
> file instead of calling syslog() directly from the .h file?
>
> >
> > diff --git a/scripts/tracetool/backend/syslog.py
> b/scripts/tracetool/backend/syslog.py
> > index 012970f6cc..52b8ff65ea 100644
> > --- a/scripts/tracetool/backend/syslog.py
> > +++ b/scripts/tracetool/backend/syslog.py
> > @@ -21,8 +21,12 @@
> >
> >
> >  def generate_h_begin(events, group):
> > -    out('#include <syslog.h>',
> > -        '')
> > +    out('#include <syslog.h>')
> > +    for event in events:
> > +        out('void _syslog_%(api)s(%(args)s);',
> > +            api=event.api(),
> > +            args=event.args)
> > +    out('')
> >
> >
> >  def generate_h(event, group):
> > @@ -37,17 +41,35 @@ def generate_h(event, group):
> >          cond = "trace_event_get_state(%s)" % ("TRACE_" +
> event.name.upper())
> >
> >      out('    if (%(cond)s) {',
> > -        '#line %(event_lineno)d "%(event_filename)s"',
> > -        '        syslog(LOG_INFO, "%(name)s " %(fmt)s %(argnames)s);',
> > -        '#line %(out_next_lineno)d "%(out_filename)s"',
> > +            '       _syslog_%(api)s(%(args)s);',
> >          '    }',
> >          cond=cond,
> >          event_lineno=event.lineno,
> >          event_filename=os.path.relpath(event.filename),
> >          name=event.name,
> >          fmt=event.fmt.rstrip("\n"),
> > -        argnames=argnames)
> > -
> > +        argnames=argnames,
> > +        api=event.api(),
> > +        args=", ".join(event.args.names()))
> > +
> > +
> > +def generate_c(event, group):
> > +        argnames = ", ".join(event.args.names())
> > +        if len(event.args) > 0:
> > +            argnames = ", " + argnames
> > +        out('void _syslog_%(api)s(%(args)s){',
> > +        '   #line %(event_lineno)d "%(event_filename)s"',
> > +        '            syslog(LOG_INFO, "%(name)s " %(fmt)s
> %(argnames)s);',
> > +        '   #line %(out_next_lineno)d "%(out_filename)s"',
> > +        '}',
> > +        '',
> > +        event_lineno=event.lineno,
> > +        event_filename=os.path.relpath(event.filename),
> > +        name=event.name,
> > +        fmt=event.fmt.rstrip("\n"),
> > +        argnames=argnames,
> > +        api=event.api(),
> > +        args=event.args)
> >
> >  def generate_h_backend_dstate(event, group):
> >      out('    trace_event_get_state_dynamic_by_id(%(event_id)s) || \\',
> > --
> > 2.34.1
> >
>

[-- Attachment #2: Type: text/html, Size: 6273 bytes --]

[PATCH 2/3] trace/ftrace: seperate cold paths of tracing functions

[Tanish Desai]

Moved rarely used (cold) code from the header file to the C file to avoid
unnecessary inlining and reduce binary size. This improves code organization
and follows good practices for managing cold paths.

Signed-off-by: Tanish Desai <tanishdesai37@gmail.com>
---
 scripts/tracetool/backend/ftrace.py | 44 +++++++++++++++++++++--------
 1 file changed, 32 insertions(+), 12 deletions(-)

diff --git a/scripts/tracetool/backend/ftrace.py b/scripts/tracetool/backend/ftrace.py
index baed2ae61c..c9717d7b42 100644
--- a/scripts/tracetool/backend/ftrace.py
+++ b/scripts/tracetool/backend/ftrace.py
@@ -23,6 +23,10 @@
 def generate_h_begin(events, group):
     out('#include "trace/ftrace.h"',
         '')
+    for event in events:
+        out('void _ftrace_%(api)s(%(args)s);',
+            api=event.api(),
+            args=event.args)
 
 
 def generate_h(event, group):
@@ -30,26 +34,42 @@ def generate_h(event, group):
     if len(event.args) > 0:
         argnames = ", " + argnames
 
-    out('    {',
+    out('        if (trace_event_get_state(%(event_id)s)) {',
+        '           _ftrace_%(api)s(%(args)s);',
+        '        }',
+        name=event.name,
+        args=", ".join(event.args.names()),
+        event_id="TRACE_" + event.name.upper(),
+        event_lineno=event.lineno,
+        event_filename=os.path.relpath(event.filename),
+        fmt=event.fmt.rstrip("\n"),
+        argnames=argnames,
+        api=event.api()
+        )
+
+
+def generate_c(event, group):
+        argnames = ", ".join(event.args.names())
+        if len(event.args) > 0:
+            argnames = ", " + argnames
+        out('void _ftrace_%(api)s(%(args)s){',
         '        char ftrace_buf[MAX_TRACE_STRLEN];',
         '        int unused __attribute__ ((unused));',
         '        int trlen;',
-        '        if (trace_event_get_state(%(event_id)s)) {',
         '#line %(event_lineno)d "%(event_filename)s"',
-        '            trlen = snprintf(ftrace_buf, MAX_TRACE_STRLEN,',
-        '                             "%(name)s " %(fmt)s "\\n" %(argnames)s);',
+        '       trlen = snprintf(ftrace_buf, MAX_TRACE_STRLEN,',
         '#line %(out_next_lineno)d "%(out_filename)s"',
-        '            trlen = MIN(trlen, MAX_TRACE_STRLEN - 1);',
-        '            unused = write(trace_marker_fd, ftrace_buf, trlen);',
-        '        }',
-        '    }',
-        name=event.name,
-        args=event.args,
-        event_id="TRACE_" + event.name.upper(),
+        '                       "%(name)s " %(fmt)s "\\n" %(argnames)s);',
+        '       trlen = MIN(trlen, MAX_TRACE_STRLEN - 1);',
+        '       unused = write(trace_marker_fd, ftrace_buf, trlen);',
+        '}',
         event_lineno=event.lineno,
         event_filename=os.path.relpath(event.filename),
+        name=event.name,
         fmt=event.fmt.rstrip("\n"),
-        argnames=argnames)
+        argnames=argnames,
+        api=event.api(),
+        args=event.args)
 
 
 def generate_h_backend_dstate(event, group):
-- 
2.34.1

Re: [PATCH 2/3] trace/ftrace: seperate cold paths of tracing functions

[Stefan Hajnoczi]

[-- Attachment #1: Type: text/plain, Size: 3747 bytes --]

On Sun, Jun 01, 2025 at 06:12:30PM +0000, Tanish Desai wrote:
> Moved rarely used (cold) code from the header file to the C file to avoid
> unnecessary inlining and reduce binary size.

How much of a binary size reduction do you measure? Most trace events
are only called once, so the difference in code size is likely to be
small.

> This improves code organization
> and follows good practices for managing cold paths.

It's easier to understand the code generator and the generated code when
each trace event is implemented as a single function in the header file.
Splitting the trace event up adds complexity. I don't think this is a
step in the right direction.

> 
> Signed-off-by: Tanish Desai <tanishdesai37@gmail.com>
> ---
>  scripts/tracetool/backend/ftrace.py | 44 +++++++++++++++++++++--------
>  1 file changed, 32 insertions(+), 12 deletions(-)
> 
> diff --git a/scripts/tracetool/backend/ftrace.py b/scripts/tracetool/backend/ftrace.py
> index baed2ae61c..c9717d7b42 100644
> --- a/scripts/tracetool/backend/ftrace.py
> +++ b/scripts/tracetool/backend/ftrace.py
> @@ -23,6 +23,10 @@
>  def generate_h_begin(events, group):
>      out('#include "trace/ftrace.h"',
>          '')
> +    for event in events:
> +        out('void _ftrace_%(api)s(%(args)s);',
> +            api=event.api(),
> +            args=event.args)
>  
>  
>  def generate_h(event, group):
> @@ -30,26 +34,42 @@ def generate_h(event, group):
>      if len(event.args) > 0:
>          argnames = ", " + argnames
>  
> -    out('    {',
> +    out('        if (trace_event_get_state(%(event_id)s)) {',
> +        '           _ftrace_%(api)s(%(args)s);',
> +        '        }',
> +        name=event.name,
> +        args=", ".join(event.args.names()),
> +        event_id="TRACE_" + event.name.upper(),
> +        event_lineno=event.lineno,
> +        event_filename=os.path.relpath(event.filename),
> +        fmt=event.fmt.rstrip("\n"),
> +        argnames=argnames,
> +        api=event.api()
> +        )
> +
> +
> +def generate_c(event, group):
> +        argnames = ", ".join(event.args.names())
> +        if len(event.args) > 0:
> +            argnames = ", " + argnames
> +        out('void _ftrace_%(api)s(%(args)s){',
>          '        char ftrace_buf[MAX_TRACE_STRLEN];',
>          '        int unused __attribute__ ((unused));',
>          '        int trlen;',
> -        '        if (trace_event_get_state(%(event_id)s)) {',
>          '#line %(event_lineno)d "%(event_filename)s"',
> -        '            trlen = snprintf(ftrace_buf, MAX_TRACE_STRLEN,',
> -        '                             "%(name)s " %(fmt)s "\\n" %(argnames)s);',
> +        '       trlen = snprintf(ftrace_buf, MAX_TRACE_STRLEN,',
>          '#line %(out_next_lineno)d "%(out_filename)s"',
> -        '            trlen = MIN(trlen, MAX_TRACE_STRLEN - 1);',
> -        '            unused = write(trace_marker_fd, ftrace_buf, trlen);',
> -        '        }',
> -        '    }',
> -        name=event.name,
> -        args=event.args,
> -        event_id="TRACE_" + event.name.upper(),
> +        '                       "%(name)s " %(fmt)s "\\n" %(argnames)s);',
> +        '       trlen = MIN(trlen, MAX_TRACE_STRLEN - 1);',
> +        '       unused = write(trace_marker_fd, ftrace_buf, trlen);',
> +        '}',
>          event_lineno=event.lineno,
>          event_filename=os.path.relpath(event.filename),
> +        name=event.name,
>          fmt=event.fmt.rstrip("\n"),
> -        argnames=argnames)
> +        argnames=argnames,
> +        api=event.api(),
> +        args=event.args)
>  
>  
>  def generate_h_backend_dstate(event, group):
> -- 
> 2.34.1
> 

[-- Attachment #2: signature.asc --]
[-- Type: application/pgp-signature, Size: 488 bytes --]

Re: [PATCH 2/3] trace/ftrace: seperate cold paths of tracing functions

[Paolo Bonzini]

On 6/3/25 00:24, Stefan Hajnoczi wrote:
> On Sun, Jun 01, 2025 at 06:12:30PM +0000, Tanish Desai wrote:
>> Moved rarely used (cold) code from the header file to the C file to avoid
>> unnecessary inlining and reduce binary size.
> 
> How much of a binary size reduction do you measure? Most trace events
> are only called once, so the difference in code size is likely to be
> small.

Indeed I don't think there would be much reduction.  I expect a bigger 
benefit in terms of improved register allocation when tracepoints are 
disabled, keeping unused tracepoint code out of the TLB, and the like.

That is, the difference in code size would be in the functions that 
include tracepoints, not in QEMU overall.  That's a bit difficult to 
measure because you would have to isolate tracepoint code in the 
"before" .o files, but we can try.

>> This improves code organization
>> and follows good practices for managing cold paths.
> 
> It's easier to understand the code generator and the generated code when
> each trace event is implemented as a single function in the header file.
> Splitting the trace event up adds complexity. I don't think this is a
> step in the right direction.

I am not sure I agree on that; something like

static inline void trace_smmu_config_cache_inv(uint32_t sid)
{
     if (trace_event_get_state(TRACE_SMMU_CONFIG_CACHE_INV)) {
         _simple__trace_smmu_config_cache_inv(sid);
         _log__trace_smmu_config_cache_inv(sid);
     }
     QEMU_SMMU_CONFIG_CACHE_INV(sid);
     tracepoint(qemu, smmu_config_cache_inv(sid));
}

and one function per backend seems the most readable way to format the 
code in the headers.  I understand that most of the time you'll have 
only one backend enabled, but still the above seems pretty good and 
clarifies the difference between efficient backends like dtrace and UST 
and the others.

This series doesn't go all the way to something like the above, but it 
does go in that direction.

Now, in all honesty the main reason to do this was to allow reusing the 
C code generator when it's Rust code that is using tracepoints; but I do 
believe that these changes make sense on their own, and I didn't want to 
make these a blocker for Rust enablement as well (Tanish has already 
looked into generating Rust code for the simple backend, for example).

Paolo


>> Signed-off-by: Tanish Desai <tanishdesai37@gmail.com>
>> ---
>>   scripts/tracetool/backend/ftrace.py | 44 +++++++++++++++++++++--------
>>   1 file changed, 32 insertions(+), 12 deletions(-)
>>
>> diff --git a/scripts/tracetool/backend/ftrace.py b/scripts/tracetool/backend/ftrace.py
>> index baed2ae61c..c9717d7b42 100644
>> --- a/scripts/tracetool/backend/ftrace.py
>> +++ b/scripts/tracetool/backend/ftrace.py
>> @@ -23,6 +23,10 @@
>>   def generate_h_begin(events, group):
>>       out('#include "trace/ftrace.h"',
>>           '')
>> +    for event in events:
>> +        out('void _ftrace_%(api)s(%(args)s);',
>> +            api=event.api(),
>> +            args=event.args)
>>   
>>   
>>   def generate_h(event, group):
>> @@ -30,26 +34,42 @@ def generate_h(event, group):
>>       if len(event.args) > 0:
>>           argnames = ", " + argnames
>>   
>> -    out('    {',
>> +    out('        if (trace_event_get_state(%(event_id)s)) {',
>> +        '           _ftrace_%(api)s(%(args)s);',
>> +        '        }',
>> +        name=event.name,
>> +        args=", ".join(event.args.names()),
>> +        event_id="TRACE_" + event.name.upper(),
>> +        event_lineno=event.lineno,
>> +        event_filename=os.path.relpath(event.filename),
>> +        fmt=event.fmt.rstrip("\n"),
>> +        argnames=argnames,
>> +        api=event.api()
>> +        )
>> +
>> +
>> +def generate_c(event, group):
>> +        argnames = ", ".join(event.args.names())
>> +        if len(event.args) > 0:
>> +            argnames = ", " + argnames
>> +        out('void _ftrace_%(api)s(%(args)s){',
>>           '        char ftrace_buf[MAX_TRACE_STRLEN];',
>>           '        int unused __attribute__ ((unused));',
>>           '        int trlen;',
>> -        '        if (trace_event_get_state(%(event_id)s)) {',
>>           '#line %(event_lineno)d "%(event_filename)s"',
>> -        '            trlen = snprintf(ftrace_buf, MAX_TRACE_STRLEN,',
>> -        '                             "%(name)s " %(fmt)s "\\n" %(argnames)s);',
>> +        '       trlen = snprintf(ftrace_buf, MAX_TRACE_STRLEN,',
>>           '#line %(out_next_lineno)d "%(out_filename)s"',
>> -        '            trlen = MIN(trlen, MAX_TRACE_STRLEN - 1);',
>> -        '            unused = write(trace_marker_fd, ftrace_buf, trlen);',
>> -        '        }',
>> -        '    }',
>> -        name=event.name,
>> -        args=event.args,
>> -        event_id="TRACE_" + event.name.upper(),
>> +        '                       "%(name)s " %(fmt)s "\\n" %(argnames)s);',
>> +        '       trlen = MIN(trlen, MAX_TRACE_STRLEN - 1);',
>> +        '       unused = write(trace_marker_fd, ftrace_buf, trlen);',
>> +        '}',
>>           event_lineno=event.lineno,
>>           event_filename=os.path.relpath(event.filename),
>> +        name=event.name,
>>           fmt=event.fmt.rstrip("\n"),
>> -        argnames=argnames)
>> +        argnames=argnames,
>> +        api=event.api(),
>> +        args=event.args)
>>   
>>   
>>   def generate_h_backend_dstate(event, group):
>> -- 
>> 2.34.1
>>

Re: [PATCH 2/3] trace/ftrace: seperate cold paths of tracing functions

[Stefan Hajnoczi]

On Thu, Jun 5, 2025 at 9:57 AM Paolo Bonzini <pbonzini@redhat.com> wrote:
>
> On 6/3/25 00:24, Stefan Hajnoczi wrote:
> > On Sun, Jun 01, 2025 at 06:12:30PM +0000, Tanish Desai wrote:
> >> Moved rarely used (cold) code from the header file to the C file to avoid
> >> unnecessary inlining and reduce binary size.
> >
> > How much of a binary size reduction do you measure? Most trace events
> > are only called once, so the difference in code size is likely to be
> > small.
>
> Indeed I don't think there would be much reduction.  I expect a bigger
> benefit in terms of improved register allocation when tracepoints are
> disabled, keeping unused tracepoint code out of the TLB, and the like.
>
> That is, the difference in code size would be in the functions that
> include tracepoints, not in QEMU overall.  That's a bit difficult to
> measure because you would have to isolate tracepoint code in the
> "before" .o files, but we can try.
>
> >> This improves code organization
> >> and follows good practices for managing cold paths.
> >
> > It's easier to understand the code generator and the generated code when
> > each trace event is implemented as a single function in the header file.
> > Splitting the trace event up adds complexity. I don't think this is a
> > step in the right direction.
>
> I am not sure I agree on that; something like
>
> static inline void trace_smmu_config_cache_inv(uint32_t sid)
> {
>      if (trace_event_get_state(TRACE_SMMU_CONFIG_CACHE_INV)) {
>          _simple__trace_smmu_config_cache_inv(sid);
>          _log__trace_smmu_config_cache_inv(sid);
>      }
>      QEMU_SMMU_CONFIG_CACHE_INV(sid);
>      tracepoint(qemu, smmu_config_cache_inv(sid));
> }
>
> and one function per backend seems the most readable way to format the
> code in the headers.  I understand that most of the time you'll have
> only one backend enabled, but still the above seems pretty good and
> clarifies the difference between efficient backends like dtrace and UST
> and the others.
>
> This series doesn't go all the way to something like the above, but it
> does go in that direction.

It's nice to share a single trace_event_get_state() conditional
between all backends that use it. There is no need to move the
generated code from .h into a .c file to achieve this though.

In the absence of performance data this patch series seems like
premature optimization and code churn to me.

> Now, in all honesty the main reason to do this was to allow reusing the
> C code generator when it's Rust code that is using tracepoints; but I do
> believe that these changes make sense on their own, and I didn't want to
> make these a blocker for Rust enablement as well (Tanish has already
> looked into generating Rust code for the simple backend, for example).

How is this patch series related to Rust tracing? If generated code
needs to be restructured so Rust can call it, then that's a strong
justification.

Stefan

>
> Paolo
>
>
> >> Signed-off-by: Tanish Desai <tanishdesai37@gmail.com>
> >> ---
> >>   scripts/tracetool/backend/ftrace.py | 44 +++++++++++++++++++++--------
> >>   1 file changed, 32 insertions(+), 12 deletions(-)
> >>
> >> diff --git a/scripts/tracetool/backend/ftrace.py b/scripts/tracetool/backend/ftrace.py
> >> index baed2ae61c..c9717d7b42 100644
> >> --- a/scripts/tracetool/backend/ftrace.py
> >> +++ b/scripts/tracetool/backend/ftrace.py
> >> @@ -23,6 +23,10 @@
> >>   def generate_h_begin(events, group):
> >>       out('#include "trace/ftrace.h"',
> >>           '')
> >> +    for event in events:
> >> +        out('void _ftrace_%(api)s(%(args)s);',
> >> +            api=event.api(),
> >> +            args=event.args)
> >>
> >>
> >>   def generate_h(event, group):
> >> @@ -30,26 +34,42 @@ def generate_h(event, group):
> >>       if len(event.args) > 0:
> >>           argnames = ", " + argnames
> >>
> >> -    out('    {',
> >> +    out('        if (trace_event_get_state(%(event_id)s)) {',
> >> +        '           _ftrace_%(api)s(%(args)s);',
> >> +        '        }',
> >> +        name=event.name,
> >> +        args=", ".join(event.args.names()),
> >> +        event_id="TRACE_" + event.name.upper(),
> >> +        event_lineno=event.lineno,
> >> +        event_filename=os.path.relpath(event.filename),
> >> +        fmt=event.fmt.rstrip("\n"),
> >> +        argnames=argnames,
> >> +        api=event.api()
> >> +        )
> >> +
> >> +
> >> +def generate_c(event, group):
> >> +        argnames = ", ".join(event.args.names())
> >> +        if len(event.args) > 0:
> >> +            argnames = ", " + argnames
> >> +        out('void _ftrace_%(api)s(%(args)s){',
> >>           '        char ftrace_buf[MAX_TRACE_STRLEN];',
> >>           '        int unused __attribute__ ((unused));',
> >>           '        int trlen;',
> >> -        '        if (trace_event_get_state(%(event_id)s)) {',
> >>           '#line %(event_lineno)d "%(event_filename)s"',
> >> -        '            trlen = snprintf(ftrace_buf, MAX_TRACE_STRLEN,',
> >> -        '                             "%(name)s " %(fmt)s "\\n" %(argnames)s);',
> >> +        '       trlen = snprintf(ftrace_buf, MAX_TRACE_STRLEN,',
> >>           '#line %(out_next_lineno)d "%(out_filename)s"',
> >> -        '            trlen = MIN(trlen, MAX_TRACE_STRLEN - 1);',
> >> -        '            unused = write(trace_marker_fd, ftrace_buf, trlen);',
> >> -        '        }',
> >> -        '    }',
> >> -        name=event.name,
> >> -        args=event.args,
> >> -        event_id="TRACE_" + event.name.upper(),
> >> +        '                       "%(name)s " %(fmt)s "\\n" %(argnames)s);',
> >> +        '       trlen = MIN(trlen, MAX_TRACE_STRLEN - 1);',
> >> +        '       unused = write(trace_marker_fd, ftrace_buf, trlen);',
> >> +        '}',
> >>           event_lineno=event.lineno,
> >>           event_filename=os.path.relpath(event.filename),
> >> +        name=event.name,
> >>           fmt=event.fmt.rstrip("\n"),
> >> -        argnames=argnames)
> >> +        argnames=argnames,
> >> +        api=event.api(),
> >> +        args=event.args)
> >>
> >>
> >>   def generate_h_backend_dstate(event, group):
> >> --
> >> 2.34.1
> >>
>
>

Re: [PATCH 2/3] trace/ftrace: seperate cold paths of tracing functions

[Paolo Bonzini]

On 6/5/25 20:37, Stefan Hajnoczi wrote:
> On Thu, Jun 5, 2025 at 9:57 AM Paolo Bonzini <pbonzini@redhat.com> wrote:
>>> It's easier to understand the code generator and the generated code when
>>> each trace event is implemented as a single function in the header file.
>>> Splitting the trace event up adds complexity. I don't think this is a
>>> step in the right direction.
>>
>> I am not sure I agree on that; something like
>>
>> static inline void trace_smmu_config_cache_inv(uint32_t sid)
>> {
>>       if (trace_event_get_state(TRACE_SMMU_CONFIG_CACHE_INV)) {
>>           _simple__trace_smmu_config_cache_inv(sid);
>>           _log__trace_smmu_config_cache_inv(sid);
>>       }
>>       QEMU_SMMU_CONFIG_CACHE_INV(sid);
>>       tracepoint(qemu, smmu_config_cache_inv(sid));
>> }
>>
>> and one function per backend seems the most readable way to format the
>> code in the headers.  I understand that most of the time you'll have
>> only one backend enabled, but still the above seems pretty good and
>> clarifies the difference between efficient backends like dtrace and UST
>> and the others.
>>
>> This series doesn't go all the way to something like the above, but it
>> does go in that direction.
> 
> It's nice to share a single trace_event_get_state() conditional
> between all backends that use it. There is no need to move the
> generated code from .h into a .c file to achieve this though.

Ok, I see what you mean.  Personally I like that the backend code is 
completely out of sight and you only have a single line of code per 
backend; but it's a matter of taste I guess.

> In the absence of performance data this patch series seems like
> premature optimization and code churn to me.
> 
>> Now, in all honesty the main reason to do this was to allow reusing the
>> C code generator when it's Rust code that is using tracepoints; but I do
>> believe that these changes make sense on their own, and I didn't want to
>> make these a blocker for Rust enablement as well (Tanish has already
>> looked into generating Rust code for the simple backend, for example).
> 
> How is this patch series related to Rust tracing? If generated code
> needs to be restructured so Rust can call it, then that's a strong
> justification.
Well, moving code to the .c file would make it possible to call it in 
Rust without duplicating code generation for the various backends (other 
than the "if" and function calls, of course, but those are easy). 
However, this is only handy and not absolutely necessary for the Rust 
tracing project.

If you disagree with this change we can certainly live without them---I 
asked Tanish to start with this as an exercise to get familiar with 
tracetool, and he's learnt a bunch of things around git anyway so it's 
all good.

We'll also try to take a look at the code that is generated in the 
function that invokes the tracepoint, to see if it's improved.

Paolo

Re: [PATCH 2/3] trace/ftrace: seperate cold paths of tracing functions

[Daniel P. Berrangé]

On Thu, Jun 05, 2025 at 08:49:36PM +0200, Paolo Bonzini wrote:
> On 6/5/25 20:37, Stefan Hajnoczi wrote:
> > On Thu, Jun 5, 2025 at 9:57 AM Paolo Bonzini <pbonzini@redhat.com> wrote:
> > > > It's easier to understand the code generator and the generated code when
> > > > each trace event is implemented as a single function in the header file.
> > > > Splitting the trace event up adds complexity. I don't think this is a
> > > > step in the right direction.
> > > 
> > > I am not sure I agree on that; something like
> > > 
> > > static inline void trace_smmu_config_cache_inv(uint32_t sid)
> > > {
> > >       if (trace_event_get_state(TRACE_SMMU_CONFIG_CACHE_INV)) {
> > >           _simple__trace_smmu_config_cache_inv(sid);
> > >           _log__trace_smmu_config_cache_inv(sid);
> > >       }
> > >       QEMU_SMMU_CONFIG_CACHE_INV(sid);
> > >       tracepoint(qemu, smmu_config_cache_inv(sid));
> > > }
> > > 
> > > and one function per backend seems the most readable way to format the
> > > code in the headers.  I understand that most of the time you'll have
> > > only one backend enabled, but still the above seems pretty good and
> > > clarifies the difference between efficient backends like dtrace and UST
> > > and the others.
> > > 
> > > This series doesn't go all the way to something like the above, but it
> > > does go in that direction.
> > 
> > It's nice to share a single trace_event_get_state() conditional
> > between all backends that use it. There is no need to move the
> > generated code from .h into a .c file to achieve this though.
> 
> Ok, I see what you mean.  Personally I like that the backend code is
> completely out of sight and you only have a single line of code per backend;
> but it's a matter of taste I guess.
> 
> > In the absence of performance data this patch series seems like
> > premature optimization and code churn to me.
> > 
> > > Now, in all honesty the main reason to do this was to allow reusing the
> > > C code generator when it's Rust code that is using tracepoints; but I do
> > > believe that these changes make sense on their own, and I didn't want to
> > > make these a blocker for Rust enablement as well (Tanish has already
> > > looked into generating Rust code for the simple backend, for example).
> > 
> > How is this patch series related to Rust tracing? If generated code
> > needs to be restructured so Rust can call it, then that's a strong
> > justification.
> Well, moving code to the .c file would make it possible to call it in Rust
> without duplicating code generation for the various backends (other than the
> "if" and function calls, of course, but those are easy). However, this is
> only handy and not absolutely necessary for the Rust tracing project.

This might work for some trace backends, but certainly for dtrace/systemtap
I'd expect us to use a native rust impl to get the optimal low overhead.

With regards,
Daniel
-- 
|: https://berrange.com      -o-    https://www.flickr.com/photos/dberrange :|
|: https://libvirt.org         -o-            https://fstop138.berrange.com :|
|: https://entangle-photo.org    -o-    https://www.instagram.com/dberrange :|

Re: [PATCH 2/3] trace/ftrace: seperate cold paths of tracing functions

[Paolo Bonzini]

[-- Attachment #1: Type: text/plain, Size: 1183 bytes --]

Il gio 5 giu 2025, 21:20 Daniel P. Berrangé <berrange@redhat.com> ha
scritto:

> > > How is this patch series related to Rust tracing? If generated code
> > > needs to be restructured so Rust can call it, then that's a strong
> > > justification.
> > Well, moving code to the .c file would make it possible to call it in
> Rust
> > without duplicating code generation for the various backends (other than
> the
> > "if" and function calls, of course, but those are easy). However, this is
> > only handy and not absolutely necessary for the Rust tracing project.
>
> This might work for some trace backends, but certainly for dtrace/systemtap
> I'd expect us to use a native rust impl to get the optimal low overhead.
>

Yes, dtrace and ust are special. But they also have very small code
generation, so there would also be no reason to do a patch like this one
for them.

Paolo


> With regards,
> Daniel
> --
> |: https://berrange.com      -o-
> https://www.flickr.com/photos/dberrange :|
> |: https://libvirt.org         -o-
> https://fstop138.berrange.com :|
> |: https://entangle-photo.org    -o-
> https://www.instagram.com/dberrange :|
>
>

[-- Attachment #2: Type: text/html, Size: 2443 bytes --]

Re: [PATCH 2/3] trace/ftrace: seperate cold paths of tracing functions

[Stefan Hajnoczi]

On Thu, Jun 5, 2025 at 2:49 PM Paolo Bonzini <pbonzini@redhat.com> wrote:
>
> On 6/5/25 20:37, Stefan Hajnoczi wrote:
> > On Thu, Jun 5, 2025 at 9:57 AM Paolo Bonzini <pbonzini@redhat.com> wrote:
> >>> It's easier to understand the code generator and the generated code when
> >>> each trace event is implemented as a single function in the header file.
> >>> Splitting the trace event up adds complexity. I don't think this is a
> >>> step in the right direction.
> >>
> >> I am not sure I agree on that; something like
> >>
> >> static inline void trace_smmu_config_cache_inv(uint32_t sid)
> >> {
> >>       if (trace_event_get_state(TRACE_SMMU_CONFIG_CACHE_INV)) {
> >>           _simple__trace_smmu_config_cache_inv(sid);
> >>           _log__trace_smmu_config_cache_inv(sid);
> >>       }
> >>       QEMU_SMMU_CONFIG_CACHE_INV(sid);
> >>       tracepoint(qemu, smmu_config_cache_inv(sid));
> >> }
> >>
> >> and one function per backend seems the most readable way to format the
> >> code in the headers.  I understand that most of the time you'll have
> >> only one backend enabled, but still the above seems pretty good and
> >> clarifies the difference between efficient backends like dtrace and UST
> >> and the others.
> >>
> >> This series doesn't go all the way to something like the above, but it
> >> does go in that direction.
> >
> > It's nice to share a single trace_event_get_state() conditional
> > between all backends that use it. There is no need to move the
> > generated code from .h into a .c file to achieve this though.
>
> Ok, I see what you mean.  Personally I like that the backend code is
> completely out of sight and you only have a single line of code per
> backend; but it's a matter of taste I guess.
>
> > In the absence of performance data this patch series seems like
> > premature optimization and code churn to me.
> >
> >> Now, in all honesty the main reason to do this was to allow reusing the
> >> C code generator when it's Rust code that is using tracepoints; but I do
> >> believe that these changes make sense on their own, and I didn't want to
> >> make these a blocker for Rust enablement as well (Tanish has already
> >> looked into generating Rust code for the simple backend, for example).
> >
> > How is this patch series related to Rust tracing? If generated code
> > needs to be restructured so Rust can call it, then that's a strong
> > justification.
> Well, moving code to the .c file would make it possible to call it in
> Rust without duplicating code generation for the various backends (other
> than the "if" and function calls, of course, but those are easy).
> However, this is only handy and not absolutely necessary for the Rust
> tracing project.
>
> If you disagree with this change we can certainly live without them---I
> asked Tanish to start with this as an exercise to get familiar with
> tracetool, and he's learnt a bunch of things around git anyway so it's
> all good.

A maintainer's life is easy when patches have a clear motivation. With
this patch series I'm not convinced there is a clear motivation, and
that makes me hesitate about applying them.

If it's okay with you, Tanish and Paolo, please hold on to the patches
and let's see how they fit into the larger goal of Rust tracing
support. If they help with that then I would be happy to merge them
together with Rust tracing patches.

>
> We'll also try to take a look at the code that is generated in the
> function that invokes the tracepoint, to see if it's improved.
>
> Paolo
>

Re: [PATCH 2/3] trace/ftrace: seperate cold paths of tracing functions

[Paolo Bonzini]

[-- Attachment #1: Type: text/plain, Size: 1058 bytes --]

Il lun 9 giu 2025, 20:27 Stefan Hajnoczi <stefanha@gmail.com> ha scritto:

> > If you disagree with this change we can certainly live without them---I
> > asked Tanish to start with this as an exercise to get familiar with
> > tracetool, and he's learnt a bunch of things around git anyway so it's
> > all good.
>
> A maintainer's life is easy when patches have a clear motivation. With
> this patch series I'm not convinced there is a clear motivation, and
> that makes me hesitate about applying them.
>

Indeed. Tanish just posted a patch that should get basically all of the
benefit without the downsides, so thanks for hesitating. :)

Paolo

If it's okay with you, Tanish and Paolo, please hold on to the patches
> and let's see how they fit into the larger goal of Rust tracing
> support. If they help with that then I would be happy to merge them
> together with Rust tracing patches.
>
> >
> > We'll also try to take a look at the code that is generated in the
> > function that invokes the tracepoint, to see if it's improved.
> >
> > Paolo
> >
>
>

[-- Attachment #2: Type: text/html, Size: 1821 bytes --]

[PATCH 3/3] trace/log: seperate cold path of tracing functions

[Tanish Desai]

Moved frequently used hot paths from the .c file to the .h file to enable inlining
and improve performance. This approach is inspired by past QEMU optimizations,
where performance-critical code was inlined based on profiling results.

Signed-off-by: Tanish Desai <tanishdesai37@gmail.com>
---
 scripts/tracetool/backend/log.py | 26 ++++++++++++++++++++++++--
 1 file changed, 24 insertions(+), 2 deletions(-)

diff --git a/scripts/tracetool/backend/log.py b/scripts/tracetool/backend/log.py
index de27b7e62e..ca53747950 100644
--- a/scripts/tracetool/backend/log.py
+++ b/scripts/tracetool/backend/log.py
@@ -24,6 +24,10 @@ def generate_h_begin(events, group):
     out('#include "qemu/log-for-trace.h"',
         '#include "qemu/error-report.h"',
         '')
+    for event in events:
+        out('void _log_%(api)s(%(args)s);',
+            api=event.api(),
+            args=event.args)
 
 
 def generate_h(event, group):
@@ -38,6 +42,22 @@ def generate_h(event, group):
         cond = "trace_event_get_state(%s)" % ("TRACE_" + event.name.upper())
 
     out('    if (%(cond)s && qemu_loglevel_mask(LOG_TRACE)) {',
+        '       _log_%(api)s(%(args)s);',
+        '    }',
+        cond=cond,
+        event_lineno=event.lineno,
+        event_filename=os.path.relpath(event.filename),
+        name=event.name,
+        fmt=event.fmt.rstrip("\n"),
+        argnames=argnames,
+        args = ", ".join(event.args.names()),
+        api=event.api())
+
+def generate_c(event, group):
+        argnames = ", ".join(event.args.names())
+        if len(event.args) > 0:
+            argnames = ", " + argnames
+            out('void _log_%(api)s(%(args)s){',
         '        if (message_with_timestamp) {',
         '            struct timeval _now;',
         '            gettimeofday(&_now, NULL);',
@@ -53,12 +73,14 @@ def generate_h(event, group):
         '#line %(out_next_lineno)d "%(out_filename)s"',
         '        }',
         '    }',
-        cond=cond,
         event_lineno=event.lineno,
         event_filename=os.path.relpath(event.filename),
         name=event.name,
         fmt=event.fmt.rstrip("\n"),
-        argnames=argnames)
+        argnames=argnames,
+        args=event.args,
+        api=event.api()
+        )
 
 
 def generate_h_backend_dstate(event, group):
-- 
2.34.1