qemu-e2k/scripts/tracetool/format/log_stap.py

130 lines
3.9 KiB
Python
Raw Normal View History

trace: add ability to do simple printf logging via systemtap The dtrace systemtap trace backend for QEMU is very powerful but it is also somewhat unfriendly to users who aren't familiar with systemtap, or who don't need its power right now. stap -e "....some strange script...." The 'log' backend for QEMU by comparison is very crude but incredibly easy to use: $ qemu -d trace:qio* ...some args... 23266@1547735759.137292:qio_channel_socket_new Socket new ioc=0x563a8a39d400 23266@1547735759.137305:qio_task_new Task new task=0x563a891d0570 source=0x563a8a39d400 func=0x563a86f1e6c0 opaque=0x563a89078000 23266@1547735759.137326:qio_task_thread_start Task thread start task=0x563a891d0570 worker=0x563a86f1ce50 opaque=0x563a891d9d90 23273@1547735759.137491:qio_task_thread_run Task thread run task=0x563a891d0570 23273@1547735759.137503:qio_channel_socket_connect_sync Socket connect sync ioc=0x563a8a39d400 addr=0x563a891d9d90 23273@1547735759.138108:qio_channel_socket_connect_fail Socket connect fail ioc=0x563a8a39d400 This commit introduces a way to do simple printf style logging of probe points using systemtap. In particular it creates another set of tapsets, one per emulator: /usr/share/systemtap/tapset/qemu-*-log.stp These pre-define probe functions which simply call printf() on their arguments. The printf() format string is taken from the normal trace-events files, with a little munging to the format specifiers to cope with systemtap's more restrictive syntax. With this you can now do $ stap -e 'probe qemu.system.x86_64.log.qio*{}' 22806@1547735341399856820 qio_channel_socket_new Socket new ioc=0x56135d1d7c00 22806@1547735341399862570 qio_task_new Task new task=0x56135cd66eb0 source=0x56135d1d7c00 func=0x56135af746c0 opaque=0x56135bf06400 22806@1547735341399865943 qio_task_thread_start Task thread start task=0x56135cd66eb0 worker=0x56135af72e50 opaque=0x56135c071d70 22806@1547735341399976816 qio_task_thread_run Task thread run task=0x56135cd66eb0 We go one step further though and introduce a 'qemu-trace-stap' tool to make this even easier $ qemu-trace-stap run qemu-system-x86_64 'qio*' 22806@1547735341399856820 qio_channel_socket_new Socket new ioc=0x56135d1d7c00 22806@1547735341399862570 qio_task_new Task new task=0x56135cd66eb0 source=0x56135d1d7c00 func=0x56135af746c0 opaque=0x56135bf06400 22806@1547735341399865943 qio_task_thread_start Task thread start task=0x56135cd66eb0 worker=0x56135af72e50 opaque=0x56135c071d70 22806@1547735341399976816 qio_task_thread_run Task thread run task=0x56135cd66eb0 This tool is clever in that it will automatically change the SYSTEMTAP_TAPSET env variable to point to the directory containing the right set of probes for the QEMU binary path you give it. This is useful if you have QEMU installed in /usr but are trying to test and trace a binary in /home/berrange/usr/qemu-git. In that case you'd do $ qemu-trace-stap run /home/berrange/usr/qemu-git/bin/qemu-system-x86_64 'qio*' And it'll make sure /home/berrange/usr/qemu-git/share/systemtap/tapset is used for the trace session The 'qemu-trace-stap' script takes a verbose arg so you can understand what it is running $ qemu-trace-stap run /home/berrange/usr/qemu-git/bin/qemu-system-x86_64 'qio*' Using tapset dir '/home/berrange/usr/qemu-git/share/systemtap/tapset' for binary '/home/berrange/usr/qemu-git/bin/qemu-system-x86_64' Compiling script 'probe qemu.system.x86_64.log.qio* {}' Running script, <Ctrl>-c to quit ...trace output... It can enable multiple probes at once $ qemu-trace-stap run qemu-system-x86_64 'qio*' 'qcrypto*' 'buffer*' By default it monitors all existing running processes and all future launched proceses. This can be restricted to a specific PID using the --pid arg $ qemu-trace-stap run --pid 2532 qemu-system-x86_64 'qio*' Finally if you can't remember what probes are valid it can tell you $ qemu-trace-stap list qemu-system-x86_64 ahci_check_irq ahci_cmd_done ahci_dma_prepare_buf ahci_dma_prepare_buf_fail ahci_dma_rw_buf ahci_irq_lower ...snip... Or list just those matching a prefix pattern $ qemu-trace-stap list -v qemu-system-x86_64 'qio*' Using tapset dir '/home/berrange/usr/qemu-git/share/systemtap/tapset' for binary '/home/berrange/usr/qemu-git/bin/qemu-system-x86_64' Listing probes with name 'qemu.system.x86_64.log.qio*' qio_channel_command_abort qio_channel_command_new_pid qio_channel_command_new_spawn qio_channel_command_wait qio_channel_file_new_fd ...snip... Reviewed-by: Eric Blake <eblake@redhat.com> Signed-off-by: Daniel P. Berrangé <berrange@redhat.com> Message-id: 20190123120016.4538-5-berrange@redhat.com Signed-off-by: Stefan Hajnoczi <stefanha@redhat.com>
2019-01-23 13:00:16 +01:00
# -*- coding: utf-8 -*-
"""
Generate .stp file that printfs log messages (DTrace with SystemTAP only).
"""
__author__ = "Daniel P. Berrange <berrange@redhat.com>"
__copyright__ = "Copyright (C) 2014-2019, Red Hat, Inc."
__license__ = "GPL version 2 or (at your option) any later version"
__maintainer__ = "Daniel Berrange"
__email__ = "berrange@redhat.com"
import re
from tracetool import out
from tracetool.backend.dtrace import binary, probeprefix
from tracetool.backend.simple import is_string
from tracetool.format.stap import stap_escape
def global_var_name(name):
return probeprefix().replace(".", "_") + "_" + name
STATE_SKIP = 0
STATE_LITERAL = 1
STATE_MACRO = 2
def c_macro_to_format(macro):
if macro.startswith("PRI"):
return macro[3]
raise Exception("Unhandled macro '%s'" % macro)
def c_fmt_to_stap(fmt):
state = 0
bits = []
literal = ""
macro = ""
escape = 0;
for i in range(len(fmt)):
if fmt[i] == '\\':
if escape:
escape = 0
else:
escape = 1
if state != STATE_LITERAL:
raise Exception("Unexpected escape outside string literal")
literal = literal + fmt[i]
elif fmt[i] == '"' and not escape:
if state == STATE_LITERAL:
state = STATE_SKIP
bits.append(literal)
literal = ""
else:
if state == STATE_MACRO:
bits.append(c_macro_to_format(macro))
macro = ""
trace: add ability to do simple printf logging via systemtap The dtrace systemtap trace backend for QEMU is very powerful but it is also somewhat unfriendly to users who aren't familiar with systemtap, or who don't need its power right now. stap -e "....some strange script...." The 'log' backend for QEMU by comparison is very crude but incredibly easy to use: $ qemu -d trace:qio* ...some args... 23266@1547735759.137292:qio_channel_socket_new Socket new ioc=0x563a8a39d400 23266@1547735759.137305:qio_task_new Task new task=0x563a891d0570 source=0x563a8a39d400 func=0x563a86f1e6c0 opaque=0x563a89078000 23266@1547735759.137326:qio_task_thread_start Task thread start task=0x563a891d0570 worker=0x563a86f1ce50 opaque=0x563a891d9d90 23273@1547735759.137491:qio_task_thread_run Task thread run task=0x563a891d0570 23273@1547735759.137503:qio_channel_socket_connect_sync Socket connect sync ioc=0x563a8a39d400 addr=0x563a891d9d90 23273@1547735759.138108:qio_channel_socket_connect_fail Socket connect fail ioc=0x563a8a39d400 This commit introduces a way to do simple printf style logging of probe points using systemtap. In particular it creates another set of tapsets, one per emulator: /usr/share/systemtap/tapset/qemu-*-log.stp These pre-define probe functions which simply call printf() on their arguments. The printf() format string is taken from the normal trace-events files, with a little munging to the format specifiers to cope with systemtap's more restrictive syntax. With this you can now do $ stap -e 'probe qemu.system.x86_64.log.qio*{}' 22806@1547735341399856820 qio_channel_socket_new Socket new ioc=0x56135d1d7c00 22806@1547735341399862570 qio_task_new Task new task=0x56135cd66eb0 source=0x56135d1d7c00 func=0x56135af746c0 opaque=0x56135bf06400 22806@1547735341399865943 qio_task_thread_start Task thread start task=0x56135cd66eb0 worker=0x56135af72e50 opaque=0x56135c071d70 22806@1547735341399976816 qio_task_thread_run Task thread run task=0x56135cd66eb0 We go one step further though and introduce a 'qemu-trace-stap' tool to make this even easier $ qemu-trace-stap run qemu-system-x86_64 'qio*' 22806@1547735341399856820 qio_channel_socket_new Socket new ioc=0x56135d1d7c00 22806@1547735341399862570 qio_task_new Task new task=0x56135cd66eb0 source=0x56135d1d7c00 func=0x56135af746c0 opaque=0x56135bf06400 22806@1547735341399865943 qio_task_thread_start Task thread start task=0x56135cd66eb0 worker=0x56135af72e50 opaque=0x56135c071d70 22806@1547735341399976816 qio_task_thread_run Task thread run task=0x56135cd66eb0 This tool is clever in that it will automatically change the SYSTEMTAP_TAPSET env variable to point to the directory containing the right set of probes for the QEMU binary path you give it. This is useful if you have QEMU installed in /usr but are trying to test and trace a binary in /home/berrange/usr/qemu-git. In that case you'd do $ qemu-trace-stap run /home/berrange/usr/qemu-git/bin/qemu-system-x86_64 'qio*' And it'll make sure /home/berrange/usr/qemu-git/share/systemtap/tapset is used for the trace session The 'qemu-trace-stap' script takes a verbose arg so you can understand what it is running $ qemu-trace-stap run /home/berrange/usr/qemu-git/bin/qemu-system-x86_64 'qio*' Using tapset dir '/home/berrange/usr/qemu-git/share/systemtap/tapset' for binary '/home/berrange/usr/qemu-git/bin/qemu-system-x86_64' Compiling script 'probe qemu.system.x86_64.log.qio* {}' Running script, <Ctrl>-c to quit ...trace output... It can enable multiple probes at once $ qemu-trace-stap run qemu-system-x86_64 'qio*' 'qcrypto*' 'buffer*' By default it monitors all existing running processes and all future launched proceses. This can be restricted to a specific PID using the --pid arg $ qemu-trace-stap run --pid 2532 qemu-system-x86_64 'qio*' Finally if you can't remember what probes are valid it can tell you $ qemu-trace-stap list qemu-system-x86_64 ahci_check_irq ahci_cmd_done ahci_dma_prepare_buf ahci_dma_prepare_buf_fail ahci_dma_rw_buf ahci_irq_lower ...snip... Or list just those matching a prefix pattern $ qemu-trace-stap list -v qemu-system-x86_64 'qio*' Using tapset dir '/home/berrange/usr/qemu-git/share/systemtap/tapset' for binary '/home/berrange/usr/qemu-git/bin/qemu-system-x86_64' Listing probes with name 'qemu.system.x86_64.log.qio*' qio_channel_command_abort qio_channel_command_new_pid qio_channel_command_new_spawn qio_channel_command_wait qio_channel_file_new_fd ...snip... Reviewed-by: Eric Blake <eblake@redhat.com> Signed-off-by: Daniel P. Berrangé <berrange@redhat.com> Message-id: 20190123120016.4538-5-berrange@redhat.com Signed-off-by: Stefan Hajnoczi <stefanha@redhat.com>
2019-01-23 13:00:16 +01:00
state = STATE_LITERAL
elif fmt[i] == ' ' or fmt[i] == '\t':
if state == STATE_MACRO:
bits.append(c_macro_to_format(macro))
macro = ""
state = STATE_SKIP
elif state == STATE_LITERAL:
literal = literal + fmt[i]
else:
escape = 0
if state == STATE_SKIP:
state = STATE_MACRO
if state == STATE_LITERAL:
literal = literal + fmt[i]
else:
macro = macro + fmt[i]
if state == STATE_MACRO:
bits.append(c_macro_to_format(macro))
elif state == STATE_LITERAL:
bits.append(literal)
# All variables in systemtap are 64-bit in size
# The "%l" integer size qualifier is thus redundant
# and "%ll" is not valid at all. Similarly the size_t
# based "%z" size qualifier is not valid. We just
# strip all size qualifiers for sanity.
fmt = re.sub("%(\d*)(l+|z)(x|u|d)", "%\\1\\3", "".join(bits))
trace: add ability to do simple printf logging via systemtap The dtrace systemtap trace backend for QEMU is very powerful but it is also somewhat unfriendly to users who aren't familiar with systemtap, or who don't need its power right now. stap -e "....some strange script...." The 'log' backend for QEMU by comparison is very crude but incredibly easy to use: $ qemu -d trace:qio* ...some args... 23266@1547735759.137292:qio_channel_socket_new Socket new ioc=0x563a8a39d400 23266@1547735759.137305:qio_task_new Task new task=0x563a891d0570 source=0x563a8a39d400 func=0x563a86f1e6c0 opaque=0x563a89078000 23266@1547735759.137326:qio_task_thread_start Task thread start task=0x563a891d0570 worker=0x563a86f1ce50 opaque=0x563a891d9d90 23273@1547735759.137491:qio_task_thread_run Task thread run task=0x563a891d0570 23273@1547735759.137503:qio_channel_socket_connect_sync Socket connect sync ioc=0x563a8a39d400 addr=0x563a891d9d90 23273@1547735759.138108:qio_channel_socket_connect_fail Socket connect fail ioc=0x563a8a39d400 This commit introduces a way to do simple printf style logging of probe points using systemtap. In particular it creates another set of tapsets, one per emulator: /usr/share/systemtap/tapset/qemu-*-log.stp These pre-define probe functions which simply call printf() on their arguments. The printf() format string is taken from the normal trace-events files, with a little munging to the format specifiers to cope with systemtap's more restrictive syntax. With this you can now do $ stap -e 'probe qemu.system.x86_64.log.qio*{}' 22806@1547735341399856820 qio_channel_socket_new Socket new ioc=0x56135d1d7c00 22806@1547735341399862570 qio_task_new Task new task=0x56135cd66eb0 source=0x56135d1d7c00 func=0x56135af746c0 opaque=0x56135bf06400 22806@1547735341399865943 qio_task_thread_start Task thread start task=0x56135cd66eb0 worker=0x56135af72e50 opaque=0x56135c071d70 22806@1547735341399976816 qio_task_thread_run Task thread run task=0x56135cd66eb0 We go one step further though and introduce a 'qemu-trace-stap' tool to make this even easier $ qemu-trace-stap run qemu-system-x86_64 'qio*' 22806@1547735341399856820 qio_channel_socket_new Socket new ioc=0x56135d1d7c00 22806@1547735341399862570 qio_task_new Task new task=0x56135cd66eb0 source=0x56135d1d7c00 func=0x56135af746c0 opaque=0x56135bf06400 22806@1547735341399865943 qio_task_thread_start Task thread start task=0x56135cd66eb0 worker=0x56135af72e50 opaque=0x56135c071d70 22806@1547735341399976816 qio_task_thread_run Task thread run task=0x56135cd66eb0 This tool is clever in that it will automatically change the SYSTEMTAP_TAPSET env variable to point to the directory containing the right set of probes for the QEMU binary path you give it. This is useful if you have QEMU installed in /usr but are trying to test and trace a binary in /home/berrange/usr/qemu-git. In that case you'd do $ qemu-trace-stap run /home/berrange/usr/qemu-git/bin/qemu-system-x86_64 'qio*' And it'll make sure /home/berrange/usr/qemu-git/share/systemtap/tapset is used for the trace session The 'qemu-trace-stap' script takes a verbose arg so you can understand what it is running $ qemu-trace-stap run /home/berrange/usr/qemu-git/bin/qemu-system-x86_64 'qio*' Using tapset dir '/home/berrange/usr/qemu-git/share/systemtap/tapset' for binary '/home/berrange/usr/qemu-git/bin/qemu-system-x86_64' Compiling script 'probe qemu.system.x86_64.log.qio* {}' Running script, <Ctrl>-c to quit ...trace output... It can enable multiple probes at once $ qemu-trace-stap run qemu-system-x86_64 'qio*' 'qcrypto*' 'buffer*' By default it monitors all existing running processes and all future launched proceses. This can be restricted to a specific PID using the --pid arg $ qemu-trace-stap run --pid 2532 qemu-system-x86_64 'qio*' Finally if you can't remember what probes are valid it can tell you $ qemu-trace-stap list qemu-system-x86_64 ahci_check_irq ahci_cmd_done ahci_dma_prepare_buf ahci_dma_prepare_buf_fail ahci_dma_rw_buf ahci_irq_lower ...snip... Or list just those matching a prefix pattern $ qemu-trace-stap list -v qemu-system-x86_64 'qio*' Using tapset dir '/home/berrange/usr/qemu-git/share/systemtap/tapset' for binary '/home/berrange/usr/qemu-git/bin/qemu-system-x86_64' Listing probes with name 'qemu.system.x86_64.log.qio*' qio_channel_command_abort qio_channel_command_new_pid qio_channel_command_new_spawn qio_channel_command_wait qio_channel_file_new_fd ...snip... Reviewed-by: Eric Blake <eblake@redhat.com> Signed-off-by: Daniel P. Berrangé <berrange@redhat.com> Message-id: 20190123120016.4538-5-berrange@redhat.com Signed-off-by: Stefan Hajnoczi <stefanha@redhat.com>
2019-01-23 13:00:16 +01:00
return fmt
def generate(events, backend, group):
out('/* This file is autogenerated by tracetool, do not edit. */',
'')
for event_id, e in enumerate(events):
if 'disable' in e.properties:
continue
out('probe %(probeprefix)s.log.%(name)s = %(probeprefix)s.%(name)s ?',
'{',
probeprefix=probeprefix(),
name=e.name)
# Get references to userspace strings
for type_, name in e.args:
name = stap_escape(name)
if is_string(type_):
out(' try {',
' arg%(name)s_str = %(name)s ? ' +
'user_string_n(%(name)s, 512) : "<null>"',
' } catch {}',
name=name)
# Determine systemtap's view of variable names
fields = ["pid()", "gettimeofday_ns()"]
for type_, name in e.args:
name = stap_escape(name)
if is_string(type_):
fields.append("arg" + name + "_str")
else:
fields.append(name)
# Emit the entire record in a single SystemTap printf()
arg_str = ', '.join(arg for arg in fields)
fmt_str = "%d@%d " + e.name + " " + c_fmt_to_stap(e.fmt) + "\\n"
out(' printf("%(fmt_str)s", %(arg_str)s)',
fmt_str=fmt_str, arg_str=arg_str)
out('}')
out()