[Qemu-devel] [PULL v1 0/5] Merge tpm 2018/03/07

[Qemu-devel] [PULL v1 0/5] Merge tpm 2018/03/07

[Stefan Berger]

This series of patches converts the TPM code to use trace-events rather than
debug #define's.

    Stefan

The following changes since commit 8cb340c613ee3e626b070e0429c589f8a60ac657:

  Merge remote-tracking branch 'remotes/famz/tags/staging-pull-request' into staging (2018-03-01 12:32:31 +0000)

are available in the git repository at:

  git://github.com/stefanberger/qemu-tpm.git tags/pull-tpm-2018-03-07-1

for you to fetch changes up to fcbed221ff7230c6a5ebfb2ed27dc114ff5a30b0:

  tpm: convert tpm_tis.c to use trace-events (2018-03-06 13:00:41 -0500)

----------------------------------------------------------------
Stefan Berger (5):
      tpm: convert tpm_crb.c to use trace-events
      tpm: convert tpm_passthrough.c to use trace-events
      tpm: convert tpm_util.c to use trace-events
      tpm: convert tpm_emulator.c to use trace-events
      tpm: convert tpm_tis.c to use trace-events

 Makefile.objs            |  1 +
 hw/tpm/tpm_crb.c         | 17 +++++---------
 hw/tpm/tpm_emulator.c    | 45 +++++++++++++++++++------------------
 hw/tpm/tpm_passthrough.c | 13 +++--------
 hw/tpm/tpm_tis.c         | 98 +++++++++++++++++++++++++++++++++++++-------------------------------------------
 hw/tpm/tpm_util.c        | 29 ++++++++++--------------
 hw/tpm/trace-events      | 46 ++++++++++++++++++++++++++++++++++++++
 7 files changed, 135 insertions(+), 114 deletions(-)
 create mode 100644 hw/tpm/trace-events

-- 
2.5.5

[Qemu-devel] [PULL v1 1/5] tpm: convert tpm_crb.c to use trace-events

[Stefan Berger]

Signed-off-by: Stefan Berger <stefanb@linux.vnet.ibm.com>
Reviewed-by: Philippe Mathieu-Daudé <f4bug@amsat.org>
Reviewed-by: Marc-André Lureau <marcandre.lureau@redhat.com>
Reviewed-by: Stefan Hajnoczi <stefanha@redhat.com>
---
 Makefile.objs       |  1 +
 hw/tpm/tpm_crb.c    | 17 +++++------------
 hw/tpm/trace-events |  5 +++++
 3 files changed, 11 insertions(+), 12 deletions(-)
 create mode 100644 hw/tpm/trace-events

diff --git a/Makefile.objs b/Makefile.objs
index 5dc1348..72c3d8c 100644
--- a/Makefile.objs
+++ b/Makefile.objs
@@ -162,6 +162,7 @@ trace-events-subdirs += hw/alpha
 trace-events-subdirs += hw/hppa
 trace-events-subdirs += hw/xen
 trace-events-subdirs += hw/ide
+trace-events-subdirs += hw/tpm
 trace-events-subdirs += ui
 trace-events-subdirs += audio
 trace-events-subdirs += net
diff --git a/hw/tpm/tpm_crb.c b/hw/tpm/tpm_crb.c
index b5b8256..d8917cb 100644
--- a/hw/tpm/tpm_crb.c
+++ b/hw/tpm/tpm_crb.c
@@ -29,6 +29,7 @@
 #include "sysemu/reset.h"
 #include "tpm_int.h"
 #include "tpm_util.h"
