| Message ID | 20180123032135.28863-3-f4bug@amsat.org |
|---|---|
| State | New |
| Headers | show |
| Series | SDCard: housekeeping, add tracing (part 4) | expand |
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 > >
Hi Alistair, On 01/31/2018 01:12 PM, Alistair Francis wrote: > 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. This shouldn't happen since this function is local (static), but I'll add a check. > > Is this used in future? It seems like a lot of work for one caller. This resulted useful to me when tracing (in particular when using the MMC mode). Also note this code is only called when tracing is enabled. http://lists.nongnu.org/archive/html/qemu-devel/2017-12/msg02387.html > >> + 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? Probably leftover when rebasing, since trace_sdcard_normal_command() now displays the state, I was not sure the best way to trace hexdump before removing this debug code. > > 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 >> >>
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"; + } + 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); } 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"
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(-)