[PATCH v2 1/4] m25p80: Convert to support tracing

[PATCH v2 1/4] m25p80: Convert to support tracing

[Guenter Roeck]

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>
---
v2: Print pointer to Flash data structure as flash ID with each trace
    message to support systems with more than one instantiated flash.

 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 61f2fb8f8f..5ff8d270c4 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(s, 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(s, 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, 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(s);
 }
 
 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(s, 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(s);
         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(s);
             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(s, 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, 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, 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, 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, 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);
         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);
         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..f78939fa9d 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(void *s, int offset, uint32_t len) "[%p] offset = 0x%"PRIx32", len = %u"
+m25p80_programming_zero_to_one(void *s, uint32_t addr, uint8_t prev, uint8_t data) "[%p] programming zero to one! addr=0x%"PRIx32"  0x%"PRIx8" -> 0x%"PRIx8
+m25p80_reset_done(void *s) "[%p] Reset done."
+m25p80_command_decoded(void *s, uint32_t cmd) "[%p] new command:0x%"PRIx32
+m25p80_complete_collecting(void *s, uint32_t cmd, int n, uint8_t ear, uint32_t cur_addr) "[%p] decode cmd: 0x%"PRIx32" len %d ear 0x%"PRIx8" addr 0x%"PRIx32
+m25p80_populated_jedec(void *s) "[%p] populated jedec code"
+m25p80_chip_erase(void *s) "[%p] chip erase"
+m25p80_select(void *s, const char *what) "[%p] %sselect"
+m25p80_page_program(void *s, uint32_t addr, uint8_t tx) "[%p] page program cur_addr=0x%"PRIx32" data=0x%"PRIx8
+m25p80_transfer(void *s, uint8_t state, uint32_t len, uint8_t needed, uint32_t pos, uint32_t cur_addr, uint8_t t) "[%p] Transfer state 0x%"PRIx8" len 0x%"PRIx32" needed 0x%"PRIx8" pos 0x%"PRIx32" addr 0x%"PRIx32" tx 0x%"PRIx8
+m25p80_read_byte(void *s, uint32_t addr, uint8_t v) "[%p] Read byte 0x%"PRIx32"=0x%"PRIx8
+m25p80_read_data(void *s, uint32_t pos, uint8_t v) "[%p] Read data 0x%"PRIx32"=0x%"PRIx8
+m25p80_binding(void *s) "[%p] Binding to IF_MTD drive"
+m25p80_binding_no_bdrv(void *s) "[%p] No BDRV - binding to RAM"
-- 
2.17.1

[PATCH v2 2/4] m25p80: Improve command handling for Jedec commands

[Guenter Roeck]

When requesting JEDEC data using the JEDEC_READ command, the Linux kernel
always requests 6 bytes. The current implementation only returns three
bytes, and interprets the remaining three bytes as new commands.
While this does not matter most of the time, it is at the very least
confusing. To avoid the problem, always report up to 6 bytes of JEDEC
data. Fill remaining data with 0.

Signed-off-by: Guenter Roeck <linux@roeck-us.net>
---
v2: Split patch into two parts; improved decription

 hw/block/m25p80.c | 5 ++++-
 1 file changed, 4 insertions(+), 1 deletion(-)

diff --git a/hw/block/m25p80.c b/hw/block/m25p80.c
index 5ff8d270c4..53bf63856f 100644
--- a/hw/block/m25p80.c
+++ b/hw/block/m25p80.c
@@ -1040,8 +1040,11 @@ static void decode_new_cmd(Flash *s, uint32_t value)
         for (i = 0; i < s->pi->id_len; i++) {
             s->data[i] = s->pi->id[i];
         }
+        for (; i < SPI_NOR_MAX_ID_LEN; i++) {
+            s->data[i] = 0;
+        }
 
-        s->len = s->pi->id_len;
+        s->len = SPI_NOR_MAX_ID_LEN;
         s->pos = 0;
         s->state = STATE_READING_DATA;
         break;
-- 
2.17.1

[PATCH v2 3/4] m25p80: Improve command handling for unsupported commands

[Guenter Roeck]

Whenever an unsupported command is encountered, the current code
interprets each transferred byte as new command. Most of the time, those
'commands' are interpreted as new unknown commands. However, in rare
cases, it may be that for example address or length information
passed with the original command is by itself a valid command.
If that happens, the state machine may get completely confused and,
worst case, start writing data into the flash or even erase it.

To avoid the problem, transition into STATE_READING_DATA and keep
sending a value of 0 until the chip is deselected after encountering
an unsupported command.

Signed-off-by: Guenter Roeck <linux@roeck-us.net>
---
v2: Split patch into two parts; improved description.

 hw/block/m25p80.c | 5 +++++
 1 file changed, 5 insertions(+)

diff --git a/hw/block/m25p80.c b/hw/block/m25p80.c
index 53bf63856f..8227088441 100644
--- a/hw/block/m25p80.c
+++ b/hw/block/m25p80.c
@@ -1161,6 +1161,11 @@ static void decode_new_cmd(Flash *s, uint32_t value)
         s->quad_enable = false;
         break;
     default:
+        s->pos = 0;
+        s->len = 1;
+        s->state = STATE_READING_DATA;
+        s->data_read_loop = true;
+        s->data[0] = 0;
         qemu_log_mask(LOG_GUEST_ERROR, "M25P80: Unknown cmd %x\n", value);
         break;
     }
-- 
2.17.1

[PATCH v2 4/4] aspeed/smc: Fix number of dummy cycles for FAST_READ_4 command

[Guenter Roeck]

The Linux kernel recently started using FAST_READ_4 commands.
This results in flash read failures. At the same time, the m25p80
emulation is seen to read 8 more bytes than expected. Adjusting the
expected number of dummy cycles to match FAST_READ fixes the problem.

Fixes: f95c4bffdc4c ("aspeed/smc: snoop SPI transfers to fake dummy cycles")
Reviewed-by: Cédric Le Goater <clg@kaod.org>
Signed-off-by: Guenter Roeck <linux@roeck-us.net>
---
v2: No change

 hw/ssi/aspeed_smc.c | 2 +-
 1 file changed, 1 insertion(+), 1 deletion(-)

