| Message ID | 20200203180904.2727-1-linux@roeck-us.net |
|---|---|
| State | New |
| Headers | show |
| Series | [1/3] m25p80: Convert to support tracing | expand |
On Mon, Feb 3, 2020 at 10:10 AM Guenter Roeck <linux@roeck-us.net> wrote: > > While at it, add some trace messages to help debug problems > seen when running the latest Linux kernel. > > Signed-off-by: Guenter Roeck <linux@roeck-us.net> Reviewed-by: Alistair Francis <alistair.francis@wdc.com> Alistair > --- > hw/block/m25p80.c | 48 ++++++++++++++++++++----------------------- > hw/block/trace-events | 16 +++++++++++++++ > 2 files changed, 38 insertions(+), 26 deletions(-) > > diff --git a/hw/block/m25p80.c b/hw/block/m25p80.c > index 11ff5b9ad7..63e050d7d3 100644 > --- a/hw/block/m25p80.c > +++ b/hw/block/m25p80.c > @@ -32,17 +32,7 @@ > #include "qemu/module.h" > #include "qemu/error-report.h" > #include "qapi/error.h" > - > -#ifndef M25P80_ERR_DEBUG > -#define M25P80_ERR_DEBUG 0 > -#endif > - > -#define DB_PRINT_L(level, ...) do { \ > - if (M25P80_ERR_DEBUG > (level)) { \ > - fprintf(stderr, ": %s: ", __func__); \ > - fprintf(stderr, ## __VA_ARGS__); \ > - } \ > -} while (0) > +#include "trace.h" > > /* Fields for FlashPartInfo->flags */ > > @@ -574,7 +564,8 @@ static void flash_erase(Flash *s, int offset, FlashCMD cmd) > abort(); > } > > - DB_PRINT_L(0, "offset = %#x, len = %d\n", offset, len); > + trace_m25p80_flash_erase(offset, len); > + > if ((s->pi->flags & capa_to_assert) != capa_to_assert) { > qemu_log_mask(LOG_GUEST_ERROR, "M25P80: %d erase size not supported by" > " device\n", len); > @@ -607,8 +598,7 @@ void flash_write8(Flash *s, uint32_t addr, uint8_t data) > } > > if ((prev ^ data) & data) { > - DB_PRINT_L(1, "programming zero to one! addr=%" PRIx32 " %" PRIx8 > - " -> %" PRIx8 "\n", addr, prev, data); > + trace_m25p80_programming_zero_to_one(addr, prev, data); > } > > if (s->pi->flags & EEPROM) { > @@ -662,6 +652,9 @@ static void complete_collecting_data(Flash *s) > > s->state = STATE_IDLE; > > + trace_m25p80_complete_collecting(s->cmd_in_progress, n, s->ear, > + s->cur_addr); > + > switch (s->cmd_in_progress) { > case DPP: > case QPP: > @@ -825,7 +818,7 @@ static void reset_memory(Flash *s) > break; > } > > - DB_PRINT_L(0, "Reset done.\n"); > + trace_m25p80_reset_done(); > } > > static void decode_fast_read_cmd(Flash *s) > @@ -941,9 +934,10 @@ static void decode_qio_read_cmd(Flash *s) > > static void decode_new_cmd(Flash *s, uint32_t value) > { > - s->cmd_in_progress = value; > int i; > - DB_PRINT_L(0, "decoded new command:%x\n", value); > + > + s->cmd_in_progress = value; > + trace_m25p80_command_decoded(value); > > if (value != RESET_MEMORY) { > s->reset_enable = false; > @@ -1042,7 +1036,7 @@ static void decode_new_cmd(Flash *s, uint32_t value) > break; > > case JEDEC_READ: > - DB_PRINT_L(0, "populated jedec code\n"); > + trace_m25p80_populated_jedec(); > for (i = 0; i < s->pi->id_len; i++) { > s->data[i] = s->pi->id[i]; > } > @@ -1063,7 +1057,7 @@ static void decode_new_cmd(Flash *s, uint32_t value) > case BULK_ERASE_60: > case BULK_ERASE: > if (s->write_enable) { > - DB_PRINT_L(0, "chip erase\n"); > + trace_m25p80_chip_erase(); > flash_erase(s, 0, BULK_ERASE); > } else { > qemu_log_mask(LOG_GUEST_ERROR, "M25P80: chip erase with write " > @@ -1184,7 +1178,7 @@ static int m25p80_cs(SSISlave *ss, bool select) > s->data_read_loop = false; > } > > - DB_PRINT_L(0, "%sselect\n", select ? "de" : ""); > + trace_m25p80_select(select ? "de" : ""); > > return 0; > } > @@ -1194,19 +1188,20 @@ static uint32_t m25p80_transfer8(SSISlave *ss, uint32_t tx) > Flash *s = M25P80(ss); > uint32_t r = 0; > > + trace_m25p80_transfer(s->state, s->len, s->needed_bytes, s->pos, > + s->cur_addr, (uint8_t)tx); > + > switch (s->state) { > > case STATE_PAGE_PROGRAM: > - DB_PRINT_L(1, "page program cur_addr=%#" PRIx32 " data=%" PRIx8 "\n", > - s->cur_addr, (uint8_t)tx); > + trace_m25p80_page_program(s->cur_addr, (uint8_t)tx); > flash_write8(s, s->cur_addr, (uint8_t)tx); > s->cur_addr = (s->cur_addr + 1) & (s->size - 1); > break; > > case STATE_READ: > r = s->storage[s->cur_addr]; > - DB_PRINT_L(1, "READ 0x%" PRIx32 "=%" PRIx8 "\n", s->cur_addr, > - (uint8_t)r); > + trace_m25p80_read_byte(s->cur_addr, (uint8_t)r); > s->cur_addr = (s->cur_addr + 1) & (s->size - 1); > break; > > @@ -1244,6 +1239,7 @@ static uint32_t m25p80_transfer8(SSISlave *ss, uint32_t tx) > } > > r = s->data[s->pos]; > + trace_m25p80_read_data(s->pos, (uint8_t)r); > s->pos++; > if (s->pos == s->len) { > s->pos = 0; > @@ -1281,7 +1277,7 @@ static void m25p80_realize(SSISlave *ss, Error **errp) > return; > } > > - DB_PRINT_L(0, "Binding to IF_MTD drive\n"); > + trace_m25p80_binding(); > s->storage = blk_blockalign(s->blk, s->size); > > if (blk_pread(s->blk, 0, s->storage, s->size) != s->size) { > @@ -1289,7 +1285,7 @@ static void m25p80_realize(SSISlave *ss, Error **errp) > return; > } > } else { > - DB_PRINT_L(0, "No BDRV - binding to RAM\n"); > + trace_m25p80_binding_no_bdrv(); > s->storage = blk_blockalign(NULL, s->size); > memset(s->storage, 0xFF, s->size); > } > diff --git a/hw/block/trace-events b/hw/block/trace-events > index c03e80c2c9..d052f7578c 100644 > --- a/hw/block/trace-events > +++ b/hw/block/trace-events > @@ -134,3 +134,19 @@ xen_block_blockdev_add(char *str) "%s" > xen_block_blockdev_del(const char *node_name) "%s" > xen_block_device_create(unsigned int number) "%u" > xen_block_device_destroy(unsigned int number) "%u" > + > +# m25p80.c > +m25p80_flash_erase(int offset, uint32_t len) "offset = 0x%"PRIx32", len = %u" > +m25p80_programming_zero_to_one(uint32_t addr, uint8_t prev, uint8_t data) "programming zero to one! addr=0x%"PRIx32" 0x%"PRIx8" -> 0x%"PRIx8 > +m25p80_reset_done(void) "Reset done." > +m25p80_command_decoded(uint32_t cmd) "new command:0x%"PRIx32 > +m25p80_complete_collecting(uint32_t cmd, int n, uint8_t ear, uint32_t cur_addr) "decode cmd: 0x%"PRIx32" len %d ear 0x%"PRIx8" addr 0x%"PRIx32 > +m25p80_populated_jedec(void) "populated jedec code" > +m25p80_chip_erase(void) "chip erase" > +m25p80_select(const char *what) "%sselect" > +m25p80_page_program(uint32_t addr, uint8_t tx) "page program cur_addr=0x%"PRIx32" data=0x%"PRIx8 > +m25p80_transfer(uint8_t state, uint32_t len, uint8_t needed, uint32_t pos, uint32_t cur_addr, uint8_t t) "Transfer state 0x%"PRIx8" len 0x%"PRIx32" needed 0x%"PRIx8" pos 0x%"PRIx32" addr 0x%"PRIx32" tx 0x%"PRIx8 > +m25p80_read_byte(uint32_t addr, uint8_t v) "Read byte 0x%"PRIx32"=0x%"PRIx8 > +m25p80_read_data(uint32_t pos, uint8_t v) "Read data 0x%"PRIx32"=0x%"PRIx8 > +m25p80_binding(void) "Binding to IF_MTD drive" > +m25p80_binding_no_bdrv(void) "No BDRV - binding to RAM" > -- > 2.17.1 > >
On 2/3/20 7:09 PM, Guenter Roeck wrote: > While at it, add some trace messages to help debug problems > seen when running the latest Linux kernel. > > Signed-off-by: Guenter Roeck <linux@roeck-us.net> Reviewed-by: Cédric Le Goater <clg@kaod.org> We have been chasing a bug for years on the witherspoon-bmc machine using UBIfs. It will be useful. What kind of issue are you looking at ? Thanks, C. > --- > hw/block/m25p80.c | 48 ++++++++++++++++++++----------------------- > hw/block/trace-events | 16 +++++++++++++++ > 2 files changed, 38 insertions(+), 26 deletions(-) > > diff --git a/hw/block/m25p80.c b/hw/block/m25p80.c > index 11ff5b9ad7..63e050d7d3 100644 > --- a/hw/block/m25p80.c > +++ b/hw/block/m25p80.c > @@ -32,17 +32,7 @@ > #include "qemu/module.h" > #include "qemu/error-report.h" > #include "qapi/error.h" > - > -#ifndef M25P80_ERR_DEBUG > -#define M25P80_ERR_DEBUG 0 > -#endif > - > -#define DB_PRINT_L(level, ...) do { \ > - if (M25P80_ERR_DEBUG > (level)) { \ > - fprintf(stderr, ": %s: ", __func__); \ > - fprintf(stderr, ## __VA_ARGS__); \ > - } \ > -} while (0) > +#include "trace.h" > > /* Fields for FlashPartInfo->flags */ > > @@ -574,7 +564,8 @@ static void flash_erase(Flash *s, int offset, FlashCMD cmd) > abort(); > } > > - DB_PRINT_L(0, "offset = %#x, len = %d\n", offset, len); > + trace_m25p80_flash_erase(offset, len); > + > if ((s->pi->flags & capa_to_assert) != capa_to_assert) { > qemu_log_mask(LOG_GUEST_ERROR, "M25P80: %d erase size not supported by" > " device\n", len); > @@ -607,8 +598,7 @@ void flash_write8(Flash *s, uint32_t addr, uint8_t data) > } > > if ((prev ^ data) & data) { > - DB_PRINT_L(1, "programming zero to one! addr=%" PRIx32 " %" PRIx8 > - " -> %" PRIx8 "\n", addr, prev, data); > + trace_m25p80_programming_zero_to_one(addr, prev, data); > } > > if (s->pi->flags & EEPROM) { > @@ -662,6 +652,9 @@ static void complete_collecting_data(Flash *s) > > s->state = STATE_IDLE; > > + trace_m25p80_complete_collecting(s->cmd_in_progress, n, s->ear, > + s->cur_addr); > + > switch (s->cmd_in_progress) { > case DPP: > case QPP: > @@ -825,7 +818,7 @@ static void reset_memory(Flash *s) > break; > } > > - DB_PRINT_L(0, "Reset done.\n"); > + trace_m25p80_reset_done(); > } > > static void decode_fast_read_cmd(Flash *s) > @@ -941,9 +934,10 @@ static void decode_qio_read_cmd(Flash *s) > > static void decode_new_cmd(Flash *s, uint32_t value) > { > - s->cmd_in_progress = value; > int i; > - DB_PRINT_L(0, "decoded new command:%x\n", value); > + > + s->cmd_in_progress = value; > + trace_m25p80_command_decoded(value); > > if (value != RESET_MEMORY) { > s->reset_enable = false; > @@ -1042,7 +1036,7 @@ static void decode_new_cmd(Flash *s, uint32_t value) > break; > > case JEDEC_READ: > - DB_PRINT_L(0, "populated jedec code\n"); > + trace_m25p80_populated_jedec(); > for (i = 0; i < s->pi->id_len; i++) { > s->data[i] = s->pi->id[i]; > } > @@ -1063,7 +1057,7 @@ static void decode_new_cmd(Flash *s, uint32_t value) > case BULK_ERASE_60: > case BULK_ERASE: > if (s->write_enable) { > - DB_PRINT_L(0, "chip erase\n"); > + trace_m25p80_chip_erase(); > flash_erase(s, 0, BULK_ERASE); > } else { > qemu_log_mask(LOG_GUEST_ERROR, "M25P80: chip erase with write " > @@ -1184,7 +1178,7 @@ static int m25p80_cs(SSISlave *ss, bool select) > s->data_read_loop = false; > } > > - DB_PRINT_L(0, "%sselect\n", select ? "de" : ""); > + trace_m25p80_select(select ? "de" : ""); > > return 0; > } > @@ -1194,19 +1188,20 @@ static uint32_t m25p80_transfer8(SSISlave *ss, uint32_t tx) > Flash *s = M25P80(ss); > uint32_t r = 0; > > + trace_m25p80_transfer(s->state, s->len, s->needed_bytes, s->pos, > + s->cur_addr, (uint8_t)tx); > + > switch (s->state) { > > case STATE_PAGE_PROGRAM: > - DB_PRINT_L(1, "page program cur_addr=%#" PRIx32 " data=%" PRIx8 "\n", > - s->cur_addr, (uint8_t)tx); > + trace_m25p80_page_program(s->cur_addr, (uint8_t)tx); > flash_write8(s, s->cur_addr, (uint8_t)tx); > s->cur_addr = (s->cur_addr + 1) & (s->size - 1); > break; > > case STATE_READ: > r = s->storage[s->cur_addr]; > - DB_PRINT_L(1, "READ 0x%" PRIx32 "=%" PRIx8 "\n", s->cur_addr, > - (uint8_t)r); > + trace_m25p80_read_byte(s->cur_addr, (uint8_t)r); > s->cur_addr = (s->cur_addr + 1) & (s->size - 1); > break; > > @@ -1244,6 +1239,7 @@ static uint32_t m25p80_transfer8(SSISlave *ss, uint32_t tx) > } > > r = s->data[s->pos]; > + trace_m25p80_read_data(s->pos, (uint8_t)r); > s->pos++; > if (s->pos == s->len) { > s->pos = 0; > @@ -1281,7 +1277,7 @@ static void m25p80_realize(SSISlave *ss, Error **errp) > return; > } > > - DB_PRINT_L(0, "Binding to IF_MTD drive\n"); > + trace_m25p80_binding(); > s->storage = blk_blockalign(s->blk, s->size); > > if (blk_pread(s->blk, 0, s->storage, s->size) != s->size) { > @@ -1289,7 +1285,7 @@ static void m25p80_realize(SSISlave *ss, Error **errp) > return; > } > } else { > - DB_PRINT_L(0, "No BDRV - binding to RAM\n"); > + trace_m25p80_binding_no_bdrv(); > s->storage = blk_blockalign(NULL, s->size); > memset(s->storage, 0xFF, s->size); > } > diff --git a/hw/block/trace-events b/hw/block/trace-events > index c03e80c2c9..d052f7578c 100644 > --- a/hw/block/trace-events > +++ b/hw/block/trace-events > @@ -134,3 +134,19 @@ xen_block_blockdev_add(char *str) "%s" > xen_block_blockdev_del(const char *node_name) "%s" > xen_block_device_create(unsigned int number) "%u" > xen_block_device_destroy(unsigned int number) "%u" > + > +# m25p80.c > +m25p80_flash_erase(int offset, uint32_t len) "offset = 0x%"PRIx32", len = %u" > +m25p80_programming_zero_to_one(uint32_t addr, uint8_t prev, uint8_t data) "programming zero to one! addr=0x%"PRIx32" 0x%"PRIx8" -> 0x%"PRIx8 > +m25p80_reset_done(void) "Reset done." > +m25p80_command_decoded(uint32_t cmd) "new command:0x%"PRIx32 > +m25p80_complete_collecting(uint32_t cmd, int n, uint8_t ear, uint32_t cur_addr) "decode cmd: 0x%"PRIx32" len %d ear 0x%"PRIx8" addr 0x%"PRIx32 > +m25p80_populated_jedec(void) "populated jedec code" > +m25p80_chip_erase(void) "chip erase" > +m25p80_select(const char *what) "%sselect" > +m25p80_page_program(uint32_t addr, uint8_t tx) "page program cur_addr=0x%"PRIx32" data=0x%"PRIx8 > +m25p80_transfer(uint8_t state, uint32_t len, uint8_t needed, uint32_t pos, uint32_t cur_addr, uint8_t t) "Transfer state 0x%"PRIx8" len 0x%"PRIx32" needed 0x%"PRIx8" pos 0x%"PRIx32" addr 0x%"PRIx32" tx 0x%"PRIx8 > +m25p80_read_byte(uint32_t addr, uint8_t v) "Read byte 0x%"PRIx32"=0x%"PRIx8 > +m25p80_read_data(uint32_t pos, uint8_t v) "Read data 0x%"PRIx32"=0x%"PRIx8 > +m25p80_binding(void) "Binding to IF_MTD drive" > +m25p80_binding_no_bdrv(void) "No BDRV - binding to RAM" >
On 2/3/20 7:09 PM, Guenter Roeck wrote: > While at it, add some trace messages to help debug problems > seen when running the latest Linux kernel. > > Signed-off-by: Guenter Roeck <linux@roeck-us.net> > --- > hw/block/m25p80.c | 48 ++++++++++++++++++++----------------------- > hw/block/trace-events | 16 +++++++++++++++ > 2 files changed, 38 insertions(+), 26 deletions(-) > > diff --git a/hw/block/m25p80.c b/hw/block/m25p80.c > index 11ff5b9ad7..63e050d7d3 100644 > --- a/hw/block/m25p80.c > +++ b/hw/block/m25p80.c > @@ -32,17 +32,7 @@ > #include "qemu/module.h" > #include "qemu/error-report.h" > #include "qapi/error.h" > - > -#ifndef M25P80_ERR_DEBUG > -#define M25P80_ERR_DEBUG 0 > -#endif > - > -#define DB_PRINT_L(level, ...) do { \ > - if (M25P80_ERR_DEBUG > (level)) { \ > - fprintf(stderr, ": %s: ", __func__); \ > - fprintf(stderr, ## __VA_ARGS__); \ > - } \ > -} while (0) > +#include "trace.h" > > /* Fields for FlashPartInfo->flags */ > > @@ -574,7 +564,8 @@ static void flash_erase(Flash *s, int offset, FlashCMD cmd) > abort(); > } > > - DB_PRINT_L(0, "offset = %#x, len = %d\n", offset, len); > + trace_m25p80_flash_erase(offset, len); > + > if ((s->pi->flags & capa_to_assert) != capa_to_assert) { > qemu_log_mask(LOG_GUEST_ERROR, "M25P80: %d erase size not supported by" > " device\n", len); > @@ -607,8 +598,7 @@ void flash_write8(Flash *s, uint32_t addr, uint8_t data) > } > > if ((prev ^ data) & data) { > - DB_PRINT_L(1, "programming zero to one! addr=%" PRIx32 " %" PRIx8 > - " -> %" PRIx8 "\n", addr, prev, data); > + trace_m25p80_programming_zero_to_one(addr, prev, data); > } > > if (s->pi->flags & EEPROM) { > @@ -662,6 +652,9 @@ static void complete_collecting_data(Flash *s) > > s->state = STATE_IDLE; > > + trace_m25p80_complete_collecting(s->cmd_in_progress, n, s->ear, > + s->cur_addr); > + > switch (s->cmd_in_progress) { > case DPP: > case QPP: > @@ -825,7 +818,7 @@ static void reset_memory(Flash *s) > break; > } > > - DB_PRINT_L(0, "Reset done.\n"); > + trace_m25p80_reset_done(); > } > > static void decode_fast_read_cmd(Flash *s) > @@ -941,9 +934,10 @@ static void decode_qio_read_cmd(Flash *s) > > static void decode_new_cmd(Flash *s, uint32_t value) > { > - s->cmd_in_progress = value; > int i; > - DB_PRINT_L(0, "decoded new command:%x\n", value); > + > + s->cmd_in_progress = value; > + trace_m25p80_command_decoded(value); > > if (value != RESET_MEMORY) { > s->reset_enable = false; > @@ -1042,7 +1036,7 @@ static void decode_new_cmd(Flash *s, uint32_t value) > break; > > case JEDEC_READ: > - DB_PRINT_L(0, "populated jedec code\n"); > + trace_m25p80_populated_jedec(); > for (i = 0; i < s->pi->id_len; i++) { > s->data[i] = s->pi->id[i]; > } > @@ -1063,7 +1057,7 @@ static void decode_new_cmd(Flash *s, uint32_t value) > case BULK_ERASE_60: > case BULK_ERASE: > if (s->write_enable) { > - DB_PRINT_L(0, "chip erase\n"); > + trace_m25p80_chip_erase(); > flash_erase(s, 0, BULK_ERASE); > } else { > qemu_log_mask(LOG_GUEST_ERROR, "M25P80: chip erase with write " > @@ -1184,7 +1178,7 @@ static int m25p80_cs(SSISlave *ss, bool select) > s->data_read_loop = false; > } > > - DB_PRINT_L(0, "%sselect\n", select ? "de" : ""); > + trace_m25p80_select(select ? "de" : ""); > > return 0; > } > @@ -1194,19 +1188,20 @@ static uint32_t m25p80_transfer8(SSISlave *ss, uint32_t tx) > Flash *s = M25P80(ss); > uint32_t r = 0; > > + trace_m25p80_transfer(s->state, s->len, s->needed_bytes, s->pos, > + s->cur_addr, (uint8_t)tx); > + > switch (s->state) { > > case STATE_PAGE_PROGRAM: > - DB_PRINT_L(1, "page program cur_addr=%#" PRIx32 " data=%" PRIx8 "\n", > - s->cur_addr, (uint8_t)tx); > + trace_m25p80_page_program(s->cur_addr, (uint8_t)tx); > flash_write8(s, s->cur_addr, (uint8_t)tx); > s->cur_addr = (s->cur_addr + 1) & (s->size - 1); > break; > > case STATE_READ: > r = s->storage[s->cur_addr]; > - DB_PRINT_L(1, "READ 0x%" PRIx32 "=%" PRIx8 "\n", s->cur_addr, > - (uint8_t)r); > + trace_m25p80_read_byte(s->cur_addr, (uint8_t)r); > s->cur_addr = (s->cur_addr + 1) & (s->size - 1); > break; > > @@ -1244,6 +1239,7 @@ static uint32_t m25p80_transfer8(SSISlave *ss, uint32_t tx) > } > > r = s->data[s->pos]; > + trace_m25p80_read_data(s->pos, (uint8_t)r); > s->pos++; > if (s->pos == s->len) { > s->pos = 0; > @@ -1281,7 +1277,7 @@ static void m25p80_realize(SSISlave *ss, Error **errp) > return; > } > > - DB_PRINT_L(0, "Binding to IF_MTD drive\n"); > + trace_m25p80_binding(); > s->storage = blk_blockalign(s->blk, s->size); > > if (blk_pread(s->blk, 0, s->storage, s->size) != s->size) { > @@ -1289,7 +1285,7 @@ static void m25p80_realize(SSISlave *ss, Error **errp) > return; > } > } else { > - DB_PRINT_L(0, "No BDRV - binding to RAM\n"); > + trace_m25p80_binding_no_bdrv(); > s->storage = blk_blockalign(NULL, s->size); > memset(s->storage, 0xFF, s->size); > } > diff --git a/hw/block/trace-events b/hw/block/trace-events > index c03e80c2c9..d052f7578c 100644 > --- a/hw/block/trace-events > +++ b/hw/block/trace-events > @@ -134,3 +134,19 @@ xen_block_blockdev_add(char *str) "%s" > xen_block_blockdev_del(const char *node_name) "%s" > xen_block_device_create(unsigned int number) "%u" > xen_block_device_destroy(unsigned int number) "%u" > + > +# m25p80.c > +m25p80_flash_erase(int offset, uint32_t len) "offset = 0x%"PRIx32", len = %u" > +m25p80_programming_zero_to_one(uint32_t addr, uint8_t prev, uint8_t data) "programming zero to one! addr=0x%"PRIx32" 0x%"PRIx8" -> 0x%"PRIx8 > +m25p80_reset_done(void) "Reset done." > +m25p80_command_decoded(uint32_t cmd) "new command:0x%"PRIx32 > +m25p80_complete_collecting(uint32_t cmd, int n, uint8_t ear, uint32_t cur_addr) "decode cmd: 0x%"PRIx32" len %d ear 0x%"PRIx8" addr 0x%"PRIx32 > +m25p80_populated_jedec(void) "populated jedec code" > +m25p80_chip_erase(void) "chip erase" > +m25p80_select(const char *what) "%sselect" > +m25p80_page_program(uint32_t addr, uint8_t tx) "page program cur_addr=0x%"PRIx32" data=0x%"PRIx8 > +m25p80_transfer(uint8_t state, uint32_t len, uint8_t needed, uint32_t pos, uint32_t cur_addr, uint8_t t) "Transfer state 0x%"PRIx8" len 0x%"PRIx32" needed 0x%"PRIx8" pos 0x%"PRIx32" addr 0x%"PRIx32" tx 0x%"PRIx8 > +m25p80_read_byte(uint32_t addr, uint8_t v) "Read byte 0x%"PRIx32"=0x%"PRIx8 > +m25p80_read_data(uint32_t pos, uint8_t v) "Read data 0x%"PRIx32"=0x%"PRIx8 > +m25p80_binding(void) "Binding to IF_MTD drive" > +m25p80_binding_no_bdrv(void) "No BDRV - binding to RAM" > Reviewed-by: Philippe Mathieu-Daudé <philmd@redhat.com>
On 2/3/20 11:16 PM, Cédric Le Goater wrote: > On 2/3/20 7:09 PM, Guenter Roeck wrote: >> While at it, add some trace messages to help debug problems >> seen when running the latest Linux kernel. >> >> Signed-off-by: Guenter Roeck <linux@roeck-us.net> > > > Reviewed-by: Cédric Le Goater <clg@kaod.org> > > We have been chasing a bug for years on the witherspoon-bmc machine > using UBIfs. It will be useful. > > What kind of issue are you looking at ? > aspeed-ast2500-evb no longer boots from flash with the current mainline kernel. The problem is fixed with the 3rd patch of the series. Guenter > Thanks, > > C. > >> --- >> hw/block/m25p80.c | 48 ++++++++++++++++++++----------------------- >> hw/block/trace-events | 16 +++++++++++++++ >> 2 files changed, 38 insertions(+), 26 deletions(-) >> >> diff --git a/hw/block/m25p80.c b/hw/block/m25p80.c >> index 11ff5b9ad7..63e050d7d3 100644 >> --- a/hw/block/m25p80.c >> +++ b/hw/block/m25p80.c >> @@ -32,17 +32,7 @@ >> #include "qemu/module.h" >> #include "qemu/error-report.h" >> #include "qapi/error.h" >> - >> -#ifndef M25P80_ERR_DEBUG >> -#define M25P80_ERR_DEBUG 0 >> -#endif >> - >> -#define DB_PRINT_L(level, ...) do { \ >> - if (M25P80_ERR_DEBUG > (level)) { \ >> - fprintf(stderr, ": %s: ", __func__); \ >> - fprintf(stderr, ## __VA_ARGS__); \ >> - } \ >> -} while (0) >> +#include "trace.h" >> >> /* Fields for FlashPartInfo->flags */ >> >> @@ -574,7 +564,8 @@ static void flash_erase(Flash *s, int offset, FlashCMD cmd) >> abort(); >> } >> >> - DB_PRINT_L(0, "offset = %#x, len = %d\n", offset, len); >> + trace_m25p80_flash_erase(offset, len); >> + >> if ((s->pi->flags & capa_to_assert) != capa_to_assert) { >> qemu_log_mask(LOG_GUEST_ERROR, "M25P80: %d erase size not supported by" >> " device\n", len); >> @@ -607,8 +598,7 @@ void flash_write8(Flash *s, uint32_t addr, uint8_t data) >> } >> >> if ((prev ^ data) & data) { >> - DB_PRINT_L(1, "programming zero to one! addr=%" PRIx32 " %" PRIx8 >> - " -> %" PRIx8 "\n", addr, prev, data); >> + trace_m25p80_programming_zero_to_one(addr, prev, data); >> } >> >> if (s->pi->flags & EEPROM) { >> @@ -662,6 +652,9 @@ static void complete_collecting_data(Flash *s) >> >> s->state = STATE_IDLE; >> >> + trace_m25p80_complete_collecting(s->cmd_in_progress, n, s->ear, >> + s->cur_addr); >> + >> switch (s->cmd_in_progress) { >> case DPP: >> case QPP: >> @@ -825,7 +818,7 @@ static void reset_memory(Flash *s) >> break; >> } >> >> - DB_PRINT_L(0, "Reset done.\n"); >> + trace_m25p80_reset_done(); >> } >> >> static void decode_fast_read_cmd(Flash *s) >> @@ -941,9 +934,10 @@ static void decode_qio_read_cmd(Flash *s) >> >> static void decode_new_cmd(Flash *s, uint32_t value) >> { >> - s->cmd_in_progress = value; >> int i; >> - DB_PRINT_L(0, "decoded new command:%x\n", value); >> + >> + s->cmd_in_progress = value; >> + trace_m25p80_command_decoded(value); >> >> if (value != RESET_MEMORY) { >> s->reset_enable = false; >> @@ -1042,7 +1036,7 @@ static void decode_new_cmd(Flash *s, uint32_t value) >> break; >> >> case JEDEC_READ: >> - DB_PRINT_L(0, "populated jedec code\n"); >> + trace_m25p80_populated_jedec(); >> for (i = 0; i < s->pi->id_len; i++) { >> s->data[i] = s->pi->id[i]; >> } >> @@ -1063,7 +1057,7 @@ static void decode_new_cmd(Flash *s, uint32_t value) >> case BULK_ERASE_60: >> case BULK_ERASE: >> if (s->write_enable) { >> - DB_PRINT_L(0, "chip erase\n"); >> + trace_m25p80_chip_erase(); >> flash_erase(s, 0, BULK_ERASE); >> } else { >> qemu_log_mask(LOG_GUEST_ERROR, "M25P80: chip erase with write " >> @@ -1184,7 +1178,7 @@ static int m25p80_cs(SSISlave *ss, bool select) >> s->data_read_loop = false; >> } >> >> - DB_PRINT_L(0, "%sselect\n", select ? "de" : ""); >> + trace_m25p80_select(select ? "de" : ""); >> >> return 0; >> } >> @@ -1194,19 +1188,20 @@ static uint32_t m25p80_transfer8(SSISlave *ss, uint32_t tx) >> Flash *s = M25P80(ss); >> uint32_t r = 0; >> >> + trace_m25p80_transfer(s->state, s->len, s->needed_bytes, s->pos, >> + s->cur_addr, (uint8_t)tx); >> + >> switch (s->state) { >> >> case STATE_PAGE_PROGRAM: >> - DB_PRINT_L(1, "page program cur_addr=%#" PRIx32 " data=%" PRIx8 "\n", >> - s->cur_addr, (uint8_t)tx); >> + trace_m25p80_page_program(s->cur_addr, (uint8_t)tx); >> flash_write8(s, s->cur_addr, (uint8_t)tx); >> s->cur_addr = (s->cur_addr + 1) & (s->size - 1); >> break; >> >> case STATE_READ: >> r = s->storage[s->cur_addr]; >> - DB_PRINT_L(1, "READ 0x%" PRIx32 "=%" PRIx8 "\n", s->cur_addr, >> - (uint8_t)r); >> + trace_m25p80_read_byte(s->cur_addr, (uint8_t)r); >> s->cur_addr = (s->cur_addr + 1) & (s->size - 1); >> break; >> >> @@ -1244,6 +1239,7 @@ static uint32_t m25p80_transfer8(SSISlave *ss, uint32_t tx) >> } >> >> r = s->data[s->pos]; >> + trace_m25p80_read_data(s->pos, (uint8_t)r); >> s->pos++; >> if (s->pos == s->len) { >> s->pos = 0; >> @@ -1281,7 +1277,7 @@ static void m25p80_realize(SSISlave *ss, Error **errp) >> return; >> } >> >> - DB_PRINT_L(0, "Binding to IF_MTD drive\n"); >> + trace_m25p80_binding(); >> s->storage = blk_blockalign(s->blk, s->size); >> >> if (blk_pread(s->blk, 0, s->storage, s->size) != s->size) { >> @@ -1289,7 +1285,7 @@ static void m25p80_realize(SSISlave *ss, Error **errp) >> return; >> } >> } else { >> - DB_PRINT_L(0, "No BDRV - binding to RAM\n"); >> + trace_m25p80_binding_no_bdrv(); >> s->storage = blk_blockalign(NULL, s->size); >> memset(s->storage, 0xFF, s->size); >> } >> diff --git a/hw/block/trace-events b/hw/block/trace-events >> index c03e80c2c9..d052f7578c 100644 >> --- a/hw/block/trace-events >> +++ b/hw/block/trace-events >> @@ -134,3 +134,19 @@ xen_block_blockdev_add(char *str) "%s" >> xen_block_blockdev_del(const char *node_name) "%s" >> xen_block_device_create(unsigned int number) "%u" >> xen_block_device_destroy(unsigned int number) "%u" >> + >> +# m25p80.c >> +m25p80_flash_erase(int offset, uint32_t len) "offset = 0x%"PRIx32", len = %u" >> +m25p80_programming_zero_to_one(uint32_t addr, uint8_t prev, uint8_t data) "programming zero to one! addr=0x%"PRIx32" 0x%"PRIx8" -> 0x%"PRIx8 >> +m25p80_reset_done(void) "Reset done." >> +m25p80_command_decoded(uint32_t cmd) "new command:0x%"PRIx32 >> +m25p80_complete_collecting(uint32_t cmd, int n, uint8_t ear, uint32_t cur_addr) "decode cmd: 0x%"PRIx32" len %d ear 0x%"PRIx8" addr 0x%"PRIx32 >> +m25p80_populated_jedec(void) "populated jedec code" >> +m25p80_chip_erase(void) "chip erase" >> +m25p80_select(const char *what) "%sselect" >> +m25p80_page_program(uint32_t addr, uint8_t tx) "page program cur_addr=0x%"PRIx32" data=0x%"PRIx8 >> +m25p80_transfer(uint8_t state, uint32_t len, uint8_t needed, uint32_t pos, uint32_t cur_addr, uint8_t t) "Transfer state 0x%"PRIx8" len 0x%"PRIx32" needed 0x%"PRIx8" pos 0x%"PRIx32" addr 0x%"PRIx32" tx 0x%"PRIx8 >> +m25p80_read_byte(uint32_t addr, uint8_t v) "Read byte 0x%"PRIx32"=0x%"PRIx8 >> +m25p80_read_data(uint32_t pos, uint8_t v) "Read data 0x%"PRIx32"=0x%"PRIx8 >> +m25p80_binding(void) "Binding to IF_MTD drive" >> +m25p80_binding_no_bdrv(void) "No BDRV - binding to RAM" >> >
On 2/3/20 7:09 PM, Guenter Roeck wrote: > While at it, add some trace messages to help debug problems > seen when running the latest Linux kernel. In case you resend, It would be nice to printout a flash id in the tracing else I have a patch for it on top of yours. It helped me track a squashfs corruption on the Aspeed witherspoon-bmc machine which we were after since 2017 or so. It seems to be a kernel bug. Thanks, C. > Signed-off-by: Guenter Roeck <linux@roeck-us.net> > --- > hw/block/m25p80.c | 48 ++++++++++++++++++++----------------------- > hw/block/trace-events | 16 +++++++++++++++ > 2 files changed, 38 insertions(+), 26 deletions(-) > > diff --git a/hw/block/m25p80.c b/hw/block/m25p80.c > index 11ff5b9ad7..63e050d7d3 100644 > --- a/hw/block/m25p80.c > +++ b/hw/block/m25p80.c > @@ -32,17 +32,7 @@ > #include "qemu/module.h" > #include "qemu/error-report.h" > #include "qapi/error.h" > - > -#ifndef M25P80_ERR_DEBUG > -#define M25P80_ERR_DEBUG 0 > -#endif > - > -#define DB_PRINT_L(level, ...) do { \ > - if (M25P80_ERR_DEBUG > (level)) { \ > - fprintf(stderr, ": %s: ", __func__); \ > - fprintf(stderr, ## __VA_ARGS__); \ > - } \ > -} while (0) > +#include "trace.h" > > /* Fields for FlashPartInfo->flags */ > > @@ -574,7 +564,8 @@ static void flash_erase(Flash *s, int offset, FlashCMD cmd) > abort(); > } > > - DB_PRINT_L(0, "offset = %#x, len = %d\n", offset, len); > + trace_m25p80_flash_erase(offset, len); > + > if ((s->pi->flags & capa_to_assert) != capa_to_assert) { > qemu_log_mask(LOG_GUEST_ERROR, "M25P80: %d erase size not supported by" > " device\n", len); > @@ -607,8 +598,7 @@ void flash_write8(Flash *s, uint32_t addr, uint8_t data) > } > > if ((prev ^ data) & data) { > - DB_PRINT_L(1, "programming zero to one! addr=%" PRIx32 " %" PRIx8 > - " -> %" PRIx8 "\n", addr, prev, data); > + trace_m25p80_programming_zero_to_one(addr, prev, data); > } > > if (s->pi->flags & EEPROM) { > @@ -662,6 +652,9 @@ static void complete_collecting_data(Flash *s) > > s->state = STATE_IDLE; > > + trace_m25p80_complete_collecting(s->cmd_in_progress, n, s->ear, > + s->cur_addr); > + > switch (s->cmd_in_progress) { > case DPP: > case QPP: > @@ -825,7 +818,7 @@ static void reset_memory(Flash *s) > break; > } > > - DB_PRINT_L(0, "Reset done.\n"); > + trace_m25p80_reset_done(); > } > > static void decode_fast_read_cmd(Flash *s) > @@ -941,9 +934,10 @@ static void decode_qio_read_cmd(Flash *s) > > static void decode_new_cmd(Flash *s, uint32_t value) > { > - s->cmd_in_progress = value; > int i; > - DB_PRINT_L(0, "decoded new command:%x\n", value); > + > + s->cmd_in_progress = value; > + trace_m25p80_command_decoded(value); > > if (value != RESET_MEMORY) { > s->reset_enable = false; > @@ -1042,7 +1036,7 @@ static void decode_new_cmd(Flash *s, uint32_t value) > break; > > case JEDEC_READ: > - DB_PRINT_L(0, "populated jedec code\n"); > + trace_m25p80_populated_jedec(); > for (i = 0; i < s->pi->id_len; i++) { > s->data[i] = s->pi->id[i]; > } > @@ -1063,7 +1057,7 @@ static void decode_new_cmd(Flash *s, uint32_t value) > case BULK_ERASE_60: > case BULK_ERASE: > if (s->write_enable) { > - DB_PRINT_L(0, "chip erase\n"); > + trace_m25p80_chip_erase(); > flash_erase(s, 0, BULK_ERASE); > } else { > qemu_log_mask(LOG_GUEST_ERROR, "M25P80: chip erase with write " > @@ -1184,7 +1178,7 @@ static int m25p80_cs(SSISlave *ss, bool select) > s->data_read_loop = false; > } > > - DB_PRINT_L(0, "%sselect\n", select ? "de" : ""); > + trace_m25p80_select(select ? "de" : ""); > > return 0; > } > @@ -1194,19 +1188,20 @@ static uint32_t m25p80_transfer8(SSISlave *ss, uint32_t tx) > Flash *s = M25P80(ss); > uint32_t r = 0; > > + trace_m25p80_transfer(s->state, s->len, s->needed_bytes, s->pos, > + s->cur_addr, (uint8_t)tx); > + > switch (s->state) { > > case STATE_PAGE_PROGRAM: > - DB_PRINT_L(1, "page program cur_addr=%#" PRIx32 " data=%" PRIx8 "\n", > - s->cur_addr, (uint8_t)tx); > + trace_m25p80_page_program(s->cur_addr, (uint8_t)tx); > flash_write8(s, s->cur_addr, (uint8_t)tx); > s->cur_addr = (s->cur_addr + 1) & (s->size - 1); > break; > > case STATE_READ: > r = s->storage[s->cur_addr]; > - DB_PRINT_L(1, "READ 0x%" PRIx32 "=%" PRIx8 "\n", s->cur_addr, > - (uint8_t)r); > + trace_m25p80_read_byte(s->cur_addr, (uint8_t)r); > s->cur_addr = (s->cur_addr + 1) & (s->size - 1); > break; > > @@ -1244,6 +1239,7 @@ static uint32_t m25p80_transfer8(SSISlave *ss, uint32_t tx) > } > > r = s->data[s->pos]; > + trace_m25p80_read_data(s->pos, (uint8_t)r); > s->pos++; > if (s->pos == s->len) { > s->pos = 0; > @@ -1281,7 +1277,7 @@ static void m25p80_realize(SSISlave *ss, Error **errp) > return; > } > > - DB_PRINT_L(0, "Binding to IF_MTD drive\n"); > + trace_m25p80_binding(); > s->storage = blk_blockalign(s->blk, s->size); > > if (blk_pread(s->blk, 0, s->storage, s->size) != s->size) { > @@ -1289,7 +1285,7 @@ static void m25p80_realize(SSISlave *ss, Error **errp) > return; > } > } else { > - DB_PRINT_L(0, "No BDRV - binding to RAM\n"); > + trace_m25p80_binding_no_bdrv(); > s->storage = blk_blockalign(NULL, s->size); > memset(s->storage, 0xFF, s->size); > } > diff --git a/hw/block/trace-events b/hw/block/trace-events > index c03e80c2c9..d052f7578c 100644 > --- a/hw/block/trace-events > +++ b/hw/block/trace-events > @@ -134,3 +134,19 @@ xen_block_blockdev_add(char *str) "%s" > xen_block_blockdev_del(const char *node_name) "%s" > xen_block_device_create(unsigned int number) "%u" > xen_block_device_destroy(unsigned int number) "%u" > + > +# m25p80.c > +m25p80_flash_erase(int offset, uint32_t len) "offset = 0x%"PRIx32", len = %u" > +m25p80_programming_zero_to_one(uint32_t addr, uint8_t prev, uint8_t data) "programming zero to one! addr=0x%"PRIx32" 0x%"PRIx8" -> 0x%"PRIx8 > +m25p80_reset_done(void) "Reset done." > +m25p80_command_decoded(uint32_t cmd) "new command:0x%"PRIx32 > +m25p80_complete_collecting(uint32_t cmd, int n, uint8_t ear, uint32_t cur_addr) "decode cmd: 0x%"PRIx32" len %d ear 0x%"PRIx8" addr 0x%"PRIx32 > +m25p80_populated_jedec(void) "populated jedec code" > +m25p80_chip_erase(void) "chip erase" > +m25p80_select(const char *what) "%sselect" > +m25p80_page_program(uint32_t addr, uint8_t tx) "page program cur_addr=0x%"PRIx32" data=0x%"PRIx8 > +m25p80_transfer(uint8_t state, uint32_t len, uint8_t needed, uint32_t pos, uint32_t cur_addr, uint8_t t) "Transfer state 0x%"PRIx8" len 0x%"PRIx32" needed 0x%"PRIx8" pos 0x%"PRIx32" addr 0x%"PRIx32" tx 0x%"PRIx8 > +m25p80_read_byte(uint32_t addr, uint8_t v) "Read byte 0x%"PRIx32"=0x%"PRIx8 > +m25p80_read_data(uint32_t pos, uint8_t v) "Read data 0x%"PRIx32"=0x%"PRIx8 > +m25p80_binding(void) "Binding to IF_MTD drive" > +m25p80_binding_no_bdrv(void) "No BDRV - binding to RAM" >
On Wed, Feb 05, 2020 at 11:05:04AM +0100, Cédric Le Goater wrote: > On 2/3/20 7:09 PM, Guenter Roeck wrote: > > While at it, add some trace messages to help debug problems > > seen when running the latest Linux kernel. > > In case you resend, It would be nice to printout a flash id in the tracing > else I have a patch for it on top of yours. It helped me track a squashfs > corruption on the Aspeed witherspoon-bmc machine which we were after since > 2017 or so. It seems to be a kernel bug. > I'll send a new version to split patch 2. Not sure I understand what you mean with the above. If you send me your patch I'll be happy to merge it into mine, otherwise we can just keep it as follow-ip patch. Thanks, Guenter
On 2/5/20 5:35 PM, Guenter Roeck wrote: > On Wed, Feb 05, 2020 at 11:05:04AM +0100, Cédric Le Goater wrote: >> On 2/3/20 7:09 PM, Guenter Roeck wrote: >>> While at it, add some trace messages to help debug problems >>> seen when running the latest Linux kernel. >> >> In case you resend, It would be nice to printout a flash id in the tracing >> else I have a patch for it on top of yours. It helped me track a squashfs >> corruption on the Aspeed witherspoon-bmc machine which we were after since >> 2017 or so. It seems to be a kernel bug. >> > > I'll send a new version to split patch 2. Not sure I understand what you mean > with the above. If you send me your patch I'll be happy to merge it into mine, > otherwise we can just keep it as follow-ip patch. Here is the idea : https://github.com/legoater/qemu/commit/a07727e9cfc8447ea18249ff68a561f7e8883584 You can merge and maybe extend to all traces. In the issue we had, two CS could be selected at the same time and the SPI transfers were getting mixed. Printing out which CS is doing what is interesting for debug. Thanks, C.
On Wed, Feb 05, 2020 at 06:10:44PM +0100, Cédric Le Goater wrote: > On 2/5/20 5:35 PM, Guenter Roeck wrote: > > On Wed, Feb 05, 2020 at 11:05:04AM +0100, Cédric Le Goater wrote: > >> On 2/3/20 7:09 PM, Guenter Roeck wrote: > >>> While at it, add some trace messages to help debug problems > >>> seen when running the latest Linux kernel. > >> > >> In case you resend, It would be nice to printout a flash id in the tracing > >> else I have a patch for it on top of yours. It helped me track a squashfs > >> corruption on the Aspeed witherspoon-bmc machine which we were after since > >> 2017 or so. It seems to be a kernel bug. > >> > > > > I'll send a new version to split patch 2. Not sure I understand what you mean > > with the above. If you send me your patch I'll be happy to merge it into mine, > > otherwise we can just keep it as follow-ip patch. > > Here is the idea : > > https://github.com/legoater/qemu/commit/a07727e9cfc8447ea18249ff68a561f7e8883584 > Ah, that. I had thought about doing that, but I found displaying the pointer a bit clumsy. It looks like there isn't really anything else available that would provide a flash index, and I agree that it would be useful, so I'll add it for all traces. Thanks, Guenter
diff --git a/hw/block/m25p80.c b/hw/block/m25p80.c index 11ff5b9ad7..63e050d7d3 100644 --- a/hw/block/m25p80.c +++ b/hw/block/m25p80.c @@ -32,17 +32,7 @@ #include "qemu/module.h" #include "qemu/error-report.h" #include "qapi/error.h" - -#ifndef M25P80_ERR_DEBUG -#define M25P80_ERR_DEBUG 0 -#endif - -#define DB_PRINT_L(level, ...) do { \ - if (M25P80_ERR_DEBUG > (level)) { \ - fprintf(stderr, ": %s: ", __func__); \ - fprintf(stderr, ## __VA_ARGS__); \ - } \ -} while (0) +#include "trace.h" /* Fields for FlashPartInfo->flags */ @@ -574,7 +564,8 @@ static void flash_erase(Flash *s, int offset, FlashCMD cmd) abort(); } - DB_PRINT_L(0, "offset = %#x, len = %d\n", offset, len); + trace_m25p80_flash_erase(offset, len); + if ((s->pi->flags & capa_to_assert) != capa_to_assert) { qemu_log_mask(LOG_GUEST_ERROR, "M25P80: %d erase size not supported by" " device\n", len); @@ -607,8 +598,7 @@ void flash_write8(Flash *s, uint32_t addr, uint8_t data) } if ((prev ^ data) & data) { - DB_PRINT_L(1, "programming zero to one! addr=%" PRIx32 " %" PRIx8 - " -> %" PRIx8 "\n", addr, prev, data); + trace_m25p80_programming_zero_to_one(addr, prev, data); } if (s->pi->flags & EEPROM) { @@ -662,6 +652,9 @@ static void complete_collecting_data(Flash *s) s->state = STATE_IDLE; + trace_m25p80_complete_collecting(s->cmd_in_progress, n, s->ear, + s->cur_addr); + switch (s->cmd_in_progress) { case DPP: case QPP: @@ -825,7 +818,7 @@ static void reset_memory(Flash *s) break; } - DB_PRINT_L(0, "Reset done.\n"); + trace_m25p80_reset_done(); } static void decode_fast_read_cmd(Flash *s) @@ -941,9 +934,10 @@ static void decode_qio_read_cmd(Flash *s) static void decode_new_cmd(Flash *s, uint32_t value) { - s->cmd_in_progress = value; int i; - DB_PRINT_L(0, "decoded new command:%x\n", value); + + s->cmd_in_progress = value; + trace_m25p80_command_decoded(value); if (value != RESET_MEMORY) { s->reset_enable = false; @@ -1042,7 +1036,7 @@ static void decode_new_cmd(Flash *s, uint32_t value) break; case JEDEC_READ: - DB_PRINT_L(0, "populated jedec code\n"); + trace_m25p80_populated_jedec(); for (i = 0; i < s->pi->id_len; i++) { s->data[i] = s->pi->id[i]; } @@ -1063,7 +1057,7 @@ static void decode_new_cmd(Flash *s, uint32_t value) case BULK_ERASE_60: case BULK_ERASE: if (s->write_enable) { - DB_PRINT_L(0, "chip erase\n"); + trace_m25p80_chip_erase(); flash_erase(s, 0, BULK_ERASE); } else { qemu_log_mask(LOG_GUEST_ERROR, "M25P80: chip erase with write " @@ -1184,7 +1178,7 @@ static int m25p80_cs(SSISlave *ss, bool select) s->data_read_loop = false; } - DB_PRINT_L(0, "%sselect\n", select ? "de" : ""); + trace_m25p80_select(select ? "de" : ""); return 0; } @@ -1194,19 +1188,20 @@ static uint32_t m25p80_transfer8(SSISlave *ss, uint32_t tx) Flash *s = M25P80(ss); uint32_t r = 0; + trace_m25p80_transfer(s->state, s->len, s->needed_bytes, s->pos, + s->cur_addr, (uint8_t)tx); + switch (s->state) { case STATE_PAGE_PROGRAM: - DB_PRINT_L(1, "page program cur_addr=%#" PRIx32 " data=%" PRIx8 "\n", - s->cur_addr, (uint8_t)tx); + trace_m25p80_page_program(s->cur_addr, (uint8_t)tx); flash_write8(s, s->cur_addr, (uint8_t)tx); s->cur_addr = (s->cur_addr + 1) & (s->size - 1); break; case STATE_READ: r = s->storage[s->cur_addr]; - DB_PRINT_L(1, "READ 0x%" PRIx32 "=%" PRIx8 "\n", s->cur_addr, - (uint8_t)r); + trace_m25p80_read_byte(s->cur_addr, (uint8_t)r); s->cur_addr = (s->cur_addr + 1) & (s->size - 1); break; @@ -1244,6 +1239,7 @@ static uint32_t m25p80_transfer8(SSISlave *ss, uint32_t tx) } r = s->data[s->pos]; + trace_m25p80_read_data(s->pos, (uint8_t)r); s->pos++; if (s->pos == s->len) { s->pos = 0; @@ -1281,7 +1277,7 @@ static void m25p80_realize(SSISlave *ss, Error **errp) return; } - DB_PRINT_L(0, "Binding to IF_MTD drive\n"); + trace_m25p80_binding(); s->storage = blk_blockalign(s->blk, s->size); if (blk_pread(s->blk, 0, s->storage, s->size) != s->size) { @@ -1289,7 +1285,7 @@ static void m25p80_realize(SSISlave *ss, Error **errp) return; } } else { - DB_PRINT_L(0, "No BDRV - binding to RAM\n"); + trace_m25p80_binding_no_bdrv(); s->storage = blk_blockalign(NULL, s->size); memset(s->storage, 0xFF, s->size); } diff --git a/hw/block/trace-events b/hw/block/trace-events index c03e80c2c9..d052f7578c 100644 --- a/hw/block/trace-events +++ b/hw/block/trace-events @@ -134,3 +134,19 @@ xen_block_blockdev_add(char *str) "%s" xen_block_blockdev_del(const char *node_name) "%s" xen_block_device_create(unsigned int number) "%u" xen_block_device_destroy(unsigned int number) "%u" + +# m25p80.c +m25p80_flash_erase(int offset, uint32_t len) "offset = 0x%"PRIx32", len = %u" +m25p80_programming_zero_to_one(uint32_t addr, uint8_t prev, uint8_t data) "programming zero to one! addr=0x%"PRIx32" 0x%"PRIx8" -> 0x%"PRIx8 +m25p80_reset_done(void) "Reset done." +m25p80_command_decoded(uint32_t cmd) "new command:0x%"PRIx32 +m25p80_complete_collecting(uint32_t cmd, int n, uint8_t ear, uint32_t cur_addr) "decode cmd: 0x%"PRIx32" len %d ear 0x%"PRIx8" addr 0x%"PRIx32 +m25p80_populated_jedec(void) "populated jedec code" +m25p80_chip_erase(void) "chip erase" +m25p80_select(const char *what) "%sselect" +m25p80_page_program(uint32_t addr, uint8_t tx) "page program cur_addr=0x%"PRIx32" data=0x%"PRIx8 +m25p80_transfer(uint8_t state, uint32_t len, uint8_t needed, uint32_t pos, uint32_t cur_addr, uint8_t t) "Transfer state 0x%"PRIx8" len 0x%"PRIx32" needed 0x%"PRIx8" pos 0x%"PRIx32" addr 0x%"PRIx32" tx 0x%"PRIx8 +m25p80_read_byte(uint32_t addr, uint8_t v) "Read byte 0x%"PRIx32"=0x%"PRIx8 +m25p80_read_data(uint32_t pos, uint8_t v) "Read data 0x%"PRIx32"=0x%"PRIx8 +m25p80_binding(void) "Binding to IF_MTD drive" +m25p80_binding_no_bdrv(void) "No BDRV - binding to RAM"
While at it, add some trace messages to help debug problems seen when running the latest Linux kernel. Signed-off-by: Guenter Roeck <linux@roeck-us.net> --- hw/block/m25p80.c | 48 ++++++++++++++++++++----------------------- hw/block/trace-events | 16 +++++++++++++++ 2 files changed, 38 insertions(+), 26 deletions(-)