+#include "trace.h"
 
 typedef struct CRBState {
     DeviceState parent_obj;
@@ -44,14 +45,6 @@ typedef struct CRBState {
 
 #define CRB(obj) OBJECT_CHECK(CRBState, (obj), TYPE_TPM_CRB)
 
-#define DEBUG_CRB 0
-
-#define DPRINTF(fmt, ...) do {                  \
-        if (DEBUG_CRB) {                        \
-            printf(fmt, ## __VA_ARGS__);        \
-        }                                       \
-    } while (0)
-
 #define CRB_INTF_TYPE_CRB_ACTIVE 0b1
 #define CRB_INTF_VERSION_CRB 0b1
 #define CRB_INTF_CAP_LOCALITY_0_ONLY 0b0
@@ -91,8 +84,8 @@ static uint64_t tpm_crb_mmio_read(void *opaque, hwaddr addr,
     unsigned offset = addr & 3;
     uint32_t val = *(uint32_t *)regs >> (8 * offset);
 
-    DPRINTF("CRB read 0x" TARGET_FMT_plx " len:%u val: 0x%" PRIx32 "\n",
-            addr, size, val);
+    trace_tpm_crb_mmio_read(addr, size, val);
+
     return val;
 }
 
@@ -100,8 +93,8 @@ static void tpm_crb_mmio_write(void *opaque, hwaddr addr,
                                uint64_t val, unsigned size)
 {
     CRBState *s = CRB(opaque);
-    DPRINTF("CRB write 0x" TARGET_FMT_plx " len:%u val: 0x%" PRIx64 "\n",
-            addr, size, val);
+
+    trace_tpm_crb_mmio_write(addr, size, val);
 
     switch (addr) {
     case A_CRB_CTRL_REQ:
diff --git a/hw/tpm/trace-events b/hw/tpm/trace-events
new file mode 100644
index 0000000..336b06d
--- /dev/null
+++ b/hw/tpm/trace-events
@@ -0,0 +1,5 @@
+# See docs/devel/tracing.txt for syntax documentation.
+
+# hw/tpm/tpm_crb.c
+tpm_crb_mmio_read(uint64_t addr, unsigned size, uint32_t val) "CRB read 0x" TARGET_FMT_plx " len:%u val: 0x%" PRIx32
+tpm_crb_mmio_write(uint64_t addr, unsigned size, uint32_t val) "CRB write 0x" TARGET_FMT_plx " len:%u val: 0x%" PRIx32
-- 
2.5.5

[Qemu-devel] [PULL v1 2/5] tpm: convert tpm_passthrough.c to use trace-events

[Stefan Berger]

Signed-off-by: Stefan Berger <stefanb@linux.vnet.ibm.com>
Reviewed-by: Philippe Mathieu-Daudé <f4bug@amsat.org>
Reviewed-by: Marc-André Lureau <marcandre.lureau@redhat.com>
Reviewed-by: Stefan Hajnoczi <stefanha@redhat.com>
---
 hw/tpm/tpm_passthrough.c | 13 +++----------
 hw/tpm/trace-events      |  4 ++++
 2 files changed, 7 insertions(+), 10 deletions(-)

diff --git a/hw/tpm/tpm_passthrough.c b/hw/tpm/tpm_passthrough.c
index a495fe0..2589c4d 100644
--- a/hw/tpm/tpm_passthrough.c
+++ b/hw/tpm/tpm_passthrough.c
@@ -31,14 +31,7 @@
 #include "hw/hw.h"
 #include "qapi/clone-visitor.h"
 #include "tpm_util.h"
-
-#define DEBUG_TPM 0
-
-#define DPRINTF(fmt, ...) do { \
-    if (DEBUG_TPM) { \
-        fprintf(stderr, fmt, ## __VA_ARGS__); \
-    } \
-} while (0)
+#include "trace.h"
 
 #define TYPE_TPM_PASSTHROUGH "tpm-passthrough"
 #define TPM_PASSTHROUGH(obj) \
@@ -137,7 +130,7 @@ static void tpm_passthrough_handle_request(TPMBackend *tb, TPMBackendCmd *cmd,
 {
     TPMPassthruState *tpm_pt = TPM_PASSTHROUGH(tb);
 
-    DPRINTF("tpm_passthrough: processing command %p\n", cmd);
+    trace_tpm_passthrough_handle_request(cmd);
 
     tpm_passthrough_unix_tx_bufs(tpm_pt, cmd->in, cmd->in_len,
                                  cmd->out, cmd->out_len, &cmd->selftest_done,
@@ -146,7 +139,7 @@ static void tpm_passthrough_handle_request(TPMBackend *tb, TPMBackendCmd *cmd,
 
 static void tpm_passthrough_reset(TPMBackend *tb)
 {
-    DPRINTF("tpm_passthrough: CALL TO TPM_RESET!\n");
+    trace_tpm_passthrough_reset();
 
     tpm_passthrough_cancel_cmd(tb);
 }
diff --git a/hw/tpm/trace-events b/hw/tpm/trace-events
index 336b06d..8557dd9 100644
--- a/hw/tpm/trace-events
+++ b/hw/tpm/trace-events
@@ -3,3 +3,7 @@
 # hw/tpm/tpm_crb.c
 tpm_crb_mmio_read(uint64_t addr, unsigned size, uint32_t val) "CRB read 0x" TARGET_FMT_plx " len:%u val: 0x%" PRIx32
 tpm_crb_mmio_write(uint64_t addr, unsigned size, uint32_t val) "CRB write 0x" TARGET_FMT_plx " len:%u val: 0x%" PRIx32
+
+# hw/tpm/tpm_passthrough.c
+tpm_passthrough_handle_request(void *cmd) "processing command %p"
+tpm_passthrough_reset(void) "reset"
-- 
2.5.5

[Qemu-devel] [PULL v1 3/5] tpm: convert tpm_util.c to use trace-events

[Stefan Berger]

Signed-off-by: Stefan Berger <stefanb@linux.vnet.ibm.com>
Reviewed-by: Philippe Mathieu-Daudé <f4bug@amsat.org>
Reviewed-by: Marc-André Lureau <marcandre.lureau@redhat.com>
Reviewed-by: Stefan Hajnoczi <stefanha@redhat.com>
---
 hw/tpm/tpm_util.c   | 29 ++++++++++++-----------------
 hw/tpm/trace-events |  7 +++++++
 2 files changed, 19 insertions(+), 17 deletions(-)

diff --git a/hw/tpm/tpm_util.c b/hw/tpm/tpm_util.c
index 2de52a0..ee41757 100644
--- a/hw/tpm/tpm_util.c
+++ b/hw/tpm/tpm_util.c
@@ -28,14 +28,7 @@
 #include "exec/memory.h"
 #include "sysemu/tpm_backend.h"
 #include "hw/qdev.h"
-
-#define DEBUG_TPM 0
-
-#define DPRINTF(fmt, ...) do { \
-    if (DEBUG_TPM) { \
-        fprintf(stderr, "tpm-util:"fmt"\n", ## __VA_ARGS__); \
-    } \
-} while (0)
+#include "trace.h"
 
 /* tpm backend property */
 
@@ -279,10 +272,11 @@ int tpm_util_get_buffer_size(int tpm_fd, TPMVersion tpm_version,
 
         if (be32_to_cpu(tpm_resp.hdr.len) != sizeof(tpm_resp) ||
             be32_to_cpu(tpm_resp.len) != sizeof(uint32_t)) {
-            DPRINTF("tpm_resp->hdr.len = %u, expected = %zu\n",
-                    be32_to_cpu(tpm_resp.hdr.len), sizeof(tpm_resp));
-            DPRINTF("tpm_resp->len = %u, expected = %zu\n",
-                    be32_to_cpu(tpm_resp.len), sizeof(uint32_t));
+            trace_tpm_util_get_buffer_size_hdr_len(
+                be32_to_cpu(tpm_resp.hdr.len),
+                sizeof(tpm_resp));
+            trace_tpm_util_get_buffer_size_len(be32_to_cpu(tpm_resp.len),
+                                               sizeof(uint32_t));
             error_report("tpm_util: Got unexpected response to "
                          "TPM_GetCapability; errcode: 0x%x",
                          be32_to_cpu(tpm_resp.hdr.errcode));
@@ -327,10 +321,11 @@ int tpm_util_get_buffer_size(int tpm_fd, TPMVersion tpm_version,
 
         if (be32_to_cpu(tpm2_resp.hdr.len) != sizeof(tpm2_resp) ||
             be32_to_cpu(tpm2_resp.count) != 2) {
-            DPRINTF("tpm2_resp->hdr.len = %u, expected = %zu\n",
-                    be32_to_cpu(tpm2_resp.hdr.len), sizeof(tpm2_resp));
-            DPRINTF("tpm2_resp->len = %u, expected = %u\n",
-                    be32_to_cpu(tpm2_resp.count), 2);
+            trace_tpm_util_get_buffer_size_hdr_len2(
+                be32_to_cpu(tpm2_resp.hdr.len),
+                sizeof(tpm2_resp));
+            trace_tpm_util_get_buffer_size_len2(
+                be32_to_cpu(tpm2_resp.count), 2);
             error_report("tpm_util: Got unexpected response to "
                          "TPM2_GetCapability; errcode: 0x%x",
                          be32_to_cpu(tpm2_resp.hdr.errcode));
@@ -344,7 +339,7 @@ int tpm_util_get_buffer_size(int tpm_fd, TPMVersion tpm_version,
         return -EFAULT;
     }
 
-    DPRINTF("buffersize of device: %zu\n", *buffersize);
+    trace_tpm_util_get_buffer_size(*buffersize);
 
     return 0;
 }
diff --git a/hw/tpm/trace-events b/hw/tpm/trace-events
index 8557dd9..66b2b91 100644
--- a/hw/tpm/trace-events
+++ b/hw/tpm/trace-events
@@ -7,3 +7,10 @@ tpm_crb_mmio_write(uint64_t addr, unsigned size, uint32_t val) "CRB write 0x" TA
 # hw/tpm/tpm_passthrough.c
 tpm_passthrough_handle_request(void *cmd) "processing command %p"
 tpm_passthrough_reset(void) "reset"
+
+# hw/tpm/tpm_util.c
+tpm_util_get_buffer_size_hdr_len(uint32_t len, size_t expected) "tpm_resp->hdr.len = %u, expected = %zu"
+tpm_util_get_buffer_size_len(uint32_t len, size_t expected) "tpm_resp->len = %u, expected = %zu"
+tpm_util_get_buffer_size_hdr_len2(uint32_t len, size_t expected) "tpm2_resp->hdr.len = %u, expected = %zu"
+tpm_util_get_buffer_size_len2(uint32_t len, size_t expected) "tpm2_resp->len = %u, expected = %zu"
+tpm_util_get_buffer_size(size_t len) "buffersize of device: %zu"
-- 
2.5.5

[Qemu-devel] [PULL v1 4/5] tpm: convert tpm_emulator.c to use trace-events

[Stefan Berger]

Signed-off-by: Stefan Berger <stefanb@linux.vnet.ibm.com>
Reviewed-by: Philippe Mathieu-Daudé <f4bug@amsat.org>
Reviewed-by: Marc-André Lureau <marcandre.lureau@redhat.com>
Reviewed-by: Stefan Hajnoczi <stefanha@redhat.com>
---
 hw/tpm/tpm_emulator.c | 45 +++++++++++++++++++++++----------------------
 hw/tpm/trace-events   | 14 ++++++++++++++
 2 files changed, 37 insertions(+), 22 deletions(-)

diff --git a/hw/tpm/tpm_emulator.c b/hw/tpm/tpm_emulator.c
index b787aee..d0da10a 100644
--- a/hw/tpm/tpm_emulator.c
+++ b/hw/tpm/tpm_emulator.c
@@ -39,14 +39,7 @@
 #include "qapi/error.h"
 #include "qapi/clone-visitor.h"
 #include "chardev/char-fe.h"
-
-#define DEBUG_TPM 0
-
-#define DPRINTF(fmt, ...) do { \
-    if (DEBUG_TPM) { \
-        fprintf(stderr, "tpm-emulator:"fmt"\n", ## __VA_ARGS__); \
-    } \
-} while (0)
+#include "trace.h"
 
 #define TYPE_TPM_EMULATOR "tpm-emulator"
 #define TPM_EMULATOR(obj) \
@@ -151,13 +144,12 @@ static int tpm_emulator_set_locality(TPMEmulator *tpm_emu, uint8_t locty_number,
 {
     ptm_loc loc;
 
-    DPRINTF("%s : locality: 0x%x", __func__, locty_number);
-
     if (tpm_emu->cur_locty_number == locty_number) {
         return 0;
     }
 
-    DPRINTF("setting locality : 0x%x", locty_number);
+    trace_tpm_emulator_set_locality(locty_number);
+
     loc.u.req.loc = locty_number;
     if (tpm_emulator_ctrlcmd(tpm_emu, CMD_SET_LOCALITY, &loc,
                              sizeof(loc), sizeof(loc)) < 0) {
@@ -183,7 +175,7 @@ static void tpm_emulator_handle_request(TPMBackend *tb, TPMBackendCmd *cmd,
 {
     TPMEmulator *tpm_emu = TPM_EMULATOR(tb);
 
-    DPRINTF("processing TPM command");
+    trace_tpm_emulator_handle_request();
 
     if (tpm_emulator_set_locality(tpm_emu, cmd->locty, errp) < 0 ||
         tpm_emulator_unix_tx_bufs(tpm_emu, cmd->in, cmd->in_len,
@@ -195,7 +187,6 @@ static void tpm_emulator_handle_request(TPMBackend *tb, TPMBackendCmd *cmd,
 
 static int tpm_emulator_probe_caps(TPMEmulator *tpm_emu)
 {
-    DPRINTF("%s", __func__);
     if (tpm_emulator_ctrlcmd(tpm_emu, CMD_GET_CAPABILITY,
                              &tpm_emu->caps, 0, sizeof(tpm_emu->caps)) < 0) {
         error_report("tpm-emulator: probing failed : %s", strerror(errno));
@@ -204,7 +195,7 @@ static int tpm_emulator_probe_caps(TPMEmulator *tpm_emu)
 
     tpm_emu->caps = be64_to_cpu(tpm_emu->caps);
 
-    DPRINTF("capabilities : 0x%"PRIx64, tpm_emu->caps);
+    trace_tpm_emulator_probe_caps(tpm_emu->caps);
 
     return 0;
 }
@@ -293,7 +284,7 @@ static int tpm_emulator_set_buffer_size(TPMBackend *tb,
         *actual_size = be32_to_cpu(psbs.u.resp.buffersize);
     }
 
-    DPRINTF("buffer size: %u, min: %u, max: %u\n",
+    trace_tpm_emulator_set_buffer_size(
             be32_to_cpu(psbs.u.resp.buffersize),
             be32_to_cpu(psbs.u.resp.minsize),
             be32_to_cpu(psbs.u.resp.maxsize));
@@ -314,7 +305,7 @@ static int tpm_emulator_startup_tpm(TPMBackend *tb, size_t buffersize)
         goto err_exit;
     }
 
-    DPRINTF("%s", __func__);
+    trace_tpm_emulator_startup_tpm();
     if (tpm_emulator_ctrlcmd(tpm_emu, CMD_INIT, &init, sizeof(init),
                              sizeof(init)) < 0) {
         error_report("tpm-emulator: could not send INIT: %s",
@@ -348,7 +339,7 @@ static bool tpm_emulator_get_tpm_established_flag(TPMBackend *tb)
                      strerror(errno));
         return false;
     }
-    DPRINTF("got established flag: %0x", est.u.resp.bit);
+    trace_tpm_emulator_get_tpm_established_flag(est.u.resp.bit);
 
     tpm_emu->established_flag_cached = 1;
     tpm_emu->established_flag = (est.u.resp.bit != 0);
@@ -395,7 +386,7 @@ static void tpm_emulator_cancel_cmd(TPMBackend *tb)
     ptm_res res;
 
     if (!TPM_EMULATOR_IMPLEMENTS_ALL_CAPS(tpm_emu, PTM_CAP_CANCEL_TPM_CMD)) {
-        DPRINTF("Backend does not support CANCEL_TPM_CMD");
+        trace_tpm_emulator_cancel_cmd_not_supt();
         return;
     }
 
@@ -521,8 +512,16 @@ static int tpm_emulator_handle_device_opts(TPMEmulator *tpm_emu, QemuOpts *opts)
         goto err;
     }
 
-    DPRINTF("TPM Version %s", tpm_emu->tpm_version == TPM_VERSION_1_2 ? "1.2" :
-            (tpm_emu->tpm_version == TPM_VERSION_2_0 ?  "2.0" : "Unspecified"));
+    switch (tpm_emu->tpm_version) {
+    case TPM_VERSION_1_2:
+        trace_tpm_emulator_handle_device_opts_tpm12();
+        break;
+    case TPM_VERSION_2_0:
+        trace_tpm_emulator_handle_device_opts_tpm2();
+        break;
+    default:
+        trace_tpm_emulator_handle_device_opts_unspec();
+    }
 
     if (tpm_emulator_probe_caps(tpm_emu) ||
         tpm_emulator_check_caps(tpm_emu)) {
@@ -532,7 +531,8 @@ static int tpm_emulator_handle_device_opts(TPMEmulator *tpm_emu, QemuOpts *opts)
     return tpm_emulator_block_migration(tpm_emu);
 
 err:
-    DPRINTF("Startup error");
+    trace_tpm_emulator_handle_device_opts_startup_error();
+
     return -1;
 }
 
@@ -573,7 +573,8 @@ static void tpm_emulator_inst_init(Object *obj)
 {
     TPMEmulator *tpm_emu = TPM_EMULATOR(obj);
 
-    DPRINTF("%s", __func__);
+    trace_tpm_emulator_inst_init();
+
     tpm_emu->options = g_new0(TPMEmulatorOptions, 1);
     tpm_emu->cur_locty_number = ~0;
     qemu_mutex_init(&tpm_emu->mutex);
diff --git a/hw/tpm/trace-events b/hw/tpm/trace-events
index 66b2b91..fe88fa6 100644
--- a/hw/tpm/trace-events
+++ b/hw/tpm/trace-events
@@ -14,3 +14,17 @@ tpm_util_get_buffer_size_len(uint32_t len, size_t expected) "tpm_resp->len = %u,
 tpm_util_get_buffer_size_hdr_len2(uint32_t len, size_t expected) "tpm2_resp->hdr.len = %u, expected = %zu"
 tpm_util_get_buffer_size_len2(uint32_t len, size_t expected) "tpm2_resp->len = %u, expected = %zu"
 tpm_util_get_buffer_size(size_t len) "buffersize of device: %zu"
+
+# hw/tpm/tpm_emulator.c
+tpm_emulator_set_locality(uint8_t locty) "setting locality to %d"
+tpm_emulator_handle_request(void) "processing TPM command"
+tpm_emulator_probe_caps(uint64_t caps) "capabilities: 0x%"PRIx64
+tpm_emulator_set_buffer_size(uint32_t buffersize, uint32_t minsize, uint32_t maxsize) "buffer size: %u, min: %u, max: %u"
+tpm_emulator_startup_tpm(void) "startup"
+tpm_emulator_get_tpm_established_flag(uint8_t flag) "got established flag: %d"
+tpm_emulator_cancel_cmd_not_supt(void) "Backend does not support CANCEL_TPM_CMD"
+tpm_emulator_handle_device_opts_tpm12(void) "TPM Version 1.2"
+tpm_emulator_handle_device_opts_tpm2(void) "TPM Version 2"
+tpm_emulator_handle_device_opts_unspec(void) "TPM Version Unspecified"
+tpm_emulator_handle_device_opts_startup_error(void) "Startup error"
+tpm_emulator_inst_init(void) ""
-- 
2.5.5

[Qemu-devel] [PULL v1 5/5] tpm: convert tpm_tis.c to use trace-events

[Stefan Berger]

Leave the DEBUG_TIS for more debugging and convert to use if (DEBUG_TIS)
rather than #if DEBUG_TIS where it is being used.

Signed-off-by: Stefan Berger <stefanb@linux.vnet.ibm.com>
Reviewed-by: Philippe Mathieu-Daudé <f4bug@amsat.org>
Reviewed-by: Marc-André Lureau <marcandre.lureau@redhat.com>
Reviewed-by: Stefan Hajnoczi <stefanha@redhat.com>
---
 hw/tpm/tpm_tis.c    | 98 ++++++++++++++++++++++++-----------------------------
 hw/tpm/trace-events | 16 +++++++++
 2 files changed, 61 insertions(+), 53 deletions(-)

diff --git a/hw/tpm/tpm_tis.c b/hw/tpm/tpm_tis.c
index 834eef7..2ac7e74 100644
--- a/hw/tpm/tpm_tis.c
+++ b/hw/tpm/tpm_tis.c
@@ -31,6 +31,7 @@
 #include "sysemu/tpm_backend.h"
 #include "tpm_int.h"
 #include "tpm_util.h"
+#include "trace.h"
 
 #define TPM_TIS_NUM_LOCALITIES      5     /* per spec */
 #define TPM_TIS_LOCALITY_SHIFT      12
@@ -86,12 +87,6 @@ typedef struct TPMState {
 
 #define DEBUG_TIS 0
 
-#define DPRINTF(fmt, ...) do { \
-    if (DEBUG_TIS) { \
-        printf(fmt, ## __VA_ARGS__); \
-    } \
-} while (0)
-
 /* local prototypes */
 
 static uint64_t tpm_tis_mmio_read(void *opaque, hwaddr addr,
@@ -107,19 +102,17 @@ static uint8_t tpm_tis_locality_from_addr(hwaddr addr)
 static void tpm_tis_show_buffer(const unsigned char *buffer,
                                 size_t buffer_size, const char *string)
 {
-#ifdef DEBUG_TIS
     uint32_t len, i;
 
     len = MIN(tpm_cmd_get_size(buffer), buffer_size);
-    DPRINTF("tpm_tis: %s length = %d\n", string, len);
+    printf("tpm_tis: %s length = %d\n", string, len);
     for (i = 0; i < len; i++) {
         if (i && !(i % 16)) {
-            DPRINTF("\n");
+            printf("\n");
         }
-        DPRINTF("%.2X ", buffer[i]);
+        printf("%.2X ", buffer[i]);
     }
-    DPRINTF("\n");
-#endif
+    printf("\n");
 }
 
 /*
@@ -146,8 +139,10 @@ static void tpm_tis_sts_set(TPMLocality *l, uint32_t flags)
  */
 static void tpm_tis_tpm_send(TPMState *s, uint8_t locty)
 {
-    tpm_tis_show_buffer(s->buffer, s->be_buffer_size,
-                        "tpm_tis: To TPM");
+    if (DEBUG_TIS) {
+        tpm_tis_show_buffer(s->buffer, s->be_buffer_size,
+                            "tpm_tis: To TPM");
+    }
 
     /*
      * rw_offset serves as length indicator for length of data;
@@ -175,7 +170,7 @@ static void tpm_tis_raise_irq(TPMState *s, uint8_t locty, uint32_t irqmask)
 
     if ((s->loc[locty].inte & TPM_TIS_INT_ENABLED) &&
         (s->loc[locty].inte & irqmask)) {
-        DPRINTF("tpm_tis: Raising IRQ for flag %08x\n", irqmask);
+        trace_tpm_tis_raise_irq(irqmask);
         qemu_irq_raise(s->irq);
         s->loc[locty].ints |= irqmask;
     }
@@ -223,7 +218,7 @@ static void tpm_tis_new_active_locality(TPMState *s, uint8_t new_active_locty)
 
     s->active_locty = new_active_locty;
 
-    DPRINTF("tpm_tis: Active locality is now %d\n", s->active_locty);
+    trace_tpm_tis_new_active_locality(s->active_locty);
 
     if (TPM_TIS_IS_VALID_LOCTY(new_active_locty)) {
         /* set flags on the new active locality */
@@ -242,7 +237,7 @@ static void tpm_tis_abort(TPMState *s, uint8_t locty)
 {
     s->rw_offset = 0;
 
-    DPRINTF("tpm_tis: tis_abort: new active locality is %d\n", s->next_locty);
+    trace_tpm_tis_abort(s->next_locty);
 
     /*
      * Need to react differently depending on who's aborting now and
@@ -310,8 +305,10 @@ static void tpm_tis_request_completed(TPMIf *ti, int ret)
     s->loc[locty].state = TPM_TIS_STATE_COMPLETION;
     s->rw_offset = 0;
 
-    tpm_tis_show_buffer(s->buffer, s->be_buffer_size,
-                        "tpm_tis: From TPM");
+    if (DEBUG_TIS) {
+        tpm_tis_show_buffer(s->buffer, s->be_buffer_size,
+                            "tpm_tis: From TPM");
+    }
 
     if (TPM_TIS_IS_VALID_LOCTY(s->next_locty)) {
         tpm_tis_abort(s, locty);
@@ -339,8 +336,7 @@ static uint32_t tpm_tis_data_read(TPMState *s, uint8_t locty)
             tpm_tis_sts_set(&s->loc[locty], TPM_TIS_STS_VALID);
             tpm_tis_raise_irq(s, locty, TPM_TIS_INT_STS_VALID);
         }
-        DPRINTF("tpm_tis: tpm_tis_data_read byte 0x%02x   [%d]\n",
-                ret, s->rw_offset - 1);
+        trace_tpm_tis_data_read(ret, s->rw_offset - 1);
     }
 
     return ret;
@@ -364,29 +360,29 @@ static void tpm_tis_dump_state(void *opaque, hwaddr addr)
     hwaddr base = addr & ~0xfff;
     TPMState *s = opaque;
 
-    DPRINTF("tpm_tis: active locality      : %d\n"
-            "tpm_tis: state of locality %d : %d\n"
-            "tpm_tis: register dump:\n",
-            s->active_locty,
-            locty, s->loc[locty].state);
+    printf("tpm_tis: active locality      : %d\n"
+           "tpm_tis: state of locality %d : %d\n"
+           "tpm_tis: register dump:\n",
+           s->active_locty,
+           locty, s->loc[locty].state);
 
     for (idx = 0; regs[idx] != 0xfff; idx++) {
-        DPRINTF("tpm_tis: 0x%04x : 0x%08x\n", regs[idx],
-                (int)tpm_tis_mmio_read(opaque, base + regs[idx], 4));
+        printf("tpm_tis: 0x%04x : 0x%08x\n", regs[idx],
+               (int)tpm_tis_mmio_read(opaque, base + regs[idx], 4));
     }
 
-    DPRINTF("tpm_tis: r/w offset    : %d\n"
-            "tpm_tis: result buffer : ",
-            s->rw_offset);
+    printf("tpm_tis: r/w offset    : %d\n"
+           "tpm_tis: result buffer : ",
+           s->rw_offset);
     for (idx = 0;
          idx < MIN(tpm_cmd_get_size(&s->buffer), s->be_buffer_size);
          idx++) {
-        DPRINTF("%c%02x%s",
-                s->rw_offset == idx ? '>' : ' ',
-                s->buffer[idx],
-                ((idx & 0xf) == 0xf) ? "\ntpm_tis:                 " : "");
+        printf("%c%02x%s",
+               s->rw_offset == idx ? '>' : ' ',
+               s->buffer[idx],
+               ((idx & 0xf) == 0xf) ? "\ntpm_tis:                 " : "");
     }
-    DPRINTF("\n");
+    printf("\n");
 }
 #endif
 
@@ -506,7 +502,7 @@ static uint64_t tpm_tis_mmio_read(void *opaque, hwaddr addr,
         val >>= shift;
     }
 
-    DPRINTF("tpm_tis:  read.%u(%08x) = %08x\n", size, (int)addr, (int)val);
+    trace_tpm_tis_mmio_read(size, addr, val);
 
     return val;
 }
@@ -527,10 +523,10 @@ static void tpm_tis_mmio_write(void *opaque, hwaddr addr,
     uint16_t len;
     uint32_t mask = (size == 1) ? 0xff : ((size == 2) ? 0xffff : ~0);
 
-    DPRINTF("tpm_tis: write.%u(%08x) = %08x\n", size, (int)addr, (int)val);
+    trace_tpm_tis_mmio_write(size, addr, val);
 
     if (locty == 4) {
-        DPRINTF("tpm_tis: Access to locality 4 only allowed from hardware\n");
+        trace_tpm_tis_mmio_write_locty4();
         return;
     }
 
@@ -560,20 +556,18 @@ static void tpm_tis_mmio_write(void *opaque, hwaddr addr,
         if ((val & TPM_TIS_ACCESS_ACTIVE_LOCALITY)) {
             /* give up locality if currently owned */
             if (s->active_locty == locty) {
-                DPRINTF("tpm_tis: Releasing locality %d\n", locty);
+                trace_tpm_tis_mmio_write_release_locty(locty);
 
                 uint8_t newlocty = TPM_TIS_NO_LOCALITY;
                 /* anybody wants the locality ? */
                 for (c = TPM_TIS_NUM_LOCALITIES - 1; c >= 0; c--) {
                     if ((s->loc[c].access & TPM_TIS_ACCESS_REQUEST_USE)) {
-                        DPRINTF("tpm_tis: Locality %d requests use.\n", c);
+                        trace_tpm_tis_mmio_write_locty_req_use(c);
                         newlocty = c;
                         break;
                     }
                 }
-                DPRINTF("tpm_tis: TPM_TIS_ACCESS_ACTIVE_LOCALITY: "
-                        "Next active locality: %d\n",
-                        newlocty);
+                trace_tpm_tis_mmio_write_next_locty(newlocty);
 
                 if (TPM_TIS_IS_VALID_LOCTY(newlocty)) {
                     set_new_locty = 0;
@@ -627,10 +621,10 @@ static void tpm_tis_mmio_write(void *opaque, hwaddr addr,
                 }
 
                 s->loc[locty].access |= TPM_TIS_ACCESS_SEIZE;
-                DPRINTF("tpm_tis: TPM_TIS_ACCESS_SEIZE: "
-                        "Locality %d seized from locality %d\n",
-                        locty, s->active_locty);
-                DPRINTF("tpm_tis: TPM_TIS_ACCESS_SEIZE: Initiating abort.\n");
+
+                trace_tpm_tis_mmio_write_locty_seized(locty, s->active_locty);
+                trace_tpm_tis_mmio_write_init_abort();
+
                 set_new_locty = 0;
                 tpm_tis_prep_abort(s, s->active_locty, locty);
                 break;
@@ -677,7 +671,7 @@ static void tpm_tis_mmio_write(void *opaque, hwaddr addr,
             s->loc[locty].ints &= ~val;
             if (s->loc[locty].ints == 0) {
                 qemu_irq_lower(s->irq);
-                DPRINTF("tpm_tis: Lowering IRQ\n");
+                trace_tpm_tis_mmio_write_lowering_irq();
             }
         }
         s->loc[locty].ints &= ~(val & TPM_TIS_INTERRUPTS_SUPPORTED);
@@ -725,8 +719,7 @@ static void tpm_tis_mmio_write(void *opaque, hwaddr addr,
             case TPM_TIS_STATE_EXECUTION:
             case TPM_TIS_STATE_RECEPTION:
                 /* abort currently running command */
-                DPRINTF("tpm_tis: %s: Initiating abort.\n",
-                        __func__);
+                trace_tpm_tis_mmio_write_init_abort();
                 tpm_tis_prep_abort(s, locty, locty);
             break;
 
@@ -780,8 +773,7 @@ static void tpm_tis_mmio_write(void *opaque, hwaddr addr,
             s->loc[locty].state == TPM_TIS_STATE_COMPLETION) {
             /* drop the byte */
         } else {
-            DPRINTF("tpm_tis: Data to send to TPM: %08x (size=%d)\n",
-                    (int)val, size);
+            trace_tpm_tis_mmio_write_data2send(val, size);
             if (s->loc[locty].state == TPM_TIS_STATE_READY) {
                 s->loc[locty].state = TPM_TIS_STATE_RECEPTION;
                 tpm_tis_sts_set(&s->loc[locty],
diff --git a/hw/tpm/trace-events b/hw/tpm/trace-events
index fe88fa6..9a65384 100644
--- a/hw/tpm/trace-events
+++ b/hw/tpm/trace-events
@@ -28,3 +28,19 @@ tpm_emulator_handle_device_opts_tpm2(void) "TPM Version 2"
 tpm_emulator_handle_device_opts_unspec(void) "TPM Version Unspecified"
 tpm_emulator_handle_device_opts_startup_error(void) "Startup error"
 tpm_emulator_inst_init(void) ""
+
+# hw/tpm/tpm_tis.c
+tpm_tis_raise_irq(uint32_t irqmask) "Raising IRQ for flag 0x%08x"
+tpm_tis_new_active_locality(uint8_t locty) "Active locality is now %d"
+tpm_tis_abort(uint8_t locty) "New active locality is %d"
+tpm_tis_data_read(uint32_t value, uint32_t off) "byte 0x%02x   [%d]"
+tpm_tis_mmio_read(unsigned size, uint32_t addr, uint32_t val)  " read.%u(0x%08x) = 0x%08x"
+tpm_tis_mmio_write(unsigned size, uint32_t addr, uint32_t val) "write.%u(0x%08x) = 0x%08x"
+tpm_tis_mmio_write_locty4(void) "Access to locality 4 only allowed from hardware"
+tpm_tis_mmio_write_release_locty(uint8_t locty) "Releasing locality %d"
+tpm_tis_mmio_write_locty_req_use(uint8_t locty) "Locality %d requests use"
+tpm_tis_mmio_write_next_locty(uint8_t locty) "Next active locality is %d"
+tpm_tis_mmio_write_locty_seized(uint8_t locty, uint8_t active) "Locality %d seized from locality %d"
+tpm_tis_mmio_write_init_abort(void) "Initiating abort"
+tpm_tis_mmio_write_lowering_irq(void) "Lowering IRQ"
+tpm_tis_mmio_write_data2send(uint32_t value, unsigned size) "Data to send to TPM: 0x%08x (size=%d)"
-- 
2.5.5

Re: [Qemu-devel] [PULL v1 0/5] Merge tpm 2018/03/07

[Peter Maydell]

On 7 March 2018 at 12:51, Stefan Berger <stefanb@linux.vnet.ibm.com> wrote:
> This series of patches converts the TPM code to use trace-events rather than
> debug #define's.
>
>     Stefan
>
> The following changes since commit 8cb340c613ee3e626b070e0429c589f8a60ac657:
>
>   Merge remote-tracking branch 'remotes/famz/tags/staging-pull-request' into staging (2018-03-01 12:32:31 +0000)
>
> are available in the git repository at:
>
>   git://github.com/stefanberger/qemu-tpm.git tags/pull-tpm-2018-03-07-1
>
> for you to fetch changes up to fcbed221ff7230c6a5ebfb2ed27dc114ff5a30b0:
>
>   tpm: convert tpm_tis.c to use trace-events (2018-03-06 13:00:41 -0500)
>
> ----------------------------------------------------------------
> Stefan Berger (5):
>       tpm: convert tpm_crb.c to use trace-events
>       tpm: convert tpm_passthrough.c to use trace-events
>       tpm: convert tpm_util.c to use trace-events
>       tpm: convert tpm_emulator.c to use trace-events
>       tpm: convert tpm_tis.c to use trace-events
Applied, thanks.

-- PMM