diff --git a/hw/ssi/aspeed_smc.c b/hw/ssi/aspeed_smc.c
index 23c8d2f062..0444570750 100644
--- a/hw/ssi/aspeed_smc.c
+++ b/hw/ssi/aspeed_smc.c
@@ -787,11 +787,11 @@ static int aspeed_smc_num_dummies(uint8_t command)
     case FAST_READ:
     case DOR:
     case QOR:
+    case FAST_READ_4:
     case DOR_4:
     case QOR_4:
         return 1;
     case DIOR:
-    case FAST_READ_4:
     case DIOR_4:
         return 2;
     case QIOR:
-- 
2.17.1

Re: [PATCH v2 2/4] m25p80: Improve command handling for Jedec commands

[Philippe Mathieu-Daudé]

On 2/6/20 7:32 PM, Guenter Roeck wrote:
> When requesting JEDEC data using the JEDEC_READ command, the Linux kernel
> always requests 6 bytes. The current implementation only returns three
> bytes, and interprets the remaining three bytes as new commands.
> While this does not matter most of the time, it is at the very least
> confusing. To avoid the problem, always report up to 6 bytes of JEDEC
> data. Fill remaining data with 0.
> 
> Signed-off-by: Guenter Roeck <linux@roeck-us.net>
> ---
> v2: Split patch into two parts; improved decription
> 
>   hw/block/m25p80.c | 5 ++++-
>   1 file changed, 4 insertions(+), 1 deletion(-)
> 
> diff --git a/hw/block/m25p80.c b/hw/block/m25p80.c
> index 5ff8d270c4..53bf63856f 100644
> --- a/hw/block/m25p80.c
> +++ b/hw/block/m25p80.c
> @@ -1040,8 +1040,11 @@ static void decode_new_cmd(Flash *s, uint32_t value)
>           for (i = 0; i < s->pi->id_len; i++) {
>               s->data[i] = s->pi->id[i];
>           }
> +        for (; i < SPI_NOR_MAX_ID_LEN; i++) {
> +            s->data[i] = 0;
> +        }
>   
> -        s->len = s->pi->id_len;
> +        s->len = SPI_NOR_MAX_ID_LEN;
>           s->pos = 0;
>           s->state = STATE_READING_DATA;
>           break;
> 

Reviewed-by: Philippe Mathieu-Daudé <philmd@redhat.com>

Re: [PATCH v2 4/4] aspeed/smc: Fix number of dummy cycles for FAST_READ_4 command

[Philippe Mathieu-Daudé]

On 2/6/20 7:32 PM, Guenter Roeck wrote:
> The Linux kernel recently started using FAST_READ_4 commands.
> This results in flash read failures. At the same time, the m25p80
> emulation is seen to read 8 more bytes than expected. Adjusting the
> expected number of dummy cycles to match FAST_READ fixes the problem.
> 
> Fixes: f95c4bffdc4c ("aspeed/smc: snoop SPI transfers to fake dummy cycles")
> Reviewed-by: Cédric Le Goater <clg@kaod.org>
> Signed-off-by: Guenter Roeck <linux@roeck-us.net>
> ---
> v2: No change
> 
>   hw/ssi/aspeed_smc.c | 2 +-
>   1 file changed, 1 insertion(+), 1 deletion(-)
> 
> diff --git a/hw/ssi/aspeed_smc.c b/hw/ssi/aspeed_smc.c
> index 23c8d2f062..0444570750 100644
> --- a/hw/ssi/aspeed_smc.c
> +++ b/hw/ssi/aspeed_smc.c
> @@ -787,11 +787,11 @@ static int aspeed_smc_num_dummies(uint8_t command)
>       case FAST_READ:
>       case DOR:
>       case QOR:
> +    case FAST_READ_4:
>       case DOR_4:
>       case QOR_4:
>           return 1;
>       case DIOR:
> -    case FAST_READ_4:
>       case DIOR_4:
>           return 2;
>       case QIOR:
> 

Reviewed-by: Philippe Mathieu-Daudé <philmd@redhat.com>

Re: [PATCH v2 1/4] m25p80: Convert to support tracing

[Philippe Mathieu-Daudé]

On 2/6/20 7:32 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>
> ---
> v2: Print pointer to Flash data structure as flash ID with each trace
>      message to support systems with more than one instantiated flash.
> 
>   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 61f2fb8f8f..5ff8d270c4 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(s, 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(s, 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, 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(s);
>   }
>   
>   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(s, 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(s);
>           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(s);
>               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(s, select ? "de" : "");

This one is acceptable.

Reviewed-by: Philippe Mathieu-Daudé <philmd@redhat.com>

>   
>       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, 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, 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, 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, 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);
>           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);
>           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..f78939fa9d 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(void *s, int offset, uint32_t len) "[%p] offset = 0x%"PRIx32", len = %u"
> +m25p80_programming_zero_to_one(void *s, uint32_t addr, uint8_t prev, uint8_t data) "[%p] programming zero to one! addr=0x%"PRIx32"  0x%"PRIx8" -> 0x%"PRIx8
> +m25p80_reset_done(void *s) "[%p] Reset done."
> +m25p80_command_decoded(void *s, uint32_t cmd) "[%p] new command:0x%"PRIx32
> +m25p80_complete_collecting(void *s, uint32_t cmd, int n, uint8_t ear, uint32_t cur_addr) "[%p] decode cmd: 0x%"PRIx32" len %d ear 0x%"PRIx8" addr 0x%"PRIx32
> +m25p80_populated_jedec(void *s) "[%p] populated jedec code"
> +m25p80_chip_erase(void *s) "[%p] chip erase"
> +m25p80_select(void *s, const char *what) "[%p] %sselect"
> +m25p80_page_program(void *s, uint32_t addr, uint8_t tx) "[%p] page program cur_addr=0x%"PRIx32" data=0x%"PRIx8
> +m25p80_transfer(void *s, uint8_t state, uint32_t len, uint8_t needed, uint32_t pos, uint32_t cur_addr, uint8_t t) "[%p] Transfer state 0x%"PRIx8" len 0x%"PRIx32" needed 0x%"PRIx8" pos 0x%"PRIx32" addr 0x%"PRIx32" tx 0x%"PRIx8
> +m25p80_read_byte(void *s, uint32_t addr, uint8_t v) "[%p] Read byte 0x%"PRIx32"=0x%"PRIx8
> +m25p80_read_data(void *s, uint32_t pos, uint8_t v) "[%p] Read data 0x%"PRIx32"=0x%"PRIx8
> +m25p80_binding(void *s) "[%p] Binding to IF_MTD drive"
> +m25p80_binding_no_bdrv(void *s) "[%p] No BDRV - binding to RAM"
> 

