From mboxrd@z Thu Jan 1 00:00:00 1970 Received: from eggs.gnu.org ([2001:4830:134:3::10]:33343) by lists.gnu.org with esmtp (Exim 4.71) (envelope-from ) id 1esbcc-000252-I3 for qemu-devel@nongnu.org; Sun, 04 Mar 2018 16:56:48 -0500 Received: from Debian-exim by eggs.gnu.org with spam-scanned (Exim 4.71) (envelope-from ) id 1esbcY-0004mM-2l for qemu-devel@nongnu.org; Sun, 04 Mar 2018 16:56:46 -0500 Received: from mx0a-001b2d01.pphosted.com ([148.163.156.1]:60814) by eggs.gnu.org with esmtps (TLS1.0:RSA_AES_256_CBC_SHA1:32) (Exim 4.71) (envelope-from ) id 1esbcX-0004lw-QD for qemu-devel@nongnu.org; Sun, 04 Mar 2018 16:56:42 -0500 Received: from pps.filterd (m0098404.ppops.net [127.0.0.1]) by mx0a-001b2d01.pphosted.com (8.16.0.22/8.16.0.22) with SMTP id w24LsF4t051804 for ; Sun, 4 Mar 2018 16:56:40 -0500 Received: from e38.co.us.ibm.com (e38.co.us.ibm.com [32.97.110.159]) by mx0a-001b2d01.pphosted.com with ESMTP id 2gga4fw5da-1 (version=TLSv1.2 cipher=AES256-SHA256 bits=256 verify=NOT) for ; Sun, 04 Mar 2018 16:56:40 -0500 Received: from localhost by e38.co.us.ibm.com with IBM ESMTP SMTP Gateway: Authorized Use Only! Violators will be prosecuted for from ; Sun, 4 Mar 2018 14:56:39 -0700 From: Stefan Berger Date: Sun, 4 Mar 2018 16:56:27 -0500 In-Reply-To: <1520200587-14681-1-git-send-email-stefanb@linux.vnet.ibm.com> References: <1520200587-14681-1-git-send-email-stefanb@linux.vnet.ibm.com> Message-Id: <1520200587-14681-6-git-send-email-stefanb@linux.vnet.ibm.com> Subject: [Qemu-devel] [PATCH 5/5] tpm: convert tpm_tis.c to use trace-events List-Id: List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , To: qemu-devel@nongnu.org Cc: marcandre.lureau@redhat.com, dgilbert@redhat.com, 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 --- 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