[PATCH] pflash: cfi02: Convert debug log to tracing

[Guenter Roeck]

When trying to track down problems such as failing unlock sequences
it is essential to have a complete trace log. Having part of it as debug
output and the rest as trace output is counter-productive. Convert all
debug logs to tracing.

Signed-off-by: Guenter Roeck <linux@roeck-us.net>
---
 hw/block/pflash_cfi02.c | 62 +++++++++++++++--------------------------
 hw/block/trace-events   | 18 ++++++++++++
 2 files changed, 40 insertions(+), 40 deletions(-)

diff --git a/hw/block/pflash_cfi02.c b/hw/block/pflash_cfi02.c
index ac7e34ecbf..4c6e8e3b9b 100644
--- a/hw/block/pflash_cfi02.c
+++ b/hw/block/pflash_cfi02.c
@@ -47,14 +47,6 @@
 #include "migration/vmstate.h"
 #include "trace.h"
 
-#define PFLASH_DEBUG false
-#define DPRINTF(fmt, ...)                                  \
-do {                                                       \
-    if (PFLASH_DEBUG) {                                    \
-        fprintf(stderr, "PFLASH: " fmt, ## __VA_ARGS__);   \
-    }                                                      \
-} while (0)
-
 #define PFLASH_LAZY_ROMD_THRESHOLD 42
 
 /*
@@ -232,11 +224,10 @@ static void pflash_timer(void *opaque)
             uint64_t timeout = pflash_erase_time(pfl);
             timer_mod(&pfl->timer,
                       qemu_clock_get_ns(QEMU_CLOCK_VIRTUAL) + timeout);
-            DPRINTF("%s: erase timeout fired; erasing %d sectors\n",
-                    __func__, pfl->sectors_to_erase);
+            trace_pflash_sector_erase_timeout(pfl->sectors_to_erase);
             return;
         }
-        DPRINTF("%s: sector erase complete\n", __func__);
+        trace_pflash_sector_erase_complete();
         bitmap_zero(pfl->sector_erase_map, pfl->total_sectors);
         pfl->sectors_to_erase = 0;
         reset_dq3(pfl);
@@ -324,7 +315,7 @@ static uint64_t pflash_read(void *opaque, hwaddr offset, 
unsigned int width)
     switch (pfl->cmd) {
     default:
         /* This should never happen : reset state & treat it as a read*/
-        DPRINTF("%s: unknown command state: %x\n", __func__, pfl->cmd);
+        trace_pflash_unknown_command_state(pfl->cmd);
         pfl->wcycle = 0;
         pfl->cmd = 0;
         /* fall through to the read code */
@@ -337,7 +328,7 @@ static uint64_t pflash_read(void *opaque, hwaddr offset, 
unsigned int width)
             toggle_dq2(pfl);
             /* Status register read */
             ret = pfl->status;
-            DPRINTF("%s: status %" PRIx64 "\n", __func__, ret);
+            trace_pflash_status(ret);
             break;
         }
         /* Flash area read */
@@ -362,7 +353,7 @@ static uint64_t pflash_read(void *opaque, hwaddr offset, 
unsigned int width)
         default:
             ret = pflash_data_read(pfl, offset, width);
         }
-        DPRINTF("%s: ID " TARGET_FMT_plx " %" PRIx64 "\n", __func__, boff, 
ret);
+        trace_pflash_flash_id(boff, ret);
         break;
     case 0x10: /* Chip Erase */
     case 0x30: /* Sector Erase */
@@ -374,7 +365,7 @@ static uint64_t pflash_read(void *opaque, hwaddr offset, 
unsigned int width)
         toggle_dq6(pfl);
         /* Status register read */
         ret = pfl->status;
-        DPRINTF("%s: status %" PRIx64 "\n", __func__, ret);
+        trace_pflash_status(ret);
         break;
     case 0x98:
         /* CFI query mode */
@@ -414,9 +405,7 @@ static void pflash_sector_erase(PFlashCFI02 *pfl, hwaddr 
offset)
     SectorInfo sector_info = pflash_sector_info(pfl, offset);
     uint64_t sector_len = sector_info.len;
     offset &= ~(sector_len - 1);
