Re: [PULL 1/1] trace: log.py: human-readable timestamp

["Daniel P. Berrangé" <berrange@redhat.com>]

On Mon, Jul 21, 2025 at 02:10:51PM -0400, Stefan Hajnoczi wrote:
> From: Vladimir Sementsov-Ogievskiy <vsementsov@yandex-team.ru>
> 
> So tired to parse all these timestamps, when need to compare them
> with other logs.
> 
> Use iso8601 format as in warn_report() (info_report(), error_report())
> already used.
> 
> Also, start line with date, to be similar with warn_report() as well.
> 
> Signed-off-by: Vladimir Sementsov-Ogievskiy <vsementsov@yandex-team.ru>
> Message-id: 20250626195514.366177-1-vsementsov@yandex-team.ru
> Signed-off-by: Stefan Hajnoczi <stefanha@redhat.com>
> ---
>  scripts/tracetool/backend/log.py | 11 ++++++++---
>  1 file changed, 8 insertions(+), 3 deletions(-)
> 
> diff --git a/scripts/tracetool/backend/log.py b/scripts/tracetool/backend/log.py
> index 17ba1cd90e..61118474b1 100644
> --- a/scripts/tracetool/backend/log.py
> +++ b/scripts/tracetool/backend/log.py
> @@ -39,10 +39,15 @@ def generate_h(event, group):
>          '        if (message_with_timestamp) {',
>          '            struct timeval _now;',
>          '            gettimeofday(&_now, NULL);',
> +        '            time_t _seconds = _now.tv_sec;',
> +        '            struct tm _tm;',
> +        '            gmtime_r(&_seconds, &_tm);',
>          '#line %(event_lineno)d "%(event_filename)s"',
> -        '            qemu_log("%%d@%%zu.%%06zu:%(name)s " %(fmt)s "\\n",',
> -        '                     qemu_get_thread_id(),',
> -        '                     (size_t)_now.tv_sec, (size_t)_now.tv_usec',
> +        '            qemu_log("%%04d-%%02d-%%02dT%%02d:%%02d:%%02d.%%06ldZ'
> +        ' (%%d) %(name)s " %(fmt)s "\\n",',
> +        '                     _tm.tm_year + 1900, _tm.tm_mon + 1, _tm.tm_mday,',
> +        '                     _tm.tm_hour, _tm.tm_min, _tm.tm_sec, _now.tv_usec,',
> +        '                     qemu_get_thread_id()',
>          '                     %(argnames)s);',

IMHO this is undesirable, as it bloats the QEMU binaries by another 1 MB
as we have an excessive amount of code being inlined in every trace call
location. I've co-incidentally just sent a patch that would fix the same
problem based on a discussion last week about a bug caused by this log
backend adding 'error-report.h' into all files:

  https://lists.nongnu.org/archive/html/qemu-devel/2025-07/msg04905.html

>          '#line %(out_next_lineno)d "%(out_filename)s"',
>          '        } else {',

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 :|