Re: [Qemu-devel] [PATCH v3 02/12] sdcard: replace DPRINTF() by trace events

[Alistair Francis <alistair.francis@xilinx.com>]

On Mon, Jan 22, 2018 at 7:21 PM, Philippe Mathieu-Daudé <f4bug@amsat.org> wrote:
> Signed-off-by: Philippe Mathieu-Daudé <f4bug@amsat.org>
> ---
>  hw/sd/sd.c         | 33 ++++++++++++++++++++++++++-------
>  hw/sd/trace-events |  6 ++++++
>  2 files changed, 32 insertions(+), 7 deletions(-)
>
> diff --git a/hw/sd/sd.c b/hw/sd/sd.c
> index 55d2ba2dd7..f876973a2b 100644
> --- a/hw/sd/sd.c
> +++ b/hw/sd/sd.c
> @@ -40,6 +40,7 @@
>  #include "qemu/error-report.h"
>  #include "qemu/timer.h"
>  #include "qemu/log.h"
> +#include "trace.h"
>
>  //#define DEBUG_SD 1
>
> @@ -132,6 +133,25 @@ struct SDState {
>      bool cmd_line;
>  };
>
> +static const char *sd_state_name(enum SDCardStates state)
> +{
> +    static const char *state_name[] = {
> +        [sd_idle_state]             = "idle",
> +        [sd_ready_state]            = "ready",
> +        [sd_identification_state]   = "identification",
> +        [sd_standby_state]          = "standby",
> +        [sd_transfer_state]         = "transfer",
> +        [sd_sendingdata_state]      = "sendingdata",
> +        [sd_receivingdata_state]    = "receivingdata",
> +        [sd_programming_state]      = "programming",
> +        [sd_disconnect_state]       = "disconnect",
> +    };
> +    if (state == sd_inactive_state) {
> +        return "inactive";
> +    }

There should be an assert here to make sure we never go off the end of
this array.

Is this used in future? It seems like a lot of work for one caller.

> +    return state_name[state];
> +}
> +
>  static uint8_t sd_get_dat_lines(SDState *sd)
>  {
>      return sd->enable ? sd->dat_lines : 0;
> @@ -776,6 +796,8 @@ static sd_rsp_type_t sd_normal_command(SDState *sd,
>      uint32_t rca = 0x0000;
>      uint64_t addr = (sd->ocr & (1 << 30)) ? (uint64_t) req.arg << 9 : req.arg;
>
> +    trace_sdcard_normal_command(req.cmd, req.arg, sd_state_name(sd->state));
> +
>      /* Not interpreting this as an app command */
>      sd->card_status &= ~APP_CMD;
>
> @@ -790,7 +812,6 @@ static sd_rsp_type_t sd_normal_command(SDState *sd,
>          sd->multi_blk_cnt = 0;
>      }
>
> -    DPRINTF("CMD%d 0x%08x state %d\n", req.cmd, req.arg, sd->state);
>      switch (req.cmd) {
>      /* Basic commands (Class 0 and Class 1) */
>      case 0:    /* CMD0:   GO_IDLE_STATE */
> @@ -1310,8 +1331,6 @@ static sd_rsp_type_t sd_normal_command(SDState *sd,
>          return sd_r1;
>
>      case 56:   /* CMD56:  GEN_CMD */
> -        fprintf(stderr, "SD: GEN_CMD 0x%08x\n", req.arg);
> -
>          switch (sd->state) {
>          case sd_transfer_state:
>              sd->data_offset = 0;
> @@ -1345,7 +1364,7 @@ static sd_rsp_type_t sd_normal_command(SDState *sd,
>  static sd_rsp_type_t sd_app_command(SDState *sd,
>                                      SDRequest req)
>  {
> -    DPRINTF("ACMD%d 0x%08x\n", req.cmd, req.arg);
> +    trace_sdcard_app_command(req.cmd, req.arg);
>      sd->card_status |= APP_CMD;
>      switch (req.cmd) {
>      case 6:    /* ACMD6:  SET_BUS_WIDTH */
> @@ -1594,7 +1613,7 @@ send_response:
>          DPRINTF("Response:");
>          for (i = 0; i < rsplen; i++)
>              fprintf(stderr, " %02x", response[i]);
> -        fprintf(stderr, " state %d\n", sd->state);
> +        fputc('\n', stderr);

Why change this?

Alistair

>      } else {
>          DPRINTF("No response %d\n", sd->state);
>      }
> @@ -1605,8 +1624,7 @@ send_response:
>
>  static void sd_blk_read(SDState *sd, uint64_t addr, uint32_t len)
>  {
> -    DPRINTF("sd_blk_read: addr = 0x%08llx, len = %d\n",
> -            (unsigned long long) addr, len);
> +    trace_sdcard_read_block(addr, len);
>      if (!sd->blk || blk_pread(sd->blk, addr, sd->data, len) < 0) {
>          fprintf(stderr, "sd_blk_read: read error on host side\n");
>      }
> @@ -1614,6 +1632,7 @@ static void sd_blk_read(SDState *sd, uint64_t addr, uint32_t len)
>
>  static void sd_blk_write(SDState *sd, uint64_t addr, uint32_t len)
>  {
> +    trace_sdcard_write_block(addr, len);
>      if (!sd->blk || blk_pwrite(sd->blk, addr, sd->data, len, 0) < 0) {
>          fprintf(stderr, "sd_blk_write: write error on host side\n");
>      }
> diff --git a/hw/sd/trace-events b/hw/sd/trace-events
> index 0f8536db32..75dac5a2cd 100644
> --- a/hw/sd/trace-events
> +++ b/hw/sd/trace-events
> @@ -23,6 +23,12 @@ sdhci_read_dataport(uint16_t data_count) "all %u bytes of data have been read fr
>  sdhci_write_dataport(uint16_t data_count) "write buffer filled with %u bytes of data"
>  sdhci_capareg(const char *desc, uint16_t val) "%s: %u"
>
> +# hw/sd/sd.c
> +sdcard_normal_command(uint8_t cmd, uint32_t arg, const char *state) "CMD%d arg 0x%08x (state %s)"
> +sdcard_app_command(uint8_t acmd, uint32_t arg) "ACMD%d arg 0x%08x"
> +sdcard_read_block(uint64_t addr, uint32_t len) "addr 0x%" PRIx64 " size 0x%x"
> +sdcard_write_block(uint64_t addr, uint32_t len) "addr 0x%" PRIx64 " size 0x%x"
> +
>  # hw/sd/milkymist-memcard.c
>  milkymist_memcard_memory_read(uint32_t addr, uint32_t value) "addr 0x%08x value 0x%08x"
>  milkymist_memcard_memory_write(uint32_t addr, uint32_t value) "addr 0x%08x value 0x%08x"
> --
> 2.15.1
>
>