-    DPRINTF("%s: start sector erase at %0*" PRIx64 "-%0*" PRIx64 "\n",
-            __func__, pfl->width * 2, offset,
-            pfl->width * 2, offset + sector_len - 1);
+    trace_pflash_sector_erase_start(offset, offset + sector_len - 1);
     if (!pfl->ro) {
         uint8_t *p = pfl->storage;
         memset(p + offset, 0xff, sector_len);
@@ -495,27 +484,24 @@ static void pflash_write(void *opaque, hwaddr offset, 
uint64_t value,
             return;
         }
         if (boff != pfl->unlock_addr0 || cmd != 0xAA) {
-            DPRINTF("%s: unlock0 failed " TARGET_FMT_plx " %02x %04x\n",
-                    __func__, boff, cmd, pfl->unlock_addr0);
+            trace_pflash_unlock0_failed(boff, cmd, pfl->unlock_addr0);
             goto reset_flash;
         }
-        DPRINTF("%s: unlock sequence started\n", __func__);
+        trace_pflash_unlock_sequence_started();
         break;
     case 1:
         /* We started an unlock sequence */
     check_unlock1:
         if (boff != pfl->unlock_addr1 || cmd != 0x55) {
-            DPRINTF("%s: unlock1 failed " TARGET_FMT_plx " %02x\n", __func__,
-                    boff, cmd);
+            trace_pflash_unlock1_failed(boff, cmd, pfl->unlock_addr1);
             goto reset_flash;
         }
-        DPRINTF("%s: unlock sequence done\n", __func__);
+        trace_pflash_unlock_sequence_done();
         break;
     case 2:
         /* We finished an unlock sequence */
         if (!pfl->bypass && boff != pfl->unlock_addr0) {
-            DPRINTF("%s: command failed " TARGET_FMT_plx " %02x\n", __func__,
-                    boff, cmd);
+            trace_pflash_command_failed(boff, cmd);
             goto reset_flash;
         }
         switch (cmd) {
@@ -526,10 +512,10 @@ static void pflash_write(void *opaque, hwaddr offset, 
uint64_t value,
         case 0x90: /* Autoselect */
         case 0xA0: /* Program */
             pfl->cmd = cmd;
-            DPRINTF("%s: starting command %02x\n", __func__, cmd);
+            trace_pflash_command_starting(cmd);
             break;
         default:
-            DPRINTF("%s: unknown command %02x\n", __func__, cmd);
+            trace_pflash_command_unknown(cmd);
             goto reset_flash;
         }
         break;
@@ -585,8 +571,7 @@ static void pflash_write(void *opaque, hwaddr offset, 
uint64_t value,
             }
             /* fall through */
         default:
-            DPRINTF("%s: invalid write for command %02x\n",
-                    __func__, pfl->cmd);
+            trace_pflash_invalid_write_state(pfl->cmd, 3);
             goto reset_flash;
         }
     case 4:
@@ -599,8 +584,7 @@ static void pflash_write(void *opaque, hwaddr offset, 
uint64_t value,
             goto check_unlock1;
         default:
             /* Should never happen */
-            DPRINTF("%s: invalid command state %02x (wc 4)\n",
-                    __func__, pfl->cmd);
+            trace_pflash_invalid_command_state(pfl->cmd, 4);
             goto reset_flash;
         }
         break;
@@ -612,12 +596,11 @@ static void pflash_write(void *opaque, hwaddr offset, 
uint64_t value,
         switch (cmd) {
         case 0x10: /* Chip Erase */
             if (boff != pfl->unlock_addr0) {
-                DPRINTF("%s: chip erase: invalid address " TARGET_FMT_plx "\n",
-                        __func__, offset);
+                trace_pflash_invalid_erase_adddress(offset);
                 goto reset_flash;
             }
             /* Chip erase */
-            DPRINTF("%s: start chip erase\n", __func__);
+            trace_pflash_chip_erase_start();
             if (!pfl->ro) {
                 memset(pfl->storage, 0xff, pfl->chip_len);
                 pflash_update(pfl, 0, pfl->chip_len);
@@ -631,7 +614,7 @@ static void pflash_write(void *opaque, hwaddr offset, 
uint64_t value,
             pflash_sector_erase(pfl, offset);
             break;
         default:
-            DPRINTF("%s: invalid command %02x (wc 5)\n", __func__, cmd);
+            trace_pflash_invalid_command_state(pfl->cmd, 5);
             goto reset_flash;
         }
         pfl->cmd = cmd;
@@ -682,19 +665,18 @@ static void pflash_write(void *opaque, hwaddr offset, 
uint64_t value,
             return;
         default:
             /* Should never happen */
-            DPRINTF("%s: invalid command state %02x (wc 6)\n",
-                    __func__, pfl->cmd);
+            trace_pflash_invalid_command_state(pfl->cmd, 6);
             goto reset_flash;
         }
         break;
     /* Special values for CFI queries */
     case WCYCLE_CFI:
     case WCYCLE_AUTOSELECT_CFI:
-        DPRINTF("%s: invalid write in CFI query mode\n", __func__);
+        trace_pflash_invalid_write_query();
         goto reset_flash;
     default:
         /* Should never happen */
-        DPRINTF("%s: invalid write state (wc 7)\n",  __func__);
+        trace_pflash_invalid_write_state(pfl->cmd, pfl->wcycle);
         goto reset_flash;
     }
     pfl->wcycle++;
diff --git a/hw/block/trace-events b/hw/block/trace-events
index aca54bda14..46885c2047 100644
--- a/hw/block/trace-events
+++ b/hw/block/trace-events
@@ -15,6 +15,24 @@ pflash_data_write(uint64_t offset, unsigned size, uint32_t 
value, uint64_t count
 pflash_manufacturer_id(uint16_t id) "Read Manufacturer ID: 0x%04x"
 pflash_device_id(uint16_t id) "Read Device ID: 0x%04x"
 pflash_device_info(uint64_t offset) "Read Device Information 
offset:0x%04"PRIx64
+pflash_sector_erase_timeout(int sectors) "sector erase timeout fired; erasing 
%d sectors"
+pflash_sector_erase_complete(void) "sector erase complete"
+pflash_unknown_command_state(uint8_t cmd) "unknown command state: 0x%02x"
+pflash_status(uint64_t status) "status 0x%" PRIx64
+pflash_flash_id(uint64_t boff, uint64_t id) "ID 0x%" PRIx64 " 0x%" PRIx64
+pflash_sector_erase_start(uint64_t start, uint64_t end) "start sector erase at 
0x%"PRIx64"-0x%"PRIx64
+pflash_unlock0_failed(uint64_t addr, uint8_t cmd, uint16_t expected) "unlock0 
failed 0x%" PRIx64 " %02x %04x"
+pflash_unlock_sequence_started(void) "unlock sequence started"
+pflash_unlock1_failed(uint64_t addr, uint8_t cmd, uint16_t expected) "unlock0 
failed 0x%" PRIx64 " %02x %04x"
+pflash_unlock_sequence_done(void) "unlock sequence done"
+pflash_command_failed(uint64_t addr, uint8_t cmd) "command failed addr 0x%" 
PRIx64 " cmd 0x%02x"
+pflash_command_starting(uint8_t cmd) "starting command 0x%02x"
+pflash_command_unknown(uint8_t cmd) "unknown command 0x%02x"
+pflash_invalid_write_state(uint8_t cmd, int state) "invalid write for command 
0x%02x (wc %d)"
+pflash_invalid_command_state(uint8_t cmd, int state) "invalid command state 
0x%02x (wc %d)"
+pflash_invalid_erase_adddress(uint64_t addr) "chip erase: invalid address 0x%" 
PRIx64
+pflash_chip_erase_start(void) "start chip erase"
+pflash_invalid_write_query(void) "invalid write in CFI query mode"
 
 # virtio-blk.c
 virtio_blk_req_complete(void *vdev, void *req, int status) "vdev %p req %p 
status %d"
-- 
2.17.1