From ec427498da5a1a0d2d2e807a2681a3d1c5a93b02 Mon Sep 17 00:00:00 2001 From: Stefan Berger Date: Fri, 2 Mar 2018 20:18:41 -0500 Subject: [PATCH 1/5] tpm: convert tpm_crb.c to use trace-events MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Signed-off-by: Stefan Berger Reviewed-by: Philippe Mathieu-Daudé Reviewed-by: Marc-André Lureau Reviewed-by: Stefan Hajnoczi --- 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 5dc134818c..72c3d8c178 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 b5b8256360..d8917cb101 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 0000000000..336b06dc8d --- /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 From 49d302fe3d4de2b02f77b41f4f7de6d15e392f36 Mon Sep 17 00:00:00 2001 From: Stefan Berger Date: Fri, 2 Mar 2018 20:28:30 -0500 Subject: [PATCH 2/5] tpm: convert tpm_passthrough.c to use trace-events MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Signed-off-by: Stefan Berger Reviewed-by: Philippe Mathieu-Daudé Reviewed-by: Marc-André Lureau Reviewed-by: Stefan Hajnoczi --- 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 a495fe07f4..2589c4de76 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 336b06dc8d..8557dd9b88 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" From cc7d320f5d98a19eed5aa47b50e2186ba9c29ba7 Mon Sep 17 00:00:00 2001 From: Stefan Berger Date: Fri, 2 Mar 2018 20:42:48 -0500 Subject: [PATCH 3/5] tpm: convert tpm_util.c to use trace-events MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Signed-off-by: Stefan Berger Reviewed-by: Philippe Mathieu-Daudé Reviewed-by: Marc-André Lureau Reviewed-by: Stefan Hajnoczi --- 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 2de52a0f1b..ee41757ea2 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 8557dd9b88..66b2b91661 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" From 9d9dcd96023efcb88538261b7eeb4ed036b6ab29 Mon Sep 17 00:00:00 2001 From: Stefan Berger Date: Fri, 2 Mar 2018 21:04:42 -0500 Subject: [PATCH 4/5] tpm: convert tpm_emulator.c to use trace-events MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Signed-off-by: Stefan Berger Reviewed-by: Philippe Mathieu-Daudé Reviewed-by: Marc-André Lureau Reviewed-by: Stefan Hajnoczi --- 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 b787aee13b..d0da10a1a6 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 66b2b91661..fe88fa6a9d 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) "" From fcbed221ff7230c6a5ebfb2ed27dc114ff5a30b0 Mon Sep 17 00:00:00 2001 From: Stefan Berger Date: Fri, 2 Mar 2018 21:30:38 -0500 Subject: [PATCH 5/5] tpm: convert tpm_tis.c to use trace-events MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit 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 Reviewed-by: Philippe Mathieu-Daudé Reviewed-by: Marc-André Lureau Reviewed-by: Stefan Hajnoczi --- 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 834eef75fa..2ac7e74307 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 fe88fa6a9d..9a65384088 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)"