IDE: replace printfs with tracing

Out with the old, in with the new.

Signed-off-by John Snow <[email protected]>

---

 hw/ide/piix.c             | 11 ++++----
 hw/ide/trace-events       | 33 ++++++++++++++++++++++++
 hw/ide/via.c              | 10 +++-----

+++ b/hw/ide/cmd646.c

hw/ide/cmd646.c +1 -0

@@ -32,6 +32,7 @@
 #include "sysemu/dma.h"
 
 #include "hw/ide/pci.h"
+#include "trace.h"
 
 /* CMD646 specific */
 #define CFR		0x50

+# hw/ide/cmd646.c

Quoted 8 lines · John Snow

Out with the old, in with the new.

Signed-off-by John Snow <[email protected]>

---

 hw/ide/piix.c             | 11 ++++----
 hw/ide/trace-events       | 33 ++++++++++++++++++++++++
 hw/ide/via.c              | 10 +++-----

Hmm - should we tweak scripts/git.orderfile to prioritize trace-events over .c files? Then again, right now it prioritizes all .c files before anything that didn't match, so that things like trace-events will at least avoid falling in the middle of a patch if you use the project's orderfile.

Quoted 7 lines

+++ b/hw/ide/cmd646.c

hw/ide/cmd646.c +1 -0

@@ -32,6 +32,7 @@
 #include "sysemu/dma.h"
 
 #include "hw/ide/pci.h"
+#include "trace.h"
 

hw/ide/cmd646.c static uint64_t bmdma_read(void *opaque, hwaddr addr, · line 200

Quoted 9 lines

hw/ide/cmd646.c +0 -3

 /* CMD646 specific */
 #define CFR		0x50

@@ -195,9 +196,8 @@ static uint64_t bmdma_read(void *opaque, hwaddr addr,
         val = 0xff;
         break;
     }
-#ifdef DEBUG_IDE
-    printf("bmdma: readb " TARGET_FMT_plx " : 0x%02x\n", addr, val);
-#endif

Yay for killing code prone to bitrot.

hw/ide/core.c void ide_exec_cmd(IDEBus *bus, uint32_t val) · line 2047

Quoted 8 lines

hw/ide/core.c +2 -1

+++ b/hw/ide/core.c
 

@@ -2054,18 +2044,18 @@ void ide_exec_cmd(IDEBus *bus, uint32_t val)
     }
 
     hob = 0;