Re: [PATCH v2 1/4] m25p80: Convert to support tracing

[Alistair Francis]

On Thu, Feb 6, 2020 at 10:33 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

> ---
> v2: Print pointer to Flash data structure as flash ID with each trace
>     message to support systems with more than one instantiated flash.
>
>  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 61f2fb8f8f..5ff8d270c4 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(s, 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(s, 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, 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(s);
>  }
>
>  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(s, 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(s);
>          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(s);
>              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(s, 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, 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, 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, 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, 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);
>          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);
>          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..f78939fa9d 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(void *s, int offset, uint32_t len) "[%p] offset = 0x%"PRIx32", len = %u"
> +m25p80_programming_zero_to_one(void *s, uint32_t addr, uint8_t prev, uint8_t data) "[%p] programming zero to one! addr=0x%"PRIx32"  0x%"PRIx8" -> 0x%"PRIx8
> +m25p80_reset_done(void *s) "[%p] Reset done."
> +m25p80_command_decoded(void *s, uint32_t cmd) "[%p] new command:0x%"PRIx32
> +m25p80_complete_collecting(void *s, uint32_t cmd, int n, uint8_t ear, uint32_t cur_addr) "[%p] decode cmd: 0x%"PRIx32" len %d ear 0x%"PRIx8" addr 0x%"PRIx32
> +m25p80_populated_jedec(void *s) "[%p] populated jedec code"
> +m25p80_chip_erase(void *s) "[%p] chip erase"
> +m25p80_select(void *s, const char *what) "[%p] %sselect"
> +m25p80_page_program(void *s, uint32_t addr, uint8_t tx) "[%p] page program cur_addr=0x%"PRIx32" data=0x%"PRIx8
> +m25p80_transfer(void *s, uint8_t state, uint32_t len, uint8_t needed, uint32_t pos, uint32_t cur_addr, uint8_t t) "[%p] Transfer state 0x%"PRIx8" len 0x%"PRIx32" needed 0x%"PRIx8" pos 0x%"PRIx32" addr 0x%"PRIx32" tx 0x%"PRIx8
> +m25p80_read_byte(void *s, uint32_t addr, uint8_t v) "[%p] Read byte 0x%"PRIx32"=0x%"PRIx8
> +m25p80_read_data(void *s, uint32_t pos, uint8_t v) "[%p] Read data 0x%"PRIx32"=0x%"PRIx8
> +m25p80_binding(void *s) "[%p] Binding to IF_MTD drive"
> +m25p80_binding_no_bdrv(void *s) "[%p] No BDRV - binding to RAM"
> --
> 2.17.1
>
>

Re: [PATCH v2 2/4] m25p80: Improve command handling for Jedec commands

[Alistair Francis]

On Thu, Feb 6, 2020 at 10:33 AM Guenter Roeck <linux@roeck-us.net> wrote:
>
> When requesting JEDEC data using the JEDEC_READ command, the Linux kernel
> always requests 6 bytes. The current implementation only returns three
> bytes, and interprets the remaining three bytes as new commands.
> While this does not matter most of the time, it is at the very least
> confusing. To avoid the problem, always report up to 6 bytes of JEDEC
> data. Fill remaining data with 0.
>
> Signed-off-by: Guenter Roeck <linux@roeck-us.net>

Reviewed-by: Alistair Francis <alistair.francis@wdc.com>

Alistair

> ---
> v2: Split patch into two parts; improved decription
>
>  hw/block/m25p80.c | 5 ++++-
>  1 file changed, 4 insertions(+), 1 deletion(-)
>
> diff --git a/hw/block/m25p80.c b/hw/block/m25p80.c
> index 5ff8d270c4..53bf63856f 100644
> --- a/hw/block/m25p80.c
> +++ b/hw/block/m25p80.c
> @@ -1040,8 +1040,11 @@ static void decode_new_cmd(Flash *s, uint32_t value)
>          for (i = 0; i < s->pi->id_len; i++) {
>              s->data[i] = s->pi->id[i];
>          }
> +        for (; i < SPI_NOR_MAX_ID_LEN; i++) {
> +            s->data[i] = 0;
> +        }
>
> -        s->len = s->pi->id_len;
> +        s->len = SPI_NOR_MAX_ID_LEN;
>          s->pos = 0;
>          s->state = STATE_READING_DATA;
>          break;
> --
> 2.17.1
>
>

Re: [PATCH v2 3/4] m25p80: Improve command handling for unsupported commands

[Philippe Mathieu-Daudé]

On 2/6/20 7:32 PM, Guenter Roeck wrote:
> Whenever an unsupported command is encountered, the current code
> interprets each transferred byte as new command. Most of the time, those
> 'commands' are interpreted as new unknown commands. However, in rare
> cases, it may be that for example address or length information
> passed with the original command is by itself a valid command.
> If that happens, the state machine may get completely confused and,
> worst case, start writing data into the flash or even erase it.
> 
> To avoid the problem, transition into STATE_READING_DATA and keep
> sending a value of 0 until the chip is deselected after encountering
> an unsupported command.
> 
> Signed-off-by: Guenter Roeck <linux@roeck-us.net>
> ---
> v2: Split patch into two parts; improved description.
> 
>   hw/block/m25p80.c | 5 +++++
>   1 file changed, 5 insertions(+)
> 
> diff --git a/hw/block/m25p80.c b/hw/block/m25p80.c
> index 53bf63856f..8227088441 100644
> --- a/hw/block/m25p80.c
> +++ b/hw/block/m25p80.c
> @@ -1161,6 +1161,11 @@ static void decode_new_cmd(Flash *s, uint32_t value)
>           s->quad_enable = false;
>           break;
>       default:
> +        s->pos = 0;
> +        s->len = 1;
> +        s->state = STATE_READING_DATA;
> +        s->data_read_loop = true;
> +        s->data[0] = 0;

Maybe self-explicit using:

            s->data[0] = NOP;

Matter of taste probably, but I find this order easier to review:

            s->state = STATE_READING_DATA;
            s->data_read_loop = true;
            s->pos = 0;
            s->data[0] = NOP;
            s->len = 1;

Reviewed-by: Philippe Mathieu-Daudé <philmd@redhat.com>

>           qemu_log_mask(LOG_GUEST_ERROR, "M25P80: Unknown cmd %x\n", value);
>           break;
>       }
> 