-    switch(addr) {
+    switch(reg_num) {

Worth fixing the style to put space after switch while touching this?

Quoted 5 lines

hw/ide/trace-events new file +4 -0

+++ b/hw/ide/trace-events

@@ -0,0 +1,33 @@
+# See docs/devel/tracing.txt for syntax documentation.
+
+# hw/ide/core.c

hw/ide/trace-events line 18

Quoted 3 lines

hw/ide/trace-events new file +3 -0

+
+# hw/ide/pci.c
+bmdma_reset(void) ""

An empty trace? Do all the backends support it?

hw/ide/trace-events line 27

Quoted 1 line

hw/ide/trace-events new file +1 -0

+# hw/ide/cmd646.c

Worth sorting the sections by filename?

Whether or not you tweak based on my nits,

Reviewed-by Eric Blake <[email protected]>

Quoted 8 lines · John Snow

Out with the old, in with the new.

Signed-off-by John Snow <[email protected]>

---

  hw/ide/piix.c             | 11 ++++----
  hw/ide/trace-events       | 33 ++++++++++++++++++++++++
  hw/ide/via.c              | 10 +++-----

Hmm - should we tweak scripts/git.orderfile to prioritize trace-events over .c files? Then again, right now it prioritizes all .c files before anything that didn't match, so that things like trace-events will at least avoid falling in the middle of a patch if you use the project's orderfile.

Quoted 8 lines · John Snow

Out with the old, in with the new.

Signed-off-by John Snow <[email protected]>

---

 hw/ide/piix.c             | 11 ++++----
 hw/ide/trace-events       | 33 ++++++++++++++++++++++++
 hw/ide/via.c              | 10 +++-----

Hmm - should we tweak scripts/git.orderfile to prioritize trace-events over .c files? Then again, right now it prioritizes all .c files before anything that didn't match, so that things like trace-events will at least avoid falling in the middle of a patch if you use the project's orderfile.

Quoted 10 lines

+++ b/hw/ide/cmd646.c

hw/ide/cmd646.c +1 -0

@@ -32,6 +32,7 @@
 #include "sysemu/dma.h"
 
 #include "hw/ide/pci.h"
+#include "trace.h"
 
 /* CMD646 specific */
 #define CFR		0x50

hw/ide/cmd646.c static uint64_t bmdma_read(void *opaque, hwaddr addr, · line 200

Quoted 6 lines

hw/ide/cmd646.c +0 -3

@@ -195,9 +196,8 @@ static uint64_t bmdma_read(void *opaque, hwaddr addr,
         val = 0xff;
         break;
     }
-#ifdef DEBUG_IDE
-    printf("bmdma: readb " TARGET_FMT_plx " : 0x%02x\n", addr, val);
-#endif

Yay for killing code prone to bitrot.

hw/ide/core.c void ide_exec_cmd(IDEBus *bus, uint32_t val) · line 2047

Quoted 8 lines

hw/ide/core.c +2 -1

+++ b/hw/ide/core.c
 

@@ -2054,18 +2044,18 @@ void ide_exec_cmd(IDEBus *bus, uint32_t val)
     }
 
     hob = 0;
-    switch(addr) {
+    switch(reg_num) {

Worth fixing the style to put space after switch while touching this?

Quoted 5 lines

hw/ide/trace-events new file +4 -0

+++ b/hw/ide/trace-events

@@ -0,0 +1,33 @@
+# See docs/devel/tracing.txt for syntax documentation.
+
+# hw/ide/core.c

hw/ide/trace-events line 18

Quoted 3 lines

hw/ide/trace-events new file +3 -0

+
+# hw/ide/pci.c
+bmdma_reset(void) ""

An empty trace? Do all the backends support it?

Out with the old, in with the new.

Signed-off-by John Snow <[email protected]>

---
  Makefile.objs             |  1 +
  hw/ide/cmd646.c           | 10 +++-----
  hw/ide/core.c             | 65 +++++++++++++++++++----------------------------
  hw/ide/pci.c              | 17 ++++---------
  hw/ide/piix.c             | 11 ++++----
  hw/ide/trace-events       | 33 ++++++++++++++++++++++++
  hw/ide/via.c              | 10 +++-----
  include/hw/ide/internal.h |  1 -
  8 files changed, 78 insertions(+), 70 deletions(-)

create mode 100644 hw/ide/trace-events

Makefile.objs +1 -0

index 24a4ea0..967c092 100644
@@ -153,6 +153,7 @@ trace-events-subdirs += hw/acpi
  trace-events-subdirs += hw/arm
  trace-events-subdirs += hw/alpha
  trace-events-subdirs += hw/xen
+trace-events-subdirs += hw/ide
  trace-events-subdirs += ui
  trace-events-subdirs += audio
  trace-events-subdirs += net

hw/ide/cmd646.c +4 -6

index 9ebb8d4..86b2a8f 100644
@@ -32,6 +32,7 @@
  #include "sysemu/dma.h"
 
  #include "hw/ide/pci.h"
+#include "trace.h"
 
  /* CMD646 specific */
  #define CFR		0x50

@@ -195,9 +196,8 @@ static uint64_t bmdma_read(void *opaque, hwaddr addr,
          val = 0xff;
          break;
      }
-#ifdef DEBUG_IDE
-    printf("bmdma: readb " TARGET_FMT_plx " : 0x%02x\n", addr, val);
-#endif
+
+    trace_bmdma_read_cmd646(addr, val);
      return val;
  }
 

@@ -211,9 +211,7 @@ static void bmdma_write(void *opaque, hwaddr addr,
          return;
      }
 
-#ifdef DEBUG_IDE
-    printf("bmdma: writeb " TARGET_FMT_plx " : 0x%" PRIx64 "\n", addr, val);
-#endif
+    trace_bmdma_write_cmd646(addr, val);
      switch(addr & 3) {
      case 0:
          bmdma_cmd_writeb(bm, val);

hw/ide/core.c +26 -39

index 0b48b64..53fa084 100644
@@ -36,6 +36,7 @@
  #include "qemu/cutils.h"
 
  #include "hw/ide/internal.h"
+#include "trace.h"
 
  /* These values were based on a Seagate ST3500418AS but have been modified
     to make more sense in QEMU */

@@ -656,10 +657,7 @@ void ide_cancel_dma_sync(IDEState *s)
       * write requests) pending and we can avoid to drain. */
      QLIST_FOREACH(req, &s->buffered_requests, list) {
          if (!req->orphaned) {
-#ifdef DEBUG_IDE
-            printf("%s: invoking cb %p of buffered request %p with"
-                   " -ECANCELED\n", __func__, req->original_cb, req);
-#endif
+            trace_ide_cancel_dma_sync_buffered(req->original_cb, req);
              req->original_cb(req->original_opaque, -ECANCELED);
          }
          req->orphaned = true;

@@ -678,9 +676,7 @@ void ide_cancel_dma_sync(IDEState *s)
       * aio operation with preadv/pwritev.
       */
      if (s->bus->dma->aiocb) {
-#ifdef DEBUG_IDE
-        printf("%s: draining all remaining requests", __func__);
-#endif
+        trace_ide_cancel_dma_sync_remaining();
          blk_drain(s->blk);
          assert(s->bus->dma->aiocb == NULL);
      }

@@ -741,9 +737,7 @@ static void ide_sector_read(IDEState *s)
          n = s->req_nb_sectors;
      }
 
-#if defined(DEBUG_IDE)
-    printf("sector=%" PRId64 "\n", sector_num);
-#endif
+    trace_ide_sector_read(sector_num, n);
 
      if (!ide_sect_range_ok(s, sector_num, n)) {
          ide_rw_error(s);

@@ -1005,14 +999,14 @@ static void ide_sector_write(IDEState *s)
 
      s->status = READY_STAT | SEEK_STAT | BUSY_STAT;
      sector_num = ide_get_sector(s);
-#if defined(DEBUG_IDE)
-    printf("sector=%" PRId64 "\n", sector_num);
-#endif
+
      n = s->nsector;
      if (n > s->req_nb_sectors) {
          n = s->req_nb_sectors;
      }
 
+    trace_ide_sector_write(sector_num, n);
+
      if (!ide_sect_range_ok(s, sector_num, n)) {
          ide_rw_error(s);
          block_acct_invalid(blk_get_stats(s->blk), BLOCK_ACCT_WRITE);

@@ -1186,18 +1180,17 @@ static void ide_clear_hob(IDEBus *bus)
  void ide_ioport_write(void *opaque, uint32_t addr, uint32_t val)
  {
      IDEBus *bus = opaque;
+    IDEState *s = idebus_active_if(bus);
+    int reg_num = addr & 7;
 
-#ifdef DEBUG_IDE
-    printf("IDE: write addr=0x%x val=0x%02x\n", addr, val);
-#endif
-
-    addr &= 7;
+    trace_ide_ioport_write(addr, val, bus, s);
 
      /* ignore writes to command block while busy with previous command */
-    if (addr != 7 && (idebus_active_if(bus)->status & (BUSY_STAT|DRQ_STAT)))
+    if (reg_num != 7 && (s->status & (BUSY_STAT|DRQ_STAT))) {
          return;
+    }
 
-    switch(addr) {
+    switch(reg_num) {
      case 0:
          break;
      case 1:

@@ -1253,9 +1246,7 @@ void ide_ioport_write(void *opaque, uint32_t addr, uint32_t val)
 
  static void ide_reset(IDEState *s)
  {
-#ifdef DEBUG_IDE
-    printf("ide: reset\n");
-#endif
+    trace_ide_reset(s);
 
      if (s->pio_aiocb) {
          blk_aio_cancel(s->pio_aiocb);

@@ -2013,10 +2004,9 @@ void ide_exec_cmd(IDEBus *bus, uint32_t val)
      IDEState *s;
      bool complete;
 
-#if defined(DEBUG_IDE)
-    printf("ide: CMD=%02x\n", val);
-#endif
      s = idebus_active_if(bus);
+    trace_ide_exec_cmd(bus, s, val);
+
      /* ignore commands to non existent slave */
      if (s != bus->ifs && !s->blk) {
          return;

@@ -2054,18 +2044,18 @@ void ide_exec_cmd(IDEBus *bus, uint32_t val)
      }
  }
 
-uint32_t ide_ioport_read(void *opaque, uint32_t addr1)
+uint32_t ide_ioport_read(void *opaque, uint32_t addr)
  {
      IDEBus *bus = opaque;
      IDEState *s = idebus_active_if(bus);
-    uint32_t addr;
+    uint32_t reg_num;
      int ret, hob;
 
-    addr = addr1 & 7;
+    reg_num = addr & 7;
      /* FIXME: HOB readback uses bit 7, but it's always set right now */
      //hob = s->select & (1 << 7);
      hob = 0;
-    switch(addr) {
+    switch(reg_num) {
      case 0:
          ret = 0xff;
          break;

@@ -2133,9 +2123,8 @@ uint32_t ide_ioport_read(void *opaque, uint32_t addr1)
          qemu_irq_lower(bus->irq);
          break;
      }
-#ifdef DEBUG_IDE
-    printf("ide: read addr=0x%x val=%02x\n", addr1, ret);
-#endif
+
+    trace_ide_ioport_read(addr, ret, bus, s);
      return ret;
  }
 

@@ -2151,9 +2140,8 @@ uint32_t ide_status_read(void *opaque, uint32_t addr)
      } else {
          ret = s->status;
      }
-#ifdef DEBUG_IDE
-    printf("ide: read status addr=0x%x val=%02x\n", addr, ret);
-#endif
+
+    trace_ide_status_read(addr, ret, bus, s);
      return ret;
  }
 

@@ -2163,9 +2151,8 @@ void ide_cmd_write(void *opaque, uint32_t addr, uint32_t val)
      IDEState *s;
      int i;
 
-#ifdef DEBUG_IDE
-    printf("ide: write control addr=0x%x val=%02x\n", addr, val);
-#endif
+    trace_ide_cmd_write(addr, val, bus);
+
      /* common for both drives */
      if (!(bus->cmd & IDE_CMD_RESET) &&
          (val & IDE_CMD_RESET)) {

hw/ide/pci.c +5 -12

index 3cfb510..f2dcc0e 100644
@@ -31,6 +31,7 @@
  #include "sysemu/dma.h"
  #include "qemu/error-report.h"
  #include "hw/ide/pci.h"
+#include "trace.h"
 
  #define BMDMA_PAGE_SIZE 4096
 

@@ -196,9 +197,7 @@ static void bmdma_reset(IDEDMA *dma)
  {
      BMDMAState *bm = DO_UPCAST(BMDMAState, dma, dma);
 
-#ifdef DEBUG_IDE
-    printf("ide: dma_reset\n");
-#endif
+    trace_bmdma_reset();
      bmdma_cancel(bm);
      bm->cmd = 0;
      bm->status = 0;

@@ -227,9 +226,7 @@ static void bmdma_irq(void *opaque, int n, int level)
 
  void bmdma_cmd_writeb(BMDMAState *bm, uint32_t val)
  {
-#ifdef DEBUG_IDE
-    printf("%s: 0x%08x\n", __func__, val);
-#endif
+    trace_bmdma_cmd_writeb(val);
 
      /* Ignore writes to SSBM if it keeps the old value */
      if ((val & BM_CMD_START) != (bm->cmd & BM_CMD_START)) {

@@ -258,9 +255,7 @@ static uint64_t bmdma_addr_read(void *opaque, hwaddr addr,
      uint64_t data;
 
      data = (bm->addr >> (addr * 8)) & mask;
-#ifdef DEBUG_IDE
-    printf("%s: 0x%08x\n", __func__, (unsigned)data);
-#endif
+    trace_bmdma_addr_read(data);
      return data;
  }
 

@@ -271,9 +266,7 @@ static void bmdma_addr_write(void *opaque, hwaddr addr,
      int shift = addr * 8;
      uint32_t mask = (1ULL << (width * 8)) - 1;
 
-#ifdef DEBUG_IDE
-    printf("%s: 0x%08x\n", __func__, (unsigned)data);
-#endif
+    trace_bmdma_addr_write(data);
      bm->addr &= ~(mask << shift);
      bm->addr |= ((data & mask) << shift) & ~3;
  }

hw/ide/piix.c +5 -6

index 7e2d767..dfb21f6 100644
@@ -33,6 +33,7 @@
  #include "sysemu/dma.h"
 
  #include "hw/ide/pci.h"
+#include "trace.h"
 
  static uint64_t bmdma_read(void *opaque, hwaddr addr, unsigned size)
  {

@@ -54,9 +55,8 @@ static uint64_t bmdma_read(void *opaque, hwaddr addr, unsigned size)
          val = 0xff;
          break;
      }
-#ifdef DEBUG_IDE
-    printf("bmdma: readb 0x%02x : 0x%02x\n", (uint8_t)addr, val);
-#endif
+
+    trace_bmdma_read(addr, val);
      return val;
  }
 

@@ -69,9 +69,8 @@ static void bmdma_write(void *opaque, hwaddr addr,
          return;
      }
 
-#ifdef DEBUG_IDE
-    printf("bmdma: writeb 0x%02x : 0x%02x\n", (uint8_t)addr, (uint8_t)val);
-#endif
+    trace_bmdma_write(addr, val);
+
      switch(addr & 3) {
      case 0:
          bmdma_cmd_writeb(bm, val);

hw/ide/trace-events new file +0 -0

new file mode 100644
index 0000000..68ad96a

hw/ide/via.c +4 -6

index 5b32ecb..35c3059 100644
@@ -33,6 +33,7 @@
  #include "sysemu/dma.h"
 
  #include "hw/ide/pci.h"
+#include "trace.h"
 
  static uint64_t bmdma_read(void *opaque, hwaddr addr,
                             unsigned size)

@@ -55,9 +56,8 @@ static uint64_t bmdma_read(void *opaque, hwaddr addr,
          val = 0xff;
          break;
      }
-#ifdef DEBUG_IDE
-    printf("bmdma: readb 0x%02x : 0x%02x\n", addr, val);
-#endif
+
+    trace_bmdma_read_via(addr, val);
      return val;
  }
 

@@ -70,9 +70,7 @@ static void bmdma_write(void *opaque, hwaddr addr,
          return;
      }
 
-#ifdef DEBUG_IDE
-    printf("bmdma: writeb 0x%02x : 0x%02x\n", addr, val);
-#endif
+    trace_bmdma_write_via(addr, val);
      switch (addr & 3) {
      case 0:
          bmdma_cmd_writeb(bm, val);

include/hw/ide/internal.h +0 -0

index 482a951..4a92f0a 100644

Hi John,

Quoted 317 lines · John Snow

Out with the old, in with the new.

Signed-off-by John Snow <[email protected]>

---
  Makefile.objs             |  1 +
  hw/ide/cmd646.c           | 10 +++-----
  hw/ide/core.c             | 65
+++++++++++++++++++----------------------------
  hw/ide/pci.c              | 17 ++++---------
  hw/ide/piix.c             | 11 ++++----
  hw/ide/trace-events       | 33 ++++++++++++++++++++++++
  hw/ide/via.c              | 10 +++-----
  include/hw/ide/internal.h |  1 -
  8 files changed, 78 insertions(+), 70 deletions(-)

create mode 100644 hw/ide/trace-events

Makefile.objs +1 -0

index 24a4ea0..967c092 100644
@@ -153,6 +153,7 @@ trace-events-subdirs += hw/acpi
  trace-events-subdirs += hw/arm
  trace-events-subdirs += hw/alpha
  trace-events-subdirs += hw/xen
+trace-events-subdirs += hw/ide
  trace-events-subdirs += ui
  trace-events-subdirs += audio
  trace-events-subdirs += net

hw/ide/cmd646.c +3 -3

index 9ebb8d4..86b2a8f 100644
@@ -32,6 +32,7 @@
  #include "sysemu/dma.h"
    #include "hw/ide/pci.h"
+#include "trace.h"
    /* CMD646 specific */
  #define CFR        0x50

@@ -195,9 +196,8 @@ static uint64_t bmdma_read(void *opaque, hwaddr addr,
          val = 0xff;
          break;
      }
-#ifdef DEBUG_IDE
-    printf("bmdma: readb " TARGET_FMT_plx " : 0x%02x\n", addr, val);
-#endif
+
+    trace_bmdma_read_cmd646(addr, val);
      return val;
  }
  @@ -211,9 +211,7 @@ static void bmdma_write(void *opaque, hwaddr addr,

          return;
      }

-#ifdef DEBUG_IDE
- printf("bmdma: writeb " TARGET_FMT_plx " : 0x%" PRIx64 "\n",
addr, val);

hw/ide/cmd646.c +1 -1

-#endif
+    trace_bmdma_write_cmd646(addr, val);
      switch(addr & 3) {
      case 0:
          bmdma_cmd_writeb(bm, val);

hw/ide/core.c +1 -0

index 0b48b64..53fa084 100644
@@ -36,6 +36,7 @@
  #include "qemu/cutils.h"
    #include "hw/ide/internal.h"
+#include "trace.h"
    /* These values were based on a Seagate ST3500418AS but have been

modified
to make more sense in QEMU */

hw/ide/core.c +8 -16

@@ -656,10 +657,7 @@ void ide_cancel_dma_sync(IDEState *s)
       * write requests) pending and we can avoid to drain. */
      QLIST_FOREACH(req, &s->buffered_requests, list) {
          if (!req->orphaned) {
-#ifdef DEBUG_IDE
-            printf("%s: invoking cb %p of buffered request %p with"
-                   " -ECANCELED\n", __func__, req->original_cb, req);
-#endif
+            trace_ide_cancel_dma_sync_buffered(req->original_cb, req);
              req->original_cb(req->original_opaque, -ECANCELED);
          }
          req->orphaned = true;

@@ -678,9 +676,7 @@ void ide_cancel_dma_sync(IDEState *s)
       * aio operation with preadv/pwritev.
       */
      if (s->bus->dma->aiocb) {
-#ifdef DEBUG_IDE
-        printf("%s: draining all remaining requests", __func__);
-#endif
+        trace_ide_cancel_dma_sync_remaining();
          blk_drain(s->blk);
          assert(s->bus->dma->aiocb == NULL);
      }

@@ -741,9 +737,7 @@ static void ide_sector_read(IDEState *s)
          n = s->req_nb_sectors;
      }
  -#if defined(DEBUG_IDE)
-    printf("sector=%" PRId64 "\n", sector_num);
-#endif
+    trace_ide_sector_read(sector_num, n);
        if (!ide_sect_range_ok(s, sector_num, n)) {
          ide_rw_error(s);

@@ -1005,14 +999,14 @@ static void ide_sector_write(IDEState *s)
        s->status = READY_STAT | SEEK_STAT | BUSY_STAT;
      sector_num = ide_get_sector(s);
-#if defined(DEBUG_IDE)
-    printf("sector=%" PRId64 "\n", sector_num);
-#endif
+
      n = s->nsector;
      if (n > s->req_nb_sectors) {
          n = s->req_nb_sectors;
      }
  +    trace_ide_sector_write(sector_num, n);
+
      if (!ide_sect_range_ok(s, sector_num, n)) {
          ide_rw_error(s);
          block_acct_invalid(blk_get_stats(s->blk), BLOCK_ACCT_WRITE);

@@ -1186,18 +1180,17 @@ static void ide_clear_hob(IDEBus *bus)
  void ide_ioport_write(void *opaque, uint32_t addr, uint32_t val)
  {
      IDEBus *bus = opaque;
+    IDEState *s = idebus_active_if(bus);
+    int reg_num = addr & 7;
  -#ifdef DEBUG_IDE
-    printf("IDE: write addr=0x%x val=0x%02x\n", addr, val);
-#endif
-
-    addr &= 7;
+    trace_ide_ioport_write(addr, val, bus, s);
        /* ignore writes to command block while busy with previous

command */
- if (addr != 7 && (idebus_active_if(bus)->status &
(BUSY_STAT|DRQ_STAT)))

hw/ide/core.c +12 -10

+    if (reg_num != 7 && (s->status & (BUSY_STAT|DRQ_STAT))) {
          return;
+    }
  -    switch(addr) {
+    switch(reg_num) {
      case 0:
          break;
      case 1:

@@ -1253,9 +1246,7 @@ void ide_ioport_write(void *opaque, uint32_t
 addr, uint32_t val)
    static void ide_reset(IDEState *s)
  {
-#ifdef DEBUG_IDE
-    printf("ide: reset\n");
-#endif
+    trace_ide_reset(s);
        if (s->pio_aiocb) {
          blk_aio_cancel(s->pio_aiocb);

@@ -2013,10 +2004,9 @@ void ide_exec_cmd(IDEBus *bus, uint32_t val)
      IDEState *s;
      bool complete;
  -#if defined(DEBUG_IDE)
-    printf("ide: CMD=%02x\n", val);
-#endif
      s = idebus_active_if(bus);
+    trace_ide_exec_cmd(bus, s, val);
+
      /* ignore commands to non existent slave */
      if (s != bus->ifs && !s->blk) {
          return;

@@ -2054,18 +2044,18 @@ void ide_exec_cmd(IDEBus *bus, uint32_t val)
      }
  }
  -uint32_t ide_ioport_read(void *opaque, uint32_t addr1)
+uint32_t ide_ioport_read(void *opaque, uint32_t addr)
  {
      IDEBus *bus = opaque;
      IDEState *s = idebus_active_if(bus);
-    uint32_t addr;
+    uint32_t reg_num;
      int ret, hob;
  -    addr = addr1 & 7;
+    reg_num = addr & 7;
      /* FIXME: HOB readback uses bit 7, but it's always set right now */
      //hob = s->select & (1 << 7);
      hob = 0;
-    switch(addr) {
+    switch(reg_num) {
      case 0:
          ret = 0xff;
          break;

@@ -2133,9 +2123,8 @@ uint32_t ide_ioport_read(void *opaque, uint32_t
 addr1)
          qemu_irq_lower(bus->irq);
          break;
      }
-#ifdef DEBUG_IDE
-    printf("ide: read addr=0x%x val=%02x\n", addr1, ret);
-#endif
+
+    trace_ide_ioport_read(addr, ret, bus, s);
      return ret;
  }

@@ -2151,9 +2140,8 @@ uint32_t ide_status_read(void *opaque,
uint32_t addr)

      } else {
          ret = s->status;
      }

hw/ide/core.c +2 -3

-#ifdef DEBUG_IDE
-    printf("ide: read status addr=0x%x val=%02x\n", addr, ret);
-#endif
+
+    trace_ide_status_read(addr, ret, bus, s);
      return ret;
  }
  @@ -2163,9 +2151,8 @@ void ide_cmd_write(void *opaque, uint32_t

addr, uint32_t val)

      IDEState *s;
      int i;

-#ifdef DEBUG_IDE

hw/ide/core.c +2 -2

-    printf("ide: write control addr=0x%x val=%02x\n", addr, val);
-#endif
+    trace_ide_cmd_write(addr, val, bus);
+
      /* common for both drives */
      if (!(bus->cmd & IDE_CMD_RESET) &&
          (val & IDE_CMD_RESET)) {

hw/ide/pci.c +1 -0

index 3cfb510..f2dcc0e 100644
@@ -31,6 +31,7 @@
  #include "sysemu/dma.h"
  #include "qemu/error-report.h"
  #include "hw/ide/pci.h"
+#include "trace.h"
    #define BMDMA_PAGE_SIZE 4096
  @@ -196,9 +197,7 @@ static void bmdma_reset(IDEDMA *dma)
  {

      BMDMAState *bm = DO_UPCAST(BMDMAState, dma, dma);

-#ifdef DEBUG_IDE

hw/ide/pci.c +3 -8

-    printf("ide: dma_reset\n");
-#endif
+    trace_bmdma_reset();
      bmdma_cancel(bm);
      bm->cmd = 0;
      bm->status = 0;

@@ -227,9 +226,7 @@ static void bmdma_irq(void *opaque, int n, int level)
    void bmdma_cmd_writeb(BMDMAState *bm, uint32_t val)
  {
-#ifdef DEBUG_IDE
-    printf("%s: 0x%08x\n", __func__, val);
-#endif
+    trace_bmdma_cmd_writeb(val);
        /* Ignore writes to SSBM if it keeps the old value */
      if ((val & BM_CMD_START) != (bm->cmd & BM_CMD_START)) {

@@ -258,9 +255,7 @@ static uint64_t bmdma_addr_read(void *opaque,
 hwaddr addr,
      uint64_t data;
        data = (bm->addr >> (addr * 8)) & mask;
-#ifdef DEBUG_IDE
-    printf("%s: 0x%08x\n", __func__, (unsigned)data);
-#endif
+    trace_bmdma_addr_read(data);
      return data;
  }
  @@ -271,9 +266,7 @@ static void bmdma_addr_write(void *opaque,

hwaddr addr,

      int shift = addr * 8;
      uint32_t mask = (1ULL << (width * 8)) - 1;

-#ifdef DEBUG_IDE

hw/ide/pci.c +1 -2

-    printf("%s: 0x%08x\n", __func__, (unsigned)data);
-#endif
+    trace_bmdma_addr_write(data);
      bm->addr &= ~(mask << shift);
      bm->addr |= ((data & mask) << shift) & ~3;
  }

hw/ide/piix.c +3 -3

index 7e2d767..dfb21f6 100644
@@ -33,6 +33,7 @@
  #include "sysemu/dma.h"
    #include "hw/ide/pci.h"
+#include "trace.h"
    static uint64_t bmdma_read(void *opaque, hwaddr addr, unsigned size)
  {

@@ -54,9 +55,8 @@ static uint64_t bmdma_read(void *opaque, hwaddr
 addr, unsigned size)
          val = 0xff;
          break;
      }
-#ifdef DEBUG_IDE
-    printf("bmdma: readb 0x%02x : 0x%02x\n", (uint8_t)addr, val);
-#endif
+
+    trace_bmdma_read(addr, val);
      return val;
  }

@@ -69,9 +69,8 @@ static void bmdma_write(void *opaque, hwaddr addr,

          return;
      }

-#ifdef DEBUG_IDE
- printf("bmdma: writeb 0x%02x : 0x%02x\n", (uint8_t)addr,
(uint8_t)val);

hw/ide/piix.c +2 -1

-#endif
+    trace_bmdma_write(addr, val);
+
      switch(addr & 3) {
      case 0:
          bmdma_cmd_writeb(bm, val);

hw/ide/trace-events new file +5 -0

new file mode 100644
index 0000000..68ad96a
@@ -0,0 +1,33 @@
+# See docs/devel/tracing.txt for syntax documentation.
+
+# hw/ide/core.c
+# portio
+ide_ioport_read(uint32_t addr, uint32_t val, void *bus, void *s) 

Quoted 3 lines

"IDE PIO rd @ 0x%"PRIx32"; val 0x%02"PRIx32"; bus %p IDEState %p" +ide_ioport_write(uint32_t addr, uint32_t val, void *bus, void *s) "IDE PIO wr @ 0x%"PRIx32"; val 0x%02"PRIx32"; bus %p IDEState %p"

ide_ioport_access(char *access, uint32_t addr, uint32_t val, void *bus, void *s);

Quoted 13 lines

+ide_status_read(uint32_t addr, uint32_t val, void *bus, void
*s) "IDE PIO rd @ 0x%"PRIx32" (Alt Status); val
0x%02"PRIx32"; bus %p; IDEState %p" +ide_cmd_write(uint32_t addr, uint32_t val, void
*bus) "IDE PIO wr @ 0x%"PRIx32" (Device
Control); val 0x%02"PRIx32"; bus %p"

hw/ide/trace-events new file +2 -0

+# misc
+ide_exec_cmd(void *bus, void *state, uint32_t cmd) "IDE exec cmd: bus

%p; state %p; cmd 0x%02x" +ide_cancel_dma_sync_buffered(void *fn, void *req) "invoking cb %p of buffered request %p with -ECANCELED"

hw/ide/trace-events new file +2 -0

+ide_cancel_dma_sync_remaining(void) "draining all remaining requests"
+ide_sector_read(int64_t sector_num, int nsectors) "sector=%"PRId64"

Quoted 3 lines

nsectors=%d"
+ide_sector_write(int64_t sector_num, int nsectors) "sector=%"PRId64" nsectors=%d"

ide_sector_access(char *access, int64_t sector_num, int nsectors) "%s sector=%"PRId64" nsectors=%d"

hw/ide/trace-events line 21

Quoted 7 lines

hw/ide/trace-events new file +7 -0

+ide_reset(void *s) "IDEstate %p"
+
+# hw/ide/pci.c
+bmdma_reset(void) ""
+bmdma_cmd_writeb(uint32_t val) "val: 0x%08x"
+bmdma_addr_read(uint64_t data) "data: 0x%016"PRIx64
+bmdma_addr_write(uint64_t data) "data: 0x%016"PRIx64

bmdma_data_access(char *access, uint64_t data) "%s data: 0x%016"PRIx64

Quoted 6 lines

hw/ide/trace-events new file +3 -0

+
+# hw/ide/piix.c
+bmdma_read(uint64_t addr, uint8_t val) "bmdma: readb 0x%"PRIx64" :

0x%02x"
+bmdma_write(uint64_t addr, uint8_t val) "bmdma: writeb 0x%"PRIx64" :
0x%02x"

bmdma_io_access(char *access, uint64_t addr, uint64_t val) "bmdma: %sb 0x%"PRIx64" : 0x%02x"

Quoted 6 lines

hw/ide/trace-events new file +3 -0

+
+# hw/ide/cmd646.c
+bmdma_read_cmd646(uint64_t addr, uint32_t val) "bmdma: readb

0x%"PRIx64" : 0x%02x"
+bmdma_write_cmd646(uint64_t addr, uint64_t val) "bmdma: writeb 0x%"PRIx64" : 0x%02"PRIx64

use trace_bmdma_io_access()

Quoted 6 lines

hw/ide/trace-events new file +3 -0

+
+# hw/ide/via.c
+bmdma_read_via(uint64_t addr, uint32_t val) "bmdma: readb 0x%"PRIx64"

: 0x%02x"
+bmdma_write_via(uint64_t addr, uint64_t val) "bmdma: writeb 0x%"PRIx64" : 0x%02"PRIx64

use trace_bmdma_io_access()

Quoted 36 lines

hw/ide/via.c +3 -3

index 5b32ecb..35c3059 100644
@@ -33,6 +33,7 @@
  #include "sysemu/dma.h"
    #include "hw/ide/pci.h"
+#include "trace.h"
    static uint64_t bmdma_read(void *opaque, hwaddr addr,
                             unsigned size)

@@ -55,9 +56,8 @@ static uint64_t bmdma_read(void *opaque, hwaddr addr,
          val = 0xff;
          break;
      }
-#ifdef DEBUG_IDE
-    printf("bmdma: readb 0x%02x : 0x%02x\n", addr, val);
-#endif
+
+    trace_bmdma_read_via(addr, val);
      return val;
  }
  @@ -70,9 +70,7 @@ static void bmdma_write(void *opaque, hwaddr addr,

          return;
      }

-#ifdef DEBUG_IDE

hw/ide/via.c +1 -2

-    printf("bmdma: writeb 0x%02x : 0x%02x\n", addr, val);
-#endif
+    trace_bmdma_write_via(addr, val);
      switch (addr & 3) {
      case 0:
          bmdma_cmd_writeb(bm, val);

include/hw/ide/internal.h +0 -0

index 482a951..4a92f0a 100644

include/hw/ide/internal.h line 19

Quoted 7 lines

include/hw/ide/internal.h +0 -1

@@ -14,7 +14,6 @@
  #include "block/scsi.h"
    /* debug IDE devices */
-//#define DEBUG_IDE
  //#define DEBUG_IDE_ATAPI
  //#define DEBUG_AIO
  #define USE_DMA_CDROM
 

If you agree you can add:

Reviewed-by Philippe Mathieu-Daudé <[email protected]>

Regards,

Phil.

Name the registers for tracing purposes.

Signed-off-by John Snow <[email protected]>

---
  hw/ide/core.c       | 88 +++++++++++++++++++++++++++++++++++++++++------------
  hw/ide/trace-events |  4 +--
  2 files changed, 70 insertions(+), 22 deletions(-)

hw/ide/core.c +68 -20

index 53fa084..6235bdf 100644
@@ -1177,13 +1177,37 @@ static void ide_clear_hob(IDEBus *bus)
      bus->ifs[1].select &= ~(1 << 7);
  }
 
+/* IOport [W]rite [R]egisters */
+enum ATA_IOPORT_WR {
+    ATA_IOPORT_WR_DATA = 0,
+    ATA_IOPORT_WR_FEATURES = 1,
+    ATA_IOPORT_WR_SECTOR_COUNT = 2,
+    ATA_IOPORT_WR_SECTOR_NUMBER = 3,
+    ATA_IOPORT_WR_CYLINDER_LOW = 4,
+    ATA_IOPORT_WR_CYLINDER_HIGH = 5,
+    ATA_IOPORT_WR_DEVICE_HEAD = 6,
+    ATA_IOPORT_WR_COMMAND = 7,
+    ATA_IOPORT_WR_NUM_REGISTERS,
+};
+
+const char *ATA_IOPORT_WR_lookup[ATA_IOPORT_WR_NUM_REGISTERS] = {
+    [ATA_IOPORT_WR_DATA] = "Data",
+    [ATA_IOPORT_WR_FEATURES] = "Features",
+    [ATA_IOPORT_WR_SECTOR_COUNT] = "Sector Count",
+    [ATA_IOPORT_WR_SECTOR_NUMBER] = "Sector Number",
+    [ATA_IOPORT_WR_CYLINDER_LOW] = "Cylinder Low",
+    [ATA_IOPORT_WR_CYLINDER_HIGH] = "Cylinder High",
+    [ATA_IOPORT_WR_DEVICE_HEAD] = "Device/Head",
+    [ATA_IOPORT_WR_COMMAND] = "Command"
+};
+
  void ide_ioport_write(void *opaque, uint32_t addr, uint32_t val)
  {
      IDEBus *bus = opaque;
      IDEState *s = idebus_active_if(bus);
      int reg_num = addr & 7;
 
-    trace_ide_ioport_write(addr, val, bus, s);
+    trace_ide_ioport_write(addr, ATA_IOPORT_WR_lookup[reg_num], val, bus, s);
 
      /* ignore writes to command block while busy with previous command */
      if (reg_num != 7 && (s->status & (BUSY_STAT|DRQ_STAT))) {

@@ -1193,43 +1217,43 @@ void ide_ioport_write(void *opaque, uint32_t addr, uint32_t val)
      switch(reg_num) {
      case 0:
          break;
-    case 1:
-	ide_clear_hob(bus);
+    case ATA_IOPORT_WR_FEATURES:
+        ide_clear_hob(bus);
          /* NOTE: data is written to the two drives */
-	bus->ifs[0].hob_feature = bus->ifs[0].feature;
-	bus->ifs[1].hob_feature = bus->ifs[1].feature;
+        bus->ifs[0].hob_feature = bus->ifs[0].feature;
+        bus->ifs[1].hob_feature = bus->ifs[1].feature;
          bus->ifs[0].feature = val;
          bus->ifs[1].feature = val;
          break;
-    case 2:
+    case ATA_IOPORT_WR_SECTOR_COUNT:
  	ide_clear_hob(bus);
  	bus->ifs[0].hob_nsector = bus->ifs[0].nsector;
  	bus->ifs[1].hob_nsector = bus->ifs[1].nsector;
          bus->ifs[0].nsector = val;
          bus->ifs[1].nsector = val;
          break;
-    case 3:
+    case ATA_IOPORT_WR_SECTOR_NUMBER:
  	ide_clear_hob(bus);
  	bus->ifs[0].hob_sector = bus->ifs[0].sector;
  	bus->ifs[1].hob_sector = bus->ifs[1].sector;
          bus->ifs[0].sector = val;
          bus->ifs[1].sector = val;
          break;
-    case 4:
+    case ATA_IOPORT_WR_CYLINDER_LOW:
  	ide_clear_hob(bus);
  	bus->ifs[0].hob_lcyl = bus->ifs[0].lcyl;
  	bus->ifs[1].hob_lcyl = bus->ifs[1].lcyl;
          bus->ifs[0].lcyl = val;
          bus->ifs[1].lcyl = val;
          break;
-    case 5:
+    case ATA_IOPORT_WR_CYLINDER_HIGH:
  	ide_clear_hob(bus);
  	bus->ifs[0].hob_hcyl = bus->ifs[0].hcyl;
  	bus->ifs[1].hob_hcyl = bus->ifs[1].hcyl;
          bus->ifs[0].hcyl = val;
          bus->ifs[1].hcyl = val;
          break;
-    case 6:
+    case ATA_IOPORT_WR_DEVICE_HEAD:
  	/* FIXME: HOB readback uses bit 7 */
          bus->ifs[0].select = (val & ~0x10) | 0xa0;
          bus->ifs[1].select = (val | 0x10) | 0xa0;

@@ -1237,7 +1261,7 @@ void ide_ioport_write(void *opaque, uint32_t addr, uint32_t val)
          bus->unit = (val >> 4) & 1;
          break;
      default:
-    case 7:
+    case ATA_IOPORT_WR_COMMAND:
          /* command */
          ide_exec_cmd(bus, val);
          break;

@@ -2044,6 +2068,30 @@ void ide_exec_cmd(IDEBus *bus, uint32_t val)
      }
  }
 
+/* IOport [R]ead [R]egisters */
+enum ATA_IOPORT_RR {
+    ATA_IOPORT_RR_DATA = 0,
+    ATA_IOPORT_RR_ERROR = 1,
+    ATA_IOPORT_RR_SECTOR_COUNT = 2,
+    ATA_IOPORT_RR_SECTOR_NUMBER = 3,
+    ATA_IOPORT_RR_CYLINDER_LOW = 4,
+    ATA_IOPORT_RR_CYLINDER_HIGH = 5,
+    ATA_IOPORT_RR_DEVICE_HEAD = 6,
+    ATA_IOPORT_RR_STATUS = 7,
+    ATA_IOPORT_RR_NUM_REGISTERS,
+};
+
+const char *ATA_IOPORT_RR_lookup[ATA_IOPORT_RR_NUM_REGISTERS] = {
+    [ATA_IOPORT_RR_DATA] = "Data",
+    [ATA_IOPORT_RR_ERROR] = "Error",
+    [ATA_IOPORT_RR_SECTOR_COUNT] = "Sector Count",
+    [ATA_IOPORT_RR_SECTOR_NUMBER] = "Sector Number",
+    [ATA_IOPORT_RR_CYLINDER_LOW] = "Cylinder Low",
+    [ATA_IOPORT_RR_CYLINDER_HIGH] = "Cylinder High",
+    [ATA_IOPORT_RR_DEVICE_HEAD] = "Device/Head",
+    [ATA_IOPORT_RR_STATUS] = "Status"
+};
+
  uint32_t ide_ioport_read(void *opaque, uint32_t addr)
  {
      IDEBus *bus = opaque;

@@ -2056,10 +2104,10 @@ uint32_t ide_ioport_read(void *opaque, uint32_t addr)
      //hob = s->select & (1 << 7);
      hob = 0;
      switch(reg_num) {
-    case 0:
+    case ATA_IOPORT_RR_DATA:
          ret = 0xff;
          break;
-    case 1:
+    case ATA_IOPORT_RR_ERROR:
          if ((!bus->ifs[0].blk && !bus->ifs[1].blk) ||
              (s != bus->ifs && !s->blk)) {
              ret = 0;

@@ -2069,7 +2117,7 @@ uint32_t ide_ioport_read(void *opaque, uint32_t addr)
  	    ret = s->hob_feature;
          }
          break;
-    case 2:
+    case ATA_IOPORT_RR_SECTOR_COUNT:
          if (!bus->ifs[0].blk && !bus->ifs[1].blk) {
              ret = 0;
          } else if (!hob) {

@@ -2078,7 +2126,7 @@ uint32_t ide_ioport_read(void *opaque, uint32_t addr)
  	    ret = s->hob_nsector;
          }
          break;
-    case 3:
+    case ATA_IOPORT_RR_SECTOR_NUMBER:
          if (!bus->ifs[0].blk && !bus->ifs[1].blk) {
              ret = 0;
          } else if (!hob) {

@@ -2087,7 +2135,7 @@ uint32_t ide_ioport_read(void *opaque, uint32_t addr)
  	    ret = s->hob_sector;
          }
          break;
-    case 4:
+    case ATA_IOPORT_RR_CYLINDER_LOW:
          if (!bus->ifs[0].blk && !bus->ifs[1].blk) {
              ret = 0;
          } else if (!hob) {

@@ -2096,7 +2144,7 @@ uint32_t ide_ioport_read(void *opaque, uint32_t addr)
  	    ret = s->hob_lcyl;
          }
          break;
-    case 5:
+    case ATA_IOPORT_RR_CYLINDER_HIGH:
          if (!bus->ifs[0].blk && !bus->ifs[1].blk) {
              ret = 0;
          } else if (!hob) {

@@ -2105,7 +2153,7 @@ uint32_t ide_ioport_read(void *opaque, uint32_t addr)
  	    ret = s->hob_hcyl;
          }
          break;
-    case 6:
+    case ATA_IOPORT_RR_DEVICE_HEAD:
          if (!bus->ifs[0].blk && !bus->ifs[1].blk) {
              ret = 0;
          } else {

@@ -2113,7 +2161,7 @@ uint32_t ide_ioport_read(void *opaque, uint32_t addr)
          }
          break;
      default:
-    case 7:
+    case ATA_IOPORT_RR_STATUS:
          if ((!bus->ifs[0].blk && !bus->ifs[1].blk) ||
              (s != bus->ifs && !s->blk)) {
              ret = 0;

@@ -2124,7 +2172,7 @@ uint32_t ide_ioport_read(void *opaque, uint32_t addr)
          break;
      }
 
-    trace_ide_ioport_read(addr, ret, bus, s);
+    trace_ide_ioport_read(addr, ATA_IOPORT_RR_lookup[reg_num], ret, bus, s);
      return ret;
  }
 

hw/ide/trace-events +0 -0

index 68ad96a..6c156ac 100644

To be used sparingly, but still interesting in the case of small firmwares designed to reproduce bugs in QEMU IDE.

Signed-off-by John Snow <[email protected]>

---
 hw/ide/core.c | 12 +++++++++++-
 1 file changed, 11 insertions(+), 1 deletion(-)

hw/ide/core.c +0 -0

index 6235bdf..29848ff 100644

Quoted 16 lines · John Snow

To be used sparingly, but still interesting in the case of small firmwares designed to reproduce bugs in QEMU IDE.

Signed-off-by John Snow <[email protected]>

---
 hw/ide/core.c | 12 +++++++++++-
 1 file changed, 11 insertions(+), 1 deletion(-)

hw/ide/core.c +0 -0

index 6235bdf..29848ff 100644
@@ -2251,6 +2251,8 @@ void ide_data_writew(void *opaque, uint32_t addr, uint32_t val)
     IDEState *s = idebus_active_if(bus);
     uint8_t *p;
 

hw/ide/core.c void ide_data_writew(void *opaque, uint32_t addr, uint32_t val) · line 2254

Quoted 1 line

hw/ide/core.c +1 -0

+    trace_ide_data_writew(addr, val, bus, s);

Umm, where's the trace-events addition for this?

To be used sparingly, but still interesting in the case of small firmwares designed to reproduce bugs in QEMU IDE.

Signed-off-by John Snow <[email protected]>

---
 hw/ide/core.c | 12 +++++++++++-
 1 file changed, 11 insertions(+), 1 deletion(-)

Quoted 2 lines · John Snow

To be used sparingly, but still interesting in the case of small firmwares designed to reproduce bugs in QEMU IDE.

Is that because the trace would fire so frequently in normal usage that it will drown the user in noise?

Quoted 1 line

Quoted 5 lines

Signed-off-by John Snow <[email protected]>

---
 hw/ide/core.c | 12 +++++++++++-
 1 file changed, 11 insertions(+), 1 deletion(-)

Reviewed-by Eric Blake <[email protected]>

Quoted 2 lines · John Snow

To be used sparingly, but still interesting in the case of small firmwares designed to reproduce bugs in QEMU IDE.

Is that because the trace would fire so frequently in normal usage that it will drown the user in noise?

Quoted 6 lines

Signed-off-by John Snow <[email protected]>

---
 hw/ide/core.c | 12 +++++++++++-
 1 file changed, 11 insertions(+), 1 deletion(-)

Reviewed-by Eric Blake <[email protected]>

Goodbye, printfs.
Hello, fancy printfs.

Signed-off-by John Snow <[email protected]>

---
 hw/ide/atapi.c            | 64 +++++++++++++++++------------------------------
 hw/ide/trace-events       | 19 ++++++++++++++
 include/hw/ide/internal.h |  1 -
 3 files changed, 42 insertions(+), 42 deletions(-)

Quoted 11 lines · John Snow

Goodbye, printfs.
Hello, fancy printfs.

Signed-off-by John Snow <[email protected]>

---
 hw/ide/atapi.c            | 64 +++++++++++++++++------------------------------
 hw/ide/trace-events       | 19 ++++++++++++++
 include/hw/ide/internal.h |  1 -
 3 files changed, 42 insertions(+), 42 deletions(-)

hw/ide/atapi.c void ide_atapi_cmd(IDEState *s) · line 1317

Quoted 10 lines

hw/ide/atapi.c +5 -2

@@ -1330,16 +1310,18 @@ void ide_atapi_cmd(IDEState *s)
     uint8_t *buf = s->io_buffer;
     const struct AtapiCmd *cmd = &atapi_cmd_table[s->io_buffer[0]];
 
-#ifdef DEBUG_IDE_ATAPI
-    {
+    trace_ide_atapi_cmd(s, s->io_buffer[0]);
+
+    if (TRACE_IDE_ATAPI_CMD_PACKET_ENABLED) {
+        /* Each pretty-printed byte needs two bytes and a space; */
+        char *ppacket = g_malloc(ATAPI_PACKET_SIZE * 3 + 1);

Nice use of an extra conditional to make a pretty trace without the overhead when tracing is off. (Oh yeah, you asked me on IRC how to do it, and I pointed to commit bd6952a3 as the example)

hw/ide/trace-events ide_ioport_read(uint32_t addr, const char *reg, uint32_t val, void *bus, void *s · line 6

Quoted 3 lines

hw/ide/trace-events +1 -0

+++ b/hw/ide/trace-events

@@ -6,6 +6,10 @@ ide_ioport_read(uint32_t addr, const char *reg, uint32_t val, void *bus, void *s
 ide_ioport_write(uint32_t addr, const char *reg, uint32_t val, void *bus, void *s) "IDE PIO wr @ 0x%"PRIx32" (%s); val 0x%02"PRIx32"; bus %p IDEState %p"

Wouldn't it be nice if our trace generator would let us line-wrap?

hw/ide/trace-events bmdma_write_cmd646(uint64_t addr, uint64_t val) "bmdma: writeb 0x%"PRIx64" : 0x% · line 51

Quoted 1 line

hw/ide/trace-events +1 -0

+# Warning: Verbose

Cute. Should you also add it to the ide_data_* traces, per the commit message in 3/9?

hw/ide/trace-events bmdma_write_cmd646(uint64_t addr, uint64_t val) "bmdma: writeb 0x%"PRIx64" : 0x% · line 52

Quoted 2 lines

hw/ide/trace-events +1 -0

+ide_atapi_cmd_packet(void *s, uint16_t limit, const char *packet) "IDEState: %p; limit=0x%x packet: %s"
\ No newline at end of file

Umm, that should be fixed (I know that 'diff' uses both / and \ to differentiate whether it was the pre- or post-patch version that had the issue, but never remember which is which - so the fix may be in an earlier patch). Also fix the trace-events rebase for 3/9; with that, you can add

Reviewed-by Eric Blake <[email protected]>

Signed-off-by John Snow <[email protected]>

---
  hw/ide/atapi.c            |  5 +----
  hw/ide/core.c             | 17 ++++++++++-------
  hw/ide/trace-events       |  3 +++
  include/hw/ide/internal.h |  7 +++++--
  4 files changed, 19 insertions(+), 13 deletions(-)

hw/ide/atapi.c +1 -4

index 37fa699..b8fc51e 100644
@@ -416,10 +416,7 @@ static void ide_atapi_cmd_read_dma_cb(void *opaque, int ret)
          s->io_buffer_size = n * 2048;
          data_offset = 0;
      }
-#ifdef DEBUG_AIO
-    printf("aio_read_cd: lba=%u n=%d\n", s->lba, n);
-#endif
-
+    trace_ide_atapi_cmd_read_dma_cb_aio(s, s->lba, n);
      s->bus->dma->iov.iov_base = (void *)(s->io_buffer + data_offset);
      s->bus->dma->iov.iov_len = n * ATAPI_SECTOR_SIZE;
      qemu_iovec_init_external(&s->bus->dma->qiov, &s->bus->dma->iov, 1);

hw/ide/core.c +10 -7

index 29848ff..1358029 100644
@@ -58,6 +58,13 @@ static const int smart_attributes[][12] = {
      { 190,  0x03, 0x00, 0x45, 0x45, 0x1f, 0x00, 0x1f, 0x1f, 0x00, 0x00, 0x32},
  };
 
+const char *IDE_DMA_CMD_lookup[IDE_DMA__END] = {
+    [IDE_DMA_READ] = "DMA_READ",
+    [IDE_DMA_WRITE] = "DMA_WRITE",
+    [IDE_DMA_TRIM] = "DMA TRIM",
+    [IDE_DMA_ATAPI] = "DMA ATAPI"
+};
+
  static void ide_dummy_transfer_stop(IDEState *s);
 
  static void padstr(char *str, const char *src, int len)

@@ -860,10 +867,8 @@ static void ide_dma_cb(void *opaque, int ret)
          goto eot;
      }
 
-#ifdef DEBUG_AIO
-    printf("ide_dma_cb: sector_num=%" PRId64 " n=%d, cmd_cmd=%d\n",
-           sector_num, n, s->dma_cmd);
-#endif
+    trace_ide_dma_cb(s, sector_num, n,
+                     IDE_DMA_CMD_lookup[s->dma_cmd]);
 
      if ((s->dma_cmd == IDE_DMA_READ || s->dma_cmd == IDE_DMA_WRITE) &&
          !ide_sect_range_ok(s, sector_num, n)) {

@@ -2383,9 +2388,7 @@ void ide_bus_reset(IDEBus *bus)
 
      /* pending async DMA */
      if (bus->dma->aiocb) {
-#ifdef DEBUG_AIO
-        printf("aio_cancel\n");
-#endif
+        trace_ide_bus_reset_aio();
          blk_aio_cancel(bus->dma->aiocb);
          bus->dma->aiocb = NULL;
      }

hw/ide/trace-events +3 -0

index ade1e76..6e33cb3 100644
@@ -17,6 +17,8 @@ ide_cancel_dma_sync_remaining(void) "draining all remaining requests"
  ide_sector_read(int64_t sector_num, int nsectors) "sector=%"PRId64" nsectors=%d"
  ide_sector_write(int64_t sector_num, int nsectors) "sector=%"PRId64" nsectors=%d"
  ide_reset(void *s) "IDEstate %p"
+ide_bus_reset_aio(void) "aio_cancel"
+ide_dma_cb(void *s, int64_t sector_num, int n, const char *dma) "IDEState %p; sector_num=%"PRId64" n=%d cmd=%s"
 
  # hw/ide/pci.c
  bmdma_reset(void) ""

@@ -48,5 +50,6 @@ ide_atapi_cmd_reply_end_new(void *s, int status) "IDEState: %p; new transfer sta
  ide_atapi_cmd_check_status(void *s) "IDEState: %p"
  ide_atapi_cmd_read(void *s, const char *method, int lba, int nb_sectors) "IDEState: %p; read %s: LBA=%d nb_sectors=%d"
  ide_atapi_cmd(void *s, uint8_t cmd) "IDEState: %p; cmd: 0x%02x"
+ide_atapi_cmd_read_dma_cb_aio(void *s, int lba, int n) "IDEState: %p; aio read: lba=%d n=%d"
  # Warning: Verbose
  ide_atapi_cmd_packet(void *s, uint16_t limit, const char *packet) "IDEState: %p; limit=0x%x packet: %s"
\ No newline at end of file

include/hw/ide/internal.h +0 -1

index 74efe8a..97e97a2 100644
@@ -14,7 +14,6 @@
  #include "block/scsi.h"
 
  /* debug IDE devices */
-//#define DEBUG_AIO
  #define USE_DMA_CDROM
 
  typedef struct IDEBus IDEBus;

Hi John,

Quoted 103 lines · John Snow

Signed-off-by John Snow <[email protected]>

---
  hw/ide/atapi.c            |  5 +----
  hw/ide/core.c             | 17 ++++++++++-------
  hw/ide/trace-events       |  3 +++
  include/hw/ide/internal.h |  7 +++++--
  4 files changed, 19 insertions(+), 13 deletions(-)

hw/ide/atapi.c +1 -4

index 37fa699..b8fc51e 100644
@@ -416,10 +416,7 @@ static void ide_atapi_cmd_read_dma_cb(void
 *opaque, int ret)
          s->io_buffer_size = n * 2048;
          data_offset = 0;
      }
-#ifdef DEBUG_AIO
-    printf("aio_read_cd: lba=%u n=%d\n", s->lba, n);
-#endif
-
+    trace_ide_atapi_cmd_read_dma_cb_aio(s, s->lba, n);
      s->bus->dma->iov.iov_base = (void *)(s->io_buffer + data_offset);
      s->bus->dma->iov.iov_len = n * ATAPI_SECTOR_SIZE;

      qemu_iovec_init_external(&s->bus->dma->qiov, &s->bus->dma->iov, 1);

hw/ide/core.c +8 -3

index 29848ff..1358029 100644
@@ -58,6 +58,13 @@ static const int smart_attributes[][12] = {
      { 190,  0x03, 0x00, 0x45, 0x45, 0x1f, 0x00, 0x1f, 0x1f, 0x00,
 0x00, 0x32},
  };
  +const char *IDE_DMA_CMD_lookup[IDE_DMA__END] = {
+    [IDE_DMA_READ] = "DMA_READ",
+    [IDE_DMA_WRITE] = "DMA_WRITE",
+    [IDE_DMA_TRIM] = "DMA TRIM",
+    [IDE_DMA_ATAPI] = "DMA ATAPI"
+};
+
  static void ide_dummy_transfer_stop(IDEState *s);
    static void padstr(char *str, const char *src, int len)

@@ -860,10 +867,8 @@ static void ide_dma_cb(void *opaque, int ret)
          goto eot;
      }
  -#ifdef DEBUG_AIO
-    printf("ide_dma_cb: sector_num=%" PRId64 " n=%d, cmd_cmd=%d\n",
-           sector_num, n, s->dma_cmd);
-#endif
+    trace_ide_dma_cb(s, sector_num, n,
+                     IDE_DMA_CMD_lookup[s->dma_cmd]);
        if ((s->dma_cmd == IDE_DMA_READ || s->dma_cmd ==

IDE_DMA_WRITE) &&

          !ide_sect_range_ok(s, sector_num, n)) {

hw/ide/core.c +1 -3

@@ -2383,9 +2388,7 @@ void ide_bus_reset(IDEBus *bus)
        /* pending async DMA */
      if (bus->dma->aiocb) {
-#ifdef DEBUG_AIO
-        printf("aio_cancel\n");
-#endif
+        trace_ide_bus_reset_aio();
          blk_aio_cancel(bus->dma->aiocb);
          bus->dma->aiocb = NULL;
      }

hw/ide/trace-events +0 -0

index ade1e76..6e33cb3 100644
@@ -17,6 +17,8 @@ ide_cancel_dma_sync_remaining(void) "draining all

remaining requests"
ide_sector_read(int64_t sector_num, int nsectors) "sector=%"PRId64"
nsectors=%d"
ide_sector_write(int64_t sector_num, int nsectors) "sector=%"PRId64"
nsectors=%d"
ide_reset(void *s) "IDEstate %p"

hw/ide/trace-events +2 -0

+ide_bus_reset_aio(void) "aio_cancel"
+ide_dma_cb(void *s, int64_t sector_num, int n, const char *dma)

"IDEState %p; sector_num=%"PRId64" n=%d cmd=%s"

    # hw/ide/pci.c
  bmdma_reset(void) ""

hw/ide/trace-events +0 -0

@@ -48,5 +50,6 @@ ide_atapi_cmd_reply_end_new(void *s, int status)

"IDEState: %p; new transfer sta
ide_atapi_cmd_check_status(void *s) "IDEState: %p" ide_atapi_cmd_read(void *s, const char *method, int lba, int
nb_sectors) "IDEState: %p; read %s: LBA=%d nb_sectors=%d"
ide_atapi_cmd(void *s, uint8_t cmd) "IDEState: %p; cmd: 0x%02x"
+ide_atapi_cmd_read_dma_cb_aio(void *s, int lba, int n) "IDEState: %p; aio read: lba=%d n=%d"
# Warning: Verbose
ide_atapi_cmd_packet(void *s, uint16_t limit, const char *packet)
"IDEState: %p; limit=0x%x packet: %s"
\ No newline at end of file

include/hw/ide/internal.h +0 -1

index 74efe8a..97e97a2 100644
@@ -14,7 +14,6 @@
  #include "block/scsi.h"
    /* debug IDE devices */
-//#define DEBUG_AIO
  #define USE_DMA_CDROM
    typedef struct IDEBus IDEBus;

include/hw/ide/internal.h struct unreported_events { · line 335

Quoted 5 lines

include/hw/ide/internal.h +2 -1

@@ -333,12 +332,16 @@ struct unreported_events {
  };
    enum ide_dma_cmd {
-    IDE_DMA_READ,
+    IDE_DMA__BEGIN = 0,
+    IDE_DMA_READ = IDE_DMA__BEGIN,

not that useful, you can use directly:

    IDE_DMA_READ = 0,

include/hw/ide/internal.h struct unreported_events { · line 340

Quoted 4 lines

include/hw/ide/internal.h +1 -0

      IDE_DMA_WRITE,
      IDE_DMA_TRIM,
      IDE_DMA_ATAPI,
+    IDE_DMA__END

IDE_DMA__COUNT sounds better.

include/hw/ide/internal.h struct unreported_events { · line 347

Quoted 6 lines

include/hw/ide/internal.h +1 -0

  };
  +extern const char *IDE_DMA_CMD_lookup[IDE_DMA__END];
+
  #define ide_cmd_is_read(s) \
      ((s)->dma_cmd == IDE_DMA_READ)
 

removing IDE_DMA__BEGIN and using IDE_DMA__COUNT:

Reviewed-by Philippe Mathieu-Daudé <[email protected]>

There are a few hangers-on that will be dealt with individually in forthcoming patches.

Signed-off-by John Snow <[email protected]>

---
  hw/ide/ahci.c       | 157 +++++++++++++++++++++++-----------------------------
  hw/ide/trace-events |  52 ++++++++++++++++-
  2 files changed, 119 insertions(+), 90 deletions(-)

hw/ide/ahci.c +68 -89

index 406a1b5..d5acceb 100644
@@ -35,6 +35,7 @@
  #include "hw/ide/ahci_internal.h"
 
  #define DEBUG_AHCI 0
+#include "trace.h"
 
  #define DPRINTF(port, fmt, ...) \
  do { \

@@ -114,9 +115,9 @@ static uint32_t  ahci_port_read(AHCIState *s, int port, int offset)
      default:
          val = 0;
      }
-    DPRINTF(port, "offset: 0x%x val: 0x%x\n", offset, val);
-    return val;
 
+    trace_ahci_port_read(s, port, offset, val);
+    return val;
  }
 
  static void ahci_irq_raise(AHCIState *s, AHCIDevice *dev)

@@ -125,7 +126,7 @@ static void ahci_irq_raise(AHCIState *s, AHCIDevice *dev)
      PCIDevice *pci_dev = (PCIDevice *) object_dynamic_cast(OBJECT(dev_state),
                                                             TYPE_PCI_DEVICE);
 
-    DPRINTF(0, "raise irq\n");
+    trace_ahci_irq_raise(s);
 
      if (pci_dev && msi_enabled(pci_dev)) {
          msi_notify(pci_dev, 0);

@@ -140,7 +141,7 @@ static void ahci_irq_lower(AHCIState *s, AHCIDevice *dev)
      PCIDevice *pci_dev = (PCIDevice *) object_dynamic_cast(OBJECT(dev_state),
                                                             TYPE_PCI_DEVICE);
 
-    DPRINTF(0, "lower irq\n");
+    trace_ahci_irq_lower(s);
 
      if (!pci_dev || !msi_enabled(pci_dev)) {
          qemu_irq_lower(s->irq);

@@ -150,8 +151,7 @@ static void ahci_irq_lower(AHCIState *s, AHCIDevice *dev)
  static void ahci_check_irq(AHCIState *s)
  {
      int i;
-
-    DPRINTF(-1, "check irq %#x\n", s->control_regs.irqstatus);
+    uint32_t old_irq = s->control_regs.irqstatus;
 
      s->control_regs.irqstatus = 0;
      for (i = 0; i < s->ports; i++) {

@@ -160,7 +160,7 @@ static void ahci_check_irq(AHCIState *s)
              s->control_regs.irqstatus |= (1 << i);
          }
      }
-
+    trace_ahci_check_irq(s, old_irq, s->control_regs.irqstatus);
      if (s->control_regs.irqstatus &&
          (s->control_regs.ghc & HOST_CTL_IRQ_EN)) {
              ahci_irq_raise(s, NULL);

@@ -240,7 +240,7 @@ static void  ahci_port_write(AHCIState *s, int port, int offset, uint32_t val)
  {
      AHCIPortRegs *pr = &s->dev[port].port_regs;
 
-    DPRINTF(port, "offset: 0x%x val: 0x%x\n", offset, val);
+    trace_ahci_port_write(s, port, offset, val);
      switch (offset) {
          case PORT_LST_ADDR:
              pr->lst_addr = val;

@@ -341,8 +341,6 @@ static uint64_t ahci_mem_read_32(void *opaque, hwaddr addr)
              val = s->control_regs.version;
              break;
          }
-
-        DPRINTF(-1, "(addr 0x%08X), val 0x%08X\n", (unsigned) addr, val);
      } else if ((addr >= AHCI_PORT_REGS_START_ADDR) &&
                 (addr < (AHCI_PORT_REGS_START_ADDR +
                  (s->ports * AHCI_PORT_ADDR_OFFSET_LEN)))) {

@@ -350,6 +348,7 @@ static uint64_t ahci_mem_read_32(void *opaque, hwaddr addr)
                               addr & AHCI_PORT_ADDR_OFFSET_MASK);
      }
 
+    trace_ahci_mem_read_32(s, addr, val);
      return val;
  }
 

@@ -379,8 +378,7 @@ static uint64_t ahci_mem_read(void *opaque, hwaddr addr, unsigned size)
          val = (hi << 32 | lo) >> (ofst * 8);
      }
 
-    DPRINTF(-1, "addr=0x%" HWADDR_PRIx " val=0x%" PRIx64 ", size=%d\n",
-            addr, val, size);
+    trace_ahci_mem_read(opaque, size, addr, val);
      return val;
  }
 

@@ -390,8 +388,7 @@ static void ahci_mem_write(void *opaque, hwaddr addr,
  {
      AHCIState *s = opaque;
 
-    DPRINTF(-1, "addr=0x%" HWADDR_PRIx " val=0x%" PRIx64 ", size=%d\n",
-            addr, val, size);
+    trace_ahci_mem_write(s, size, addr, val);
 
      /* Only aligned reads are allowed on AHCI */
      if (addr & 3) {

@@ -401,15 +398,12 @@ static void ahci_mem_write(void *opaque, hwaddr addr,
      }
 
      if (addr < AHCI_GENERIC_HOST_CONTROL_REGS_MAX_ADDR) {
-        DPRINTF(-1, "(addr 0x%08X), val 0x%08"PRIX64"\n", (unsigned) addr, val);
-
          switch (addr) {
              case HOST_CAP: /* R/WO, RO */
                  /* FIXME handle R/WO */
                  break;
              case HOST_CTL: /* R/W */
                  if (val & HOST_CTL_RESET) {
-                    DPRINTF(-1, "HBA Reset\n");
                      ahci_reset(s);
                  } else {
                      s->control_regs.ghc = (val & 0x3) | HOST_CTL_AHCI_EN;

@@ -427,7 +421,7 @@ static void ahci_mem_write(void *opaque, hwaddr addr,
                  /* FIXME report write? */
                  break;
              default:
-                DPRINTF(-1, "write to unknown register 0x%x\n", (unsigned)addr);
+                trace_ahci_mem_write_unknown(s, addr);
          }
      } else if ((addr >= AHCI_PORT_REGS_START_ADDR) &&
                 (addr < (AHCI_PORT_REGS_START_ADDR +

@@ -559,7 +553,8 @@ static void ahci_set_signature(AHCIDevice *ad, uint32_t sig)
      s->sector = sig >> 8 & 0xFF;
      s->nsector = sig & 0xFF;
 
-    DPRINTF(ad->port_no, "set hcyl:lcyl:sect:nsect = 0x%08x\n", sig);
+    trace_ahci_set_signature(ad->hba, ad->port_no, s->nsector, s->sector,
+                             s->lcyl, s->hcyl, sig);
  }
 
  static void ahci_reset_port(AHCIState *s, int port)

@@ -569,7 +564,7 @@ static void ahci_reset_port(AHCIState *s, int port)
      IDEState *ide_state = &d->port.ifs[0];
      int i;
 
-    DPRINTF(port, "reset port\n");
+    trace_ahci_reset_port(s, port);
 
      ide_bus_reset(&d->port);
      ide_state->ncq_queues = AHCI_MAX_CMDS;

@@ -655,7 +650,7 @@ static bool ahci_map_fis_address(AHCIDevice *ad)
  static void ahci_unmap_fis_address(AHCIDevice *ad)
  {
      if (ad->res_fis == NULL) {
-        DPRINTF(ad->port_no, "Attempt to unmap NULL FIS address\n");
+        trace_ahci_unmap_fis_address_null(ad->hba, ad->port_no);
          return;
      }
      ad->port_regs.cmd &= ~PORT_CMD_FIS_ON;

@@ -682,7 +677,7 @@ static bool ahci_map_clb_address(AHCIDevice *ad)
  static void ahci_unmap_clb_address(AHCIDevice *ad)
  {
      if (ad->lst == NULL) {
-        DPRINTF(ad->port_no, "Attempt to unmap NULL CLB address\n");
+        trace_ahci_unmap_clb_address_null(ad->hba, ad->port_no);
          return;
      }
      ad->port_regs.cmd &= ~PORT_CMD_LIST_ON;

@@ -854,20 +849,22 @@ static int ahci_populate_sglist(AHCIDevice *ad, QEMUSGList *sglist,
      IDEBus *bus = &ad->port;
      BusState *qbus = BUS(bus);
 
+    trace_ahci_populate_sglist(ad->hba, ad->port_no);
+
      if (!prdtl) {
-        DPRINTF(ad->port_no, "no sg list given by guest: 0x%08x\n", opts);
+        trace_ahci_populate_sglist_no_prdtl(ad->hba, ad->port_no, opts);
          return -1;
      }
 
      /* map PRDT */
      if (!(prdt = dma_memory_map(ad->hba->as, prdt_addr, &prdt_len,
                                  DMA_DIRECTION_TO_DEVICE))){
-        DPRINTF(ad->port_no, "map failed\n");
+        trace_ahci_populate_sglist_no_map(ad->hba, ad->port_no);
          return -1;
      }
 
      if (prdt_len < real_prdt_len) {
-        DPRINTF(ad->port_no, "mapped less than expected\n");
+        trace_ahci_populate_sglist_short_map(ad->hba, ad->port_no);
          r = -1;
          goto out;
      }

@@ -886,9 +883,8 @@ static int ahci_populate_sglist(AHCIDevice *ad, QEMUSGList *sglist,
              sum += tbl_entry_size;
          }
          if ((off_idx == -1) || (off_pos < 0) || (off_pos > tbl_entry_size)) {
-            DPRINTF(ad->port_no, "%s: Incorrect offset! "
-                            "off_idx: %d, off_pos: %"PRId64"\n",
-                            __func__, off_idx, off_pos);
+            trace_ahci_populate_sglist_bad_offset(ad->hba, ad->port_no,
+                                                  off_idx, off_pos);
              r = -1;
              goto out;
          }

@@ -934,8 +930,8 @@ static void ncq_finish(NCQTransferState *ncq_tfs)
 
      ahci_write_fis_sdb(ncq_tfs->drive->hba, ncq_tfs);
 
-    DPRINTF(ncq_tfs->drive->port_no, "NCQ transfer tag %d finished\n",
-            ncq_tfs->tag);
+    trace_ncq_finish(ncq_tfs->drive->hba, ncq_tfs->drive->port_no,
+                     ncq_tfs->tag);
 
      block_acct_done(blk_get_stats(ncq_tfs->drive->port.ifs[0].blk),
                      &ncq_tfs->acct);

@@ -999,12 +995,8 @@ static void execute_ncq_command(NCQTransferState *ncq_tfs)
 
      switch (ncq_tfs->cmd) {
      case READ_FPDMA_QUEUED:
-        DPRINTF(port, "NCQ reading %d sectors from LBA %"PRId64", tag %d\n",
-                ncq_tfs->sector_count, ncq_tfs->lba, ncq_tfs->tag);
-
-        DPRINTF(port, "tag %d aio read %"PRId64"\n",
-                ncq_tfs->tag, ncq_tfs->lba);
-
+        trace_execute_ncq_command_read(ad->hba, port, ncq_tfs->tag,
+                                       ncq_tfs->sector_count, ncq_tfs->lba);
          dma_acct_start(ide_state->blk, &ncq_tfs->acct,
                         &ncq_tfs->sglist, BLOCK_ACCT_READ);
          ncq_tfs->aiocb = dma_blk_read(ide_state->blk, &ncq_tfs->sglist,

@@ -1013,12 +1005,8 @@ static void execute_ncq_command(NCQTransferState *ncq_tfs)
                                        ncq_cb, ncq_tfs);
          break;
      case WRITE_FPDMA_QUEUED:
-        DPRINTF(port, "NCQ writing %d sectors to LBA %"PRId64", tag %d\n",
-                ncq_tfs->sector_count, ncq_tfs->lba, ncq_tfs->tag);
-
-        DPRINTF(port, "tag %d aio write %"PRId64"\n",
-                ncq_tfs->tag, ncq_tfs->lba);
-
+        trace_execute_ncq_command_read(ad->hba, port, ncq_tfs->tag,
+                                       ncq_tfs->sector_count, ncq_tfs->lba);
          dma_acct_start(ide_state->blk, &ncq_tfs->acct,
                         &ncq_tfs->sglist, BLOCK_ACCT_WRITE);
          ncq_tfs->aiocb = dma_blk_write(ide_state->blk, &ncq_tfs->sglist,

@@ -1027,8 +1015,8 @@ static void execute_ncq_command(NCQTransferState *ncq_tfs)
                                         ncq_cb, ncq_tfs);
          break;
      default:
-        DPRINTF(port, "error: unsupported NCQ command (0x%02x) received\n",
-                ncq_tfs->cmd);
+        trace_execute_ncq_command_unsup(ad->hba, port,
+                                        ncq_tfs->tag, ncq_tfs->cmd);
          ncq_err(ncq_tfs);
      }
  }

@@ -1038,7 +1026,6 @@ static void process_ncq_command(AHCIState *s, int port, uint8_t *cmd_fis,
                                  uint8_t slot)
  {
      AHCIDevice *ad = &s->dev[port];
-    IDEState *ide_state = &ad->port.ifs[0];
      NCQFrame *ncq_fis = (NCQFrame*)cmd_fis;
      uint8_t tag = ncq_fis->tag >> 3;
      NCQTransferState *ncq_tfs = &ad->ncq_tfs[tag];

@@ -1066,21 +1053,20 @@ static void process_ncq_command(AHCIState *s, int port, uint8_t *cmd_fis,
 
      /* Sanity-check the NCQ packet */
      if (tag != slot) {
-        DPRINTF(port, "Warn: NCQ slot (%d) did not match the given tag (%d)\n",
-                slot, tag);
+        trace_process_ncq_command_mismatch(s, port, tag, slot);
      }
 
      if (ncq_fis->aux0 || ncq_fis->aux1 || ncq_fis->aux2 || ncq_fis->aux3) {
-        DPRINTF(port, "Warn: Attempt to use NCQ auxiliary fields.\n");
+        trace_process_ncq_command_aux(s, port, tag);
      }
      if (ncq_fis->prio || ncq_fis->icc) {
-        DPRINTF(port, "Warn: Unsupported attempt to use PRIO/ICC fields\n");
+        trace_process_ncq_command_prioicc(s, port, tag);
      }
      if (ncq_fis->fua & NCQ_FIS_FUA_MASK) {
-        DPRINTF(port, "Warn: Unsupported attempt to use Force Unit Access\n");
+        trace_process_ncq_command_fua(s, port, tag);
      }
      if (ncq_fis->tag & NCQ_FIS_RARC_MASK) {
-        DPRINTF(port, "Warn: Unsupported attempt to use Rebuild Assist\n");
+        trace_process_ncq_command_rarc(s, port, tag);
      }
 
      ncq_tfs->sector_count = ((ncq_fis->sector_count_high << 8) |

@@ -1099,16 +1085,14 @@ static void process_ncq_command(AHCIState *s, int port, uint8_t *cmd_fis,
          ahci_trigger_irq(ad->hba, ad, PORT_IRQ_OVERFLOW);
          return;
      } else if (ncq_tfs->sglist.size != size) {
-        DPRINTF(port, "Warn: PRDTL (0x%zx)"
-                " does not match requested size (0x%zx)",
-                ncq_tfs->sglist.size, size);
+        trace_process_ncq_command_large(s, port, tag,
+                                        ncq_tfs->sglist.size, size);
      }
 
-    DPRINTF(port, "NCQ transfer LBA from %"PRId64" to %"PRId64", "
-            "drive max %"PRId64"\n",
-            ncq_tfs->lba, ncq_tfs->lba + ncq_tfs->sector_count - 1,
-            ide_state->nb_sectors - 1);
-
+    trace_process_ncq_command(s, port, tag,
+                              ncq_fis->command,
+                              ncq_tfs->lba,
+                              ncq_tfs->lba + ncq_tfs->sector_count - 1);
      execute_ncq_command(ncq_tfs);
  }
 

@@ -1129,16 +1113,14 @@ static void handle_reg_h2d_fis(AHCIState *s, int port,
      uint16_t opts = le16_to_cpu(cmd->opts);
 
      if (cmd_fis[1] & 0x0F) {
-        DPRINTF(port, "Port Multiplier not supported."
-                " cmd_fis[0]=%02x cmd_fis[1]=%02x cmd_fis[2]=%02x\n",
-                cmd_fis[0], cmd_fis[1], cmd_fis[2]);
+        trace_handle_reg_h2d_fis_pmp(s, port, cmd_fis[1],
+                                     cmd_fis[2], cmd_fis[3]);
          return;
      }
 
      if (cmd_fis[1] & 0x70) {
-        DPRINTF(port, "Reserved flags set in H2D Register FIS."
-                " cmd_fis[0]=%02x cmd_fis[1]=%02x cmd_fis[2]=%02x\n",
-                cmd_fis[0], cmd_fis[1], cmd_fis[2]);
+        trace_handle_reg_h2d_fis_res(s, port, cmd_fis[1],
+                                     cmd_fis[2], cmd_fis[3]);
          return;
      }
 

@@ -1216,12 +1198,12 @@ static int handle_cmd(AHCIState *s, int port, uint8_t slot)
 
      if (s->dev[port].port.ifs[0].status & (BUSY_STAT|DRQ_STAT)) {
          /* Engine currently busy, try again later */
-        DPRINTF(port, "engine busy\n");
+        trace_handle_cmd_busy(s, port);
          return -1;
      }
 
      if (!s->dev[port].lst) {
-        DPRINTF(port, "error: lst not given but cmd handled");
+        trace_handle_cmd_nolist(s, port);
          return -1;
      }
      cmd = get_cmd_header(s, port, slot);

@@ -1231,7 +1213,7 @@ static int handle_cmd(AHCIState *s, int port, uint8_t slot)
      /* The device we are working for */
      ide_state = &s->dev[port].port.ifs[0];
      if (!ide_state->blk) {
-        DPRINTF(port, "error: guest accessed unused port");
+        trace_handle_cmd_badport(s, port);
          return -1;
      }
 

@@ -1240,13 +1222,11 @@ static int handle_cmd(AHCIState *s, int port, uint8_t slot)
      cmd_fis = dma_memory_map(s->as, tbl_addr, &cmd_len,
                               DMA_DIRECTION_FROM_DEVICE);
      if (!cmd_fis) {
-        DPRINTF(port, "error: guest passed us an invalid cmd fis\n");
+        trace_handle_cmd_badfis(s, port);
          return -1;
      } else if (cmd_len != 0x80) {
          ahci_trigger_irq(s, &s->dev[port], PORT_IRQ_HBUS_ERR);
-        DPRINTF(port, "error: dma_memory_map failed: "
-                "(len(%02"PRIx64") != 0x80)\n",
-                cmd_len);
+        trace_handle_cmd_badmap(s, port, cmd_len);
          goto out;
      }
      debug_print_fis(cmd_fis, 0x80);

@@ -1256,9 +1236,8 @@ static int handle_cmd(AHCIState *s, int port, uint8_t slot)
              handle_reg_h2d_fis(s, port, slot, cmd_fis);
              break;
          default:
-            DPRINTF(port, "unknown command cmd_fis[0]=%02x cmd_fis[1]=%02x "
-                          "cmd_fis[2]=%02x\n", cmd_fis[0], cmd_fis[1],
-                          cmd_fis[2]);
+            trace_handle_cmd_unhandled_fis(s, port,
+                                           cmd_fis[0], cmd_fis[1], cmd_fis[2]);
              break;
      }
 

@@ -1299,9 +1278,9 @@ static void ahci_start_transfer(IDEDMA *dma)
          has_sglist = 1;
      }
 
-    DPRINTF(ad->port_no, "%sing %d bytes on %s w/%s sglist\n",
-            is_write ? "writ" : "read", size, is_atapi ? "atapi" : "ata",
-            has_sglist ? "" : "o");
+    trace_ahci_start_transfer(ad->hba, ad->port_no, is_write ? "writ" : "read",
+                              size, is_atapi ? "atapi" : "ata",
+                              has_sglist ? "" : "o");
 
      if (has_sglist && size) {
          if (is_write) {

@@ -1330,7 +1309,7 @@ static void ahci_start_dma(IDEDMA *dma, IDEState *s,
                             BlockCompletionFunc *dma_cb)
  {
      AHCIDevice *ad = DO_UPCAST(AHCIDevice, dma, dma);
-    DPRINTF(ad->port_no, "\n");
+    trace_ahci_start_dma(ad->hba, ad->port_no);
      s->io_buffer_offset = 0;
      dma_cb(s, 0);
  }

@@ -1368,12 +1347,12 @@ static int32_t ahci_dma_prepare_buf(IDEDMA *dma, int32_t limit)
 
      if (ahci_populate_sglist(ad, &s->sg, ad->cur_cmd,
                               limit, s->io_buffer_offset) == -1) {
-        DPRINTF(ad->port_no, "ahci_dma_prepare_buf failed.\n");
+        trace_ahci_dma_prepare_buf_fail(ad->hba, ad->port_no);
          return -1;
      }
      s->io_buffer_size = s->sg.size;
 
-    DPRINTF(ad->port_no, "len=%#x\n", s->io_buffer_size);
+    trace_ahci_dma_prepare_buf(ad->hba, ad->port_no, limit, s->io_buffer_size);
      return s->io_buffer_size;
  }
 

@@ -1409,11 +1388,9 @@ static int ahci_dma_rw_buf(IDEDMA *dma, int is_write)
 
      /* free sglist, update byte count */
      dma_buf_commit(s, l);
-
      s->io_buffer_index += l;
 
-    DPRINTF(ad->port_no, "len=%#x\n", l);
-
+    trace_ahci_dma_rw_buf(ad->hba, ad->port_no, l);
      return 1;
  }
 

@@ -1421,7 +1398,7 @@ static void ahci_cmd_done(IDEDMA *dma)
  {
      AHCIDevice *ad = DO_UPCAST(AHCIDevice, dma, dma);
 
-    DPRINTF(ad->port_no, "cmd done\n");
+    trace_ahci_cmd_done(ad->hba, ad->port_no);
 
      /* update d2h status */
      ahci_write_fis_d2h(ad);

@@ -1505,6 +1482,8 @@ void ahci_reset(AHCIState *s)
      AHCIPortRegs *pr;
      int i;
 
+    trace_ahci_reset(s);
+
      s->control_regs.irqstatus = 0;
      /* AHCI Enable (AE)
       * The implementation of this bit is dependent upon the value of the

@@ -1755,6 +1734,7 @@ static uint64_t allwinner_ahci_mem_read(void *opaque, hwaddr addr,
                                          unsigned size)
  {
      AllwinnerAHCIState *a = opaque;
+    AHCIState *s = &(SYSBUS_AHCI(a)->ahci);
      uint64_t val = a->regs[addr/4];
 
      switch (addr / 4) {

@@ -1765,8 +1745,7 @@ static uint64_t allwinner_ahci_mem_read(void *opaque, hwaddr addr,
          val &= ~(0x1 << 24);
          break;
      }
-    DPRINTF(-1, "addr=0x%" HWADDR_PRIx " val=0x%" PRIx64 ", size=%d\n",
-            addr, val, size);
+    trace_allwinner_ahci_mem_read(s, a, addr, val, size);
      return  val;
  }
 

@@ -1774,9 +1753,9 @@ static void allwinner_ahci_mem_write(void *opaque, hwaddr addr,
                                       uint64_t val, unsigned size)
  {
      AllwinnerAHCIState *a = opaque;
+    AHCIState *s = &(SYSBUS_AHCI(a)->ahci);
 
-    DPRINTF(-1, "addr=0x%" HWADDR_PRIx " val=0x%" PRIx64 ", size=%d\n",
-            addr, val, size);
+    trace_allwinner_ahci_mem_write(s, a, addr, val, size);
      a->regs[addr/4] = val;
  }
 

hw/ide/trace-events +0 -1

index 6e33cb3..e1a0457 100644
@@ -52,4 +52,54 @@ ide_atapi_cmd_read(void *s, const char *method, int lba, int nb_sectors) "IDESta
  ide_atapi_cmd(void *s, uint8_t cmd) "IDEState: %p; cmd: 0x%02x"
  ide_atapi_cmd_read_dma_cb_aio(void *s, int lba, int n) "IDEState: %p; aio read: lba=%d n=%d"
  # Warning: Verbose
-ide_atapi_cmd_packet(void *s, uint16_t limit, const char *packet) "IDEState: %p; limit=0x%x packet: %s"
\ No newline at end of file