Re: [PATCH v2 1/4] m25p80: Convert to support tracing

[Cédric Le Goater]

On 2/6/20 7:32 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>

> ---
> v2: Print pointer to Flash data structure as flash ID with each trace
>     message to support systems with more than one instantiated flash.
> 
>  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 61f2fb8f8f..5ff8d270c4 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(s, 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(s, 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, 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(s);
>  }
>  
>  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(s, 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(s);
>          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(s);
>              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(s, 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, 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, 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, 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, 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);
>          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);
>          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..f78939fa9d 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(void *s, int offset, uint32_t len) "[%p] offset = 0x%"PRIx32", len = %u"
> +m25p80_programming_zero_to_one(void *s, uint32_t addr, uint8_t prev, uint8_t data) "[%p] programming zero to one! addr=0x%"PRIx32"  0x%"PRIx8" -> 0x%"PRIx8
> +m25p80_reset_done(void *s) "[%p] Reset done."
> +m25p80_command_decoded(void *s, uint32_t cmd) "[%p] new command:0x%"PRIx32
> +m25p80_complete_collecting(void *s, uint32_t cmd, int n, uint8_t ear, uint32_t cur_addr) "[%p] decode cmd: 0x%"PRIx32" len %d ear 0x%"PRIx8" addr 0x%"PRIx32
> +m25p80_populated_jedec(void *s) "[%p] populated jedec code"
> +m25p80_chip_erase(void *s) "[%p] chip erase"
> +m25p80_select(void *s, const char *what) "[%p] %sselect"
> +m25p80_page_program(void *s, uint32_t addr, uint8_t tx) "[%p] page program cur_addr=0x%"PRIx32" data=0x%"PRIx8
> +m25p80_transfer(void *s, uint8_t state, uint32_t len, uint8_t needed, uint32_t pos, uint32_t cur_addr, uint8_t t) "[%p] Transfer state 0x%"PRIx8" len 0x%"PRIx32" needed 0x%"PRIx8" pos 0x%"PRIx32" addr 0x%"PRIx32" tx 0x%"PRIx8
> +m25p80_read_byte(void *s, uint32_t addr, uint8_t v) "[%p] Read byte 0x%"PRIx32"=0x%"PRIx8
> +m25p80_read_data(void *s, uint32_t pos, uint8_t v) "[%p] Read data 0x%"PRIx32"=0x%"PRIx8
> +m25p80_binding(void *s) "[%p] Binding to IF_MTD drive"
> +m25p80_binding_no_bdrv(void *s) "[%p] No BDRV - binding to RAM"
> 

Re: [PATCH v2 2/4] m25p80: Improve command handling for Jedec commands

[Cédric Le Goater]

On 2/6/20 7:32 PM, Guenter Roeck wrote:
> When requesting JEDEC data using the JEDEC_READ command, the Linux kernel
> always requests 6 bytes. The current implementation only returns three
> bytes, and interprets the remaining three bytes as new commands.
> While this does not matter most of the time, it is at the very least
> confusing. To avoid the problem, always report up to 6 bytes of JEDEC
> data. Fill remaining data with 0.
> 
> Signed-off-by: Guenter Roeck <linux@roeck-us.net>


Reviewed-by: Cédric Le Goater <clg@kaod.org>

> ---
> v2: Split patch into two parts; improved decription
> 
>  hw/block/m25p80.c | 5 ++++-
>  1 file changed, 4 insertions(+), 1 deletion(-)
> 
> diff --git a/hw/block/m25p80.c b/hw/block/m25p80.c
> index 5ff8d270c4..53bf63856f 100644
> --- a/hw/block/m25p80.c
> +++ b/hw/block/m25p80.c
> @@ -1040,8 +1040,11 @@ static void decode_new_cmd(Flash *s, uint32_t value)
>          for (i = 0; i < s->pi->id_len; i++) {
>              s->data[i] = s->pi->id[i];
>          }
> +        for (; i < SPI_NOR_MAX_ID_LEN; i++) {
> +            s->data[i] = 0;
> +        }
>  
> -        s->len = s->pi->id_len;
> +        s->len = SPI_NOR_MAX_ID_LEN;
>          s->pos = 0;
>          s->state = STATE_READING_DATA;
>          break;
> 

Re: [PATCH v2 3/4] m25p80: Improve command handling for unsupported commands

[Cédric Le Goater]

On 2/6/20 7:32 PM, Guenter Roeck wrote:
> Whenever an unsupported command is encountered, the current code
> interprets each transferred byte as new command. Most of the time, those
> 'commands' are interpreted as new unknown commands. However, in rare
> cases, it may be that for example address or length information
> passed with the original command is by itself a valid command.
> If that happens, the state machine may get completely confused and,
> worst case, start writing data into the flash or even erase it.
> 
> To avoid the problem, transition into STATE_READING_DATA and keep
> sending a value of 0 until the chip is deselected after encountering
> an unsupported command.
> 
> Signed-off-by: Guenter Roeck <linux@roeck-us.net>


Reviewed-by: Cédric Le Goater <clg@kaod.org>

> ---
> v2: Split patch into two parts; improved description.
> 
>  hw/block/m25p80.c | 5 +++++
>  1 file changed, 5 insertions(+)
> 
> diff --git a/hw/block/m25p80.c b/hw/block/m25p80.c
> index 53bf63856f..8227088441 100644
> --- a/hw/block/m25p80.c
> +++ b/hw/block/m25p80.c
> @@ -1161,6 +1161,11 @@ static void decode_new_cmd(Flash *s, uint32_t value)
>          s->quad_enable = false;
>          break;
>      default:
> +        s->pos = 0;
> +        s->len = 1;
> +        s->state = STATE_READING_DATA;
> +        s->data_read_loop = true;
> +        s->data[0] = 0;
>          qemu_log_mask(LOG_GUEST_ERROR, "M25P80: Unknown cmd %x\n", value);
>          break;
>      }
> 

Re: [PATCH v2 1/4] m25p80: Convert to support tracing

[Cédric Le Goater]

Hello all, 

On 2/6/20 7:32 PM, Guenter Roeck wrote:
> While at it, add some trace messages to help debug problems
> seen when running the latest Linux kernel.

Through which tree do you think it is best to merge this patchset ? 
block or arm ? 

Thanks,

C.


> Signed-off-by: Guenter Roeck <linux@roeck-us.net>
> ---
> v2: Print pointer to Flash data structure as flash ID with each trace
>     message to support systems with more than one instantiated flash.
> 
>  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 61f2fb8f8f..5ff8d270c4 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(s, 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(s, 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, 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(s);
>  }
>  
>  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(s, 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(s);
>          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(s);
>              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(s, 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, 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, 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, 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, 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);
>          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);
>          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..f78939fa9d 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(void *s, int offset, uint32_t len) "[%p] offset = 0x%"PRIx32", len = %u"
> +m25p80_programming_zero_to_one(void *s, uint32_t addr, uint8_t prev, uint8_t data) "[%p] programming zero to one! addr=0x%"PRIx32"  0x%"PRIx8" -> 0x%"PRIx8
> +m25p80_reset_done(void *s) "[%p] Reset done."
> +m25p80_command_decoded(void *s, uint32_t cmd) "[%p] new command:0x%"PRIx32
> +m25p80_complete_collecting(void *s, uint32_t cmd, int n, uint8_t ear, uint32_t cur_addr) "[%p] decode cmd: 0x%"PRIx32" len %d ear 0x%"PRIx8" addr 0x%"PRIx32
> +m25p80_populated_jedec(void *s) "[%p] populated jedec code"
> +m25p80_chip_erase(void *s) "[%p] chip erase"
> +m25p80_select(void *s, const char *what) "[%p] %sselect"
> +m25p80_page_program(void *s, uint32_t addr, uint8_t tx) "[%p] page program cur_addr=0x%"PRIx32" data=0x%"PRIx8
> +m25p80_transfer(void *s, uint8_t state, uint32_t len, uint8_t needed, uint32_t pos, uint32_t cur_addr, uint8_t t) "[%p] Transfer state 0x%"PRIx8" len 0x%"PRIx32" needed 0x%"PRIx8" pos 0x%"PRIx32" addr 0x%"PRIx32" tx 0x%"PRIx8
> +m25p80_read_byte(void *s, uint32_t addr, uint8_t v) "[%p] Read byte 0x%"PRIx32"=0x%"PRIx8
> +m25p80_read_data(void *s, uint32_t pos, uint8_t v) "[%p] Read data 0x%"PRIx32"=0x%"PRIx8
> +m25p80_binding(void *s) "[%p] Binding to IF_MTD drive"
> +m25p80_binding_no_bdrv(void *s) "[%p] No BDRV - binding to RAM"
> 

Re: [PATCH v2 1/4] m25p80: Convert to support tracing

[Cédric Le Goater]

Hello,

On 2/17/20 4:47 PM, Cédric Le Goater wrote:
> Hello all, 
> 
> On 2/6/20 7:32 PM, Guenter Roeck wrote:
>> While at it, add some trace messages to help debug problems
>> seen when running the latest Linux kernel.
> 
> Through which tree do you think it is best to merge this patchset ? 
> block or arm ? 

It would be nice to have these 4 patches for 5.0. All are reviewed and
tested.

Thanks,

C.

 
>> Signed-off-by: Guenter Roeck <linux@roeck-us.net>
>> ---
>> v2: Print pointer to Flash data structure as flash ID with each trace
>>     message to support systems with more than one instantiated flash.
>>
>>  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 61f2fb8f8f..5ff8d270c4 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(s, 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(s, 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, 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(s);
>>  }
>>  
>>  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(s, 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(s);
>>          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(s);
>>              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(s, 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, 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, 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, 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, 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);
>>          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);
>>          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..f78939fa9d 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(void *s, int offset, uint32_t len) "[%p] offset = 0x%"PRIx32", len = %u"
>> +m25p80_programming_zero_to_one(void *s, uint32_t addr, uint8_t prev, uint8_t data) "[%p] programming zero to one! addr=0x%"PRIx32"  0x%"PRIx8" -> 0x%"PRIx8
>> +m25p80_reset_done(void *s) "[%p] Reset done."
>> +m25p80_command_decoded(void *s, uint32_t cmd) "[%p] new command:0x%"PRIx32
>> +m25p80_complete_collecting(void *s, uint32_t cmd, int n, uint8_t ear, uint32_t cur_addr) "[%p] decode cmd: 0x%"PRIx32" len %d ear 0x%"PRIx8" addr 0x%"PRIx32
>> +m25p80_populated_jedec(void *s) "[%p] populated jedec code"
>> +m25p80_chip_erase(void *s) "[%p] chip erase"
>> +m25p80_select(void *s, const char *what) "[%p] %sselect"
>> +m25p80_page_program(void *s, uint32_t addr, uint8_t tx) "[%p] page program cur_addr=0x%"PRIx32" data=0x%"PRIx8
>> +m25p80_transfer(void *s, uint8_t state, uint32_t len, uint8_t needed, uint32_t pos, uint32_t cur_addr, uint8_t t) "[%p] Transfer state 0x%"PRIx8" len 0x%"PRIx32" needed 0x%"PRIx8" pos 0x%"PRIx32" addr 0x%"PRIx32" tx 0x%"PRIx8
>> +m25p80_read_byte(void *s, uint32_t addr, uint8_t v) "[%p] Read byte 0x%"PRIx32"=0x%"PRIx8
>> +m25p80_read_data(void *s, uint32_t pos, uint8_t v) "[%p] Read data 0x%"PRIx32"=0x%"PRIx8
>> +m25p80_binding(void *s) "[%p] Binding to IF_MTD drive"
>> +m25p80_binding_no_bdrv(void *s) "[%p] No BDRV - binding to RAM"
>>
> 

Re: [PATCH v2 1/4] m25p80: Convert to support tracing

[Peter Maydell]

On Mon, 16 Mar 2020 at 14:14, Cédric Le Goater <clg@kaod.org> wrote:
>
> Hello,
>
> On 2/17/20 4:47 PM, Cédric Le Goater wrote:
> > Hello all,
> >
> > On 2/6/20 7:32 PM, Guenter Roeck wrote:
> >> While at it, add some trace messages to help debug problems
> >> seen when running the latest Linux kernel.
> >
> > Through which tree do you think it is best to merge this patchset ?
> > block or arm ?
>
> It would be nice to have these 4 patches for 5.0. All are reviewed and
> tested.

Do you have a pointer to the cover letter? Not sure
which platforms (and so which tree) they're aiming for...

thanks
-- PMM

Re: [PATCH v2 1/4] m25p80: Convert to support tracing

[Cédric Le Goater]

On 3/16/20 3:58 PM, Peter Maydell wrote:
> On Mon, 16 Mar 2020 at 14:14, Cédric Le Goater <clg@kaod.org> wrote:
>>
>> Hello,
>>
>> On 2/17/20 4:47 PM, Cédric Le Goater wrote:
>>> Hello all,
>>>
>>> On 2/6/20 7:32 PM, Guenter Roeck wrote:
>>>> While at it, add some trace messages to help debug problems
>>>> seen when running the latest Linux kernel.
>>>
>>> Through which tree do you think it is best to merge this patchset ?
>>> block or arm ?
>>
>> It would be nice to have these 4 patches for 5.0. All are reviewed and
>> tested.
> 
> Do you have a pointer to the cover letter? Not sure
> which platforms (and so which tree) they're aiming for...

Not having a cover letter clearly doesn't help ...

Here is the patchset diffstat :

 block/m25p80.c     |   58 ++++++++++++++++++++++++++++-------------------------
 block/trace-events |   16 ++++++++++++++
 ssi/aspeed_smc.c   |    2 -
 3 files changed, 48 insertions(+), 28 deletions(-)

http://patchwork.ozlabs.org/patch/1234532/
Signed-off-by: Guenter Roeck <linux@roeck-us.net>
Reviewed-by: Philippe Mathieu-Daudé <philmd@redhat.com>
Reviewed-by: Alistair Francis <alistair.francis@wdc.com>
Reviewed-by: Cédric Le Goater <clg@kaod.org>

http://patchwork.ozlabs.org/patch/1234533/
Signed-off-by: Guenter Roeck <linux@roeck-us.net>
Reviewed-by: Philippe Mathieu-Daudé <philmd@redhat.com>
Reviewed-by: Alistair Francis <alistair.francis@wdc.com>
Reviewed-by: Cédric Le Goater <clg@kaod.org>

http://patchwork.ozlabs.org/patch/1234535/
Signed-off-by: Guenter Roeck <linux@roeck-us.net>
Reviewed-by: Philippe Mathieu-Daudé <philmd@redhat.com>
Reviewed-by: Cédric Le Goater <clg@kaod.org>

http://patchwork.ozlabs.org/patch/1234536/
Fixes: f95c4bffdc4c ("aspeed/smc: snoop SPI transfers to fake dummy cycles")
Reviewed-by: Cédric Le Goater <clg@kaod.org>
Signed-off-by: Guenter Roeck <linux@roeck-us.net>
Reviewed-by: Philippe Mathieu-Daudé <philmd@redhat.com>

Thanks,

C. 

Re: [PATCH v2 1/4] m25p80: Convert to support tracing

[Peter Maydell]

On Mon, 16 Mar 2020 at 15:11, Cédric Le Goater <clg@kaod.org> wrote:
>
> On 3/16/20 3:58 PM, Peter Maydell wrote:
> > On Mon, 16 Mar 2020 at 14:14, Cédric Le Goater <clg@kaod.org> wrote:
> >>
> >> Hello,
> >>
> >> On 2/17/20 4:47 PM, Cédric Le Goater wrote:
> >>> Hello all,
> >>>
> >>> On 2/6/20 7:32 PM, Guenter Roeck wrote:
> >>>> While at it, add some trace messages to help debug problems
> >>>> seen when running the latest Linux kernel.
> >>>
> >>> Through which tree do you think it is best to merge this patchset ?
> >>> block or arm ?
> >>
> >> It would be nice to have these 4 patches for 5.0. All are reviewed and
> >> tested.
> >
> > Do you have a pointer to the cover letter? Not sure
> > which platforms (and so which tree) they're aiming for...
>
> Not having a cover letter clearly doesn't help ...
>
> Here is the patchset diffstat :
>
>  block/m25p80.c     |   58 ++++++++++++++++++++++++++++-------------------------
>  block/trace-events |   16 ++++++++++++++
>  ssi/aspeed_smc.c   |    2 -
>  3 files changed, 48 insertions(+), 28 deletions(-)
>
> http://patchwork.ozlabs.org/patch/1234532/
> Signed-off-by: Guenter Roeck <linux@roeck-us.net>
> Reviewed-by: Philippe Mathieu-Daudé <philmd@redhat.com>
> Reviewed-by: Alistair Francis <alistair.francis@wdc.com>
> Reviewed-by: Cédric Le Goater <clg@kaod.org>
>
> http://patchwork.ozlabs.org/patch/1234533/
> Signed-off-by: Guenter Roeck <linux@roeck-us.net>
> Reviewed-by: Philippe Mathieu-Daudé <philmd@redhat.com>
> Reviewed-by: Alistair Francis <alistair.francis@wdc.com>
> Reviewed-by: Cédric Le Goater <clg@kaod.org>
>
> http://patchwork.ozlabs.org/patch/1234535/
> Signed-off-by: Guenter Roeck <linux@roeck-us.net>
> Reviewed-by: Philippe Mathieu-Daudé <philmd@redhat.com>
> Reviewed-by: Cédric Le Goater <clg@kaod.org>
>
> http://patchwork.ozlabs.org/patch/1234536/
> Fixes: f95c4bffdc4c ("aspeed/smc: snoop SPI transfers to fake dummy cycles")
> Reviewed-by: Cédric Le Goater <clg@kaod.org>
> Signed-off-by: Guenter Roeck <linux@roeck-us.net>
> Reviewed-by: Philippe Mathieu-Daudé <philmd@redhat.com>

Thanks for rounding up the patchwork links; applied all
4 to target-arm.next.

-- PMM

Re: [PATCH v2 2/4] m25p80: Improve command handling for Jedec commands

[Cédric Le Goater]

Hello,

On 2/6/20 7:32 PM, Guenter Roeck wrote:
> When requesting JEDEC data using the JEDEC_READ command, the Linux kernel
> always requests 6 bytes. The current implementation only returns three
> bytes, and interprets the remaining three bytes as new commands.
> While this does not matter most of the time, it is at the very least
> confusing. To avoid the problem, always report up to 6 bytes of JEDEC
> data. Fill remaining data with 0.
> 
> Signed-off-by: Guenter Roeck <linux@roeck-us.net>
> ---
> v2: Split patch into two parts; improved decription
> 
>  hw/block/m25p80.c | 5 ++++-
>  1 file changed, 4 insertions(+), 1 deletion(-)
> 
> diff --git a/hw/block/m25p80.c b/hw/block/m25p80.c
> index 5ff8d270c4..53bf63856f 100644
> --- a/hw/block/m25p80.c
> +++ b/hw/block/m25p80.c
> @@ -1040,8 +1040,11 @@ static void decode_new_cmd(Flash *s, uint32_t value)
>          for (i = 0; i < s->pi->id_len; i++) {
>              s->data[i] = s->pi->id[i];
>          }
> +        for (; i < SPI_NOR_MAX_ID_LEN; i++) {
> +            s->data[i] = 0;
> +        }

This is breaking an old firmware (Linux version 2.6.28.9) for a SuperMicro
board : 

	https://www.supermicro.com/en/products/motherboard/X11SSL-F 

which expects the flash ID to repeat. Erik solved the problem with the patch 
below and I think it makes sense to wrap around. Anyone knows what should be 
the expected behavior ? 

Thanks,

C. 


diff --git a/hw/block/m25p80.c b/hw/block/m25p80.c
index 8227088441..5000930800 100644
--- a/hw/block/m25p80.c
+++ b/hw/block/m25p80.c
@@ -1041,7 +1041,7 @@ static void decode_new_cmd(Flash *s, uint32_t value)
             s->data[i] = s->pi->id[i];
         }
         for (; i < SPI_NOR_MAX_ID_LEN; i++) {
-            s->data[i] = 0;
+            s->data[i] = s->pi->id[i % s->pi->id_len];
         }

         s->len = SPI_NOR_MAX_ID_LEN;

Re: [PATCH v2 2/4] m25p80: Improve command handling for Jedec commands

[Guenter Roeck]

On 7/21/20 10:36 AM, Cédric Le Goater wrote:
> Hello,
> 
> On 2/6/20 7:32 PM, Guenter Roeck wrote:
>> When requesting JEDEC data using the JEDEC_READ command, the Linux kernel
>> always requests 6 bytes. The current implementation only returns three
>> bytes, and interprets the remaining three bytes as new commands.
>> While this does not matter most of the time, it is at the very least
>> confusing. To avoid the problem, always report up to 6 bytes of JEDEC
>> data. Fill remaining data with 0.
>>
>> Signed-off-by: Guenter Roeck <linux@roeck-us.net>
>> ---
>> v2: Split patch into two parts; improved decription
>>
>>  hw/block/m25p80.c | 5 ++++-
>>  1 file changed, 4 insertions(+), 1 deletion(-)
>>
>> diff --git a/hw/block/m25p80.c b/hw/block/m25p80.c
>> index 5ff8d270c4..53bf63856f 100644
>> --- a/hw/block/m25p80.c
>> +++ b/hw/block/m25p80.c
>> @@ -1040,8 +1040,11 @@ static void decode_new_cmd(Flash *s, uint32_t value)
>>          for (i = 0; i < s->pi->id_len; i++) {
>>              s->data[i] = s->pi->id[i];
>>          }
>> +        for (; i < SPI_NOR_MAX_ID_LEN; i++) {
>> +            s->data[i] = 0;
>> +        }
> 
> This is breaking an old firmware (Linux version 2.6.28.9) for a SuperMicro
> board : 
> 
> 	https://www.supermicro.com/en/products/motherboard/X11SSL-F 
> 
> which expects the flash ID to repeat. Erik solved the problem with the patch 
> below and I think it makes sense to wrap around. Anyone knows what should be 
> the expected behavior ? 
> 

No idea what the expected behavior is, but I am fine with the code below
if it works.

Thanks,
Guenter

> Thanks,
> 
> C. 
> 
> 
> diff --git a/hw/block/m25p80.c b/hw/block/m25p80.c
> index 8227088441..5000930800 100644
> --- a/hw/block/m25p80.c
> +++ b/hw/block/m25p80.c
> @@ -1041,7 +1041,7 @@ static void decode_new_cmd(Flash *s, uint32_t value)
>              s->data[i] = s->pi->id[i];
>          }
>          for (; i < SPI_NOR_MAX_ID_LEN; i++) {
> -            s->data[i] = 0;
> +            s->data[i] = s->pi->id[i % s->pi->id_len];
>          }
> 
>          s->len = SPI_NOR_MAX_ID_LEN;
> 

Re: [PATCH v2 2/4] m25p80: Improve command handling for Jedec commands

[Cédric Le Goater]

On 7/21/20 9:57 PM, Guenter Roeck wrote:
> On 7/21/20 10:36 AM, Cédric Le Goater wrote:
>> Hello,
>>
>> On 2/6/20 7:32 PM, Guenter Roeck wrote:
>>> When requesting JEDEC data using the JEDEC_READ command, the Linux kernel
>>> always requests 6 bytes. The current implementation only returns three
>>> bytes, and interprets the remaining three bytes as new commands.
>>> While this does not matter most of the time, it is at the very least
>>> confusing. To avoid the problem, always report up to 6 bytes of JEDEC
>>> data. Fill remaining data with 0.
>>>
>>> Signed-off-by: Guenter Roeck <linux@roeck-us.net>
>>> ---
>>> v2: Split patch into two parts; improved decription
>>>
>>>  hw/block/m25p80.c | 5 ++++-
>>>  1 file changed, 4 insertions(+), 1 deletion(-)
>>>
>>> diff --git a/hw/block/m25p80.c b/hw/block/m25p80.c
>>> index 5ff8d270c4..53bf63856f 100644
>>> --- a/hw/block/m25p80.c
>>> +++ b/hw/block/m25p80.c
>>> @@ -1040,8 +1040,11 @@ static void decode_new_cmd(Flash *s, uint32_t value)
>>>          for (i = 0; i < s->pi->id_len; i++) {
>>>              s->data[i] = s->pi->id[i];
>>>          }
>>> +        for (; i < SPI_NOR_MAX_ID_LEN; i++) {
>>> +            s->data[i] = 0;
>>> +        }
>>
>> This is breaking an old firmware (Linux version 2.6.28.9) for a SuperMicro
>> board : 
>>
>> 	https://www.supermicro.com/en/products/motherboard/X11SSL-F 
>>
>> which expects the flash ID to repeat. Erik solved the problem with the patch 
>> below and I think it makes sense to wrap around. Anyone knows what should be 
>> the expected behavior ? 
>>
> 
> No idea what the expected behavior is, but I am fine with the code below
> if it works.

I checked on a few real systems and indeed the mx25l25635e behaves
differently.

AST2400

[    5.594176] aspeed-smc 1e620000.spi: reading JEDEC ID 20:BA:19:10:00:00
[    5.602226] aspeed-smc 1e620000.spi: n25q256a (32768 Kbytes)
...
[    6.174052] aspeed-smc 1e630000.spi: reading JEDEC ID C2:20:19:C2:20:19
[    6.181682] aspeed-smc 1e630000.spi: mx25l25635e (32768 Kbytes)

AST2500

[    1.641317] aspeed-smc 1e620000.spi: reading JEDEC ID EF:40:19:00:00:00
[    1.648174] aspeed-smc 1e620000.spi: w25q256 (32768 Kbytes)
...
[    1.179214] aspeed-smc 1e630000.spi: reading JEDEC ID EF:40:19:00:00:00
[    1.186737] aspeed-smc 1e630000.spi: w25q256 (32768 Kbytes)

AST2600

[    1.020255] aspeed-smc 1e620000.spi: reading JEDEC ID EF:40:20:00:00:00
[    1.027830] aspeed-smc 1e620000.spi: w25q512jv (65536 Kbytes)
...
[    1.884171] aspeed-smc 1e630000.spi: reading JEDEC ID EF:40:19:00:00:00
[    1.890937] aspeed-smc 1e630000.spi: w25q256 (32768 Kbytes)


I think we need a special case for it.

C. 

Re: [PATCH v2 2/4] m25p80: Improve command handling for Jedec commands

[Philippe Mathieu-Daudé]

On 7/22/20 10:02 AM, Cédric Le Goater wrote:
> On 7/21/20 9:57 PM, Guenter Roeck wrote:
>> On 7/21/20 10:36 AM, Cédric Le Goater wrote:
>>> Hello,
>>>
>>> On 2/6/20 7:32 PM, Guenter Roeck wrote:
>>>> When requesting JEDEC data using the JEDEC_READ command, the Linux kernel
>>>> always requests 6 bytes. The current implementation only returns three
>>>> bytes, and interprets the remaining three bytes as new commands.
>>>> While this does not matter most of the time, it is at the very least
>>>> confusing. To avoid the problem, always report up to 6 bytes of JEDEC
>>>> data. Fill remaining data with 0.
>>>>
>>>> Signed-off-by: Guenter Roeck <linux@roeck-us.net>
>>>> ---
>>>> v2: Split patch into two parts; improved decription
>>>>
>>>>  hw/block/m25p80.c | 5 ++++-
>>>>  1 file changed, 4 insertions(+), 1 deletion(-)
>>>>
>>>> diff --git a/hw/block/m25p80.c b/hw/block/m25p80.c
>>>> index 5ff8d270c4..53bf63856f 100644
>>>> --- a/hw/block/m25p80.c
>>>> +++ b/hw/block/m25p80.c
>>>> @@ -1040,8 +1040,11 @@ static void decode_new_cmd(Flash *s, uint32_t value)
>>>>          for (i = 0; i < s->pi->id_len; i++) {
>>>>              s->data[i] = s->pi->id[i];
>>>>          }
>>>> +        for (; i < SPI_NOR_MAX_ID_LEN; i++) {
>>>> +            s->data[i] = 0;
>>>> +        }
>>>
>>> This is breaking an old firmware (Linux version 2.6.28.9) for a SuperMicro
>>> board : 
>>>
>>> 	https://www.supermicro.com/en/products/motherboard/X11SSL-F 
>>>
>>> which expects the flash ID to repeat. Erik solved the problem with the patch 
>>> below and I think it makes sense to wrap around. Anyone knows what should be 
>>> the expected behavior ? 
>>>
>>
>> No idea what the expected behavior is, but I am fine with the code below
>> if it works.
> 
> I checked on a few real systems and indeed the mx25l25635e behaves
> differently.
> 
> AST2400
> 
> [    5.594176] aspeed-smc 1e620000.spi: reading JEDEC ID 20:BA:19:10:00:00
> [    5.602226] aspeed-smc 1e620000.spi: n25q256a (32768 Kbytes)
> ...
> [    6.174052] aspeed-smc 1e630000.spi: reading JEDEC ID C2:20:19:C2:20:19
> [    6.181682] aspeed-smc 1e630000.spi: mx25l25635e (32768 Kbytes)
> 
> AST2500
> 
> [    1.641317] aspeed-smc 1e620000.spi: reading JEDEC ID EF:40:19:00:00:00
> [    1.648174] aspeed-smc 1e620000.spi: w25q256 (32768 Kbytes)
> ...
> [    1.179214] aspeed-smc 1e630000.spi: reading JEDEC ID EF:40:19:00:00:00
> [    1.186737] aspeed-smc 1e630000.spi: w25q256 (32768 Kbytes)
> 
> AST2600
> 
> [    1.020255] aspeed-smc 1e620000.spi: reading JEDEC ID EF:40:20:00:00:00
> [    1.027830] aspeed-smc 1e620000.spi: w25q512jv (65536 Kbytes)
> ...
> [    1.884171] aspeed-smc 1e630000.spi: reading JEDEC ID EF:40:19:00:00:00
> [    1.890937] aspeed-smc 1e630000.spi: w25q256 (32768 Kbytes)

FWIW QEMU models this one as 64KiB.

> 
> 
> I think we need a special case for it.
> 
> C. 
>