Re: [Qemu-devel] [PATCH v2 1/5] qxl: switch qxl.c to trace-events

[Alon Levy <alevy@redhat.com>]

On Mon, Mar 12, 2012 at 11:20:55AM +0100, Gerd Hoffmann wrote:
> On 03/11/12 20:26, Alon Levy wrote:
> > dprint is still used for qxl_init_common one time prints.
> 
> I think we shouldn't simply convert the dprintf's into trace-points.
> 
> We should look at each dprintf and check whenever it makes sense at all,
> whenever it makes sense at that place before converting it over to a
> tracepoint.

I had two changes of heart about this. Initially I started mechanically
converting, then I realized it only makes sense for recurring events,
and things we want to see come out of the same output. But then I
noticed a lot of existing users do use it for as verbose usage as we do
(bh calls) and it is not meant as a stable interface to anyone - clearly
something that should fit the developer and user, and if the subsystem
changes then the events can change.

Bottom line I think having most of the dprints as trace_events makes
sense, and we can use consistent naming to make enabling/disabling them
easy for systemtap/stderr (with monitor trace-events command) easy.

I only left very few dprints.

> 
> > @@ -409,7 +410,7 @@ static void interface_attach_worker(QXLInstance *sin, QXLWorker *qxl_worker)
> >  {
> >      PCIQXLDevice *qxl = container_of(sin, PCIQXLDevice, ssd.qxl);
> >  
> > -    dprint(qxl, 1, "%s:\n", __FUNCTION__);
> > +    trace_qxl_interface_attach_worker();
> >      qxl->ssd.worker = qxl_worker;
> >  }
> 
> For example: Do we really need that one?

I look at it the other way around - can it repeat? yes, it's a callback
from the spice server which we don't control. does it serve the
same purpose as the dprint? yes.

> 
> > @@ -505,9 +506,10 @@ static int interface_get_command(QXLInstance *sin, struct QXLCommandExt *ext)
> >      QXLCommand *cmd;
> >      int notify, ret;
> >  
> > +    trace_qxl_interface_get_command_enter(qxl_mode_to_string(qxl->mode));
> > +
> 
> Why this?

Simplyfication of the dprints to avoid introducing an additional trace
event. We had a dprint for level 1 for both VGA and other modes, so I
moved it up. This trace is for each request from the server, as opposed
to the _ret that is for each returned command (much less frequent).

> 
> > -    dprint(qxl, 1, "%s: scheduling update_area_bh, #dirty %d\n",
> > -           __func__, qxl->num_dirty_rects);
> > +    trace_qxl_interface_update_area_complete_schedule_bh(qxl->num_dirty_rects);
> 
> I think it makes more sense to have the tracepoint in the bottom half
> handler instead.

Why instead? I could add another one at the bottom half.

> 
> >  static void qxl_hard_reset(PCIQXLDevice *d, int loadvm)
> >  {
> > -    dprint(d, 1, "%s: start%s\n", __FUNCTION__,
> > -           loadvm ? " (loadvm)" : "");
> > +    trace_qxl_hard_reset_enter(loadvm);
> >  
> >      qxl_spice_reset_cursor(d);
> >      qxl_spice_reset_image_cache(d);
> > @@ -934,7 +935,7 @@ static void qxl_hard_reset(PCIQXLDevice *d, int loadvm)
> >      qemu_spice_create_host_memslot(&d->ssd);
> >      qxl_soft_reset(d);
> >  
> > -    dprint(d, 1, "%s: done\n", __FUNCTION__);
> > +    trace_qxl_hard_reset_exit();
> >  }
> 
> Do we need the exit tracepoint?

With systemtap I'd say the whole function could be traced, and that
would mean both entry and exit. But you can't do that with the tracing
framework, so this is the only way to have both.

If having both dprints makes no sense, I guess having both trace events
makes none too.

> 
> >  static void qxl_reset_memslots(PCIQXLDevice *d)
> >  {
> > -    dprint(d, 1, "%s:\n", __FUNCTION__);
> > +    trace_qxl_reset_memslots();
> >      qxl_spice_reset_memslots(d);
> >      memset(&d->guest_slots, 0, sizeof(d->guest_slots));
> >  }
> 
> Do we need that one?  qxl_hard_reset is the only caller of that function ...

Agree, I'll drop it.

But maybe I should add trace events for all the qxl_spice_* calls?

> 
> > @@ -1216,8 +1213,8 @@ static void ioport_write(void *opaque, target_phys_addr_t addr,
> >          if (d->mode != QXL_MODE_VGA) {
> >              break;
> >          }
> > -        dprint(d, 1, "%s: unexpected port 0x%x (%s) in vga mode\n",
> > -            __func__, io_port, io_port_to_string(io_port));
> > +        trace_qxl_io_unexpected_vga_mode(
> > +            io_port, io_port_to_string(io_port));
> 
> We might want raise an error irq here, and have a tracepoint in
> qxl_guest_bug() of course ...

ok, I think I can add the tracepoint for qxl_guest_bug. Raise an error
irq I'll do in another patch.

> 
> >      case QXL_IO_SET_MODE:
> > -        dprint(d, 1, "QXL_SET_MODE %d\n", (int)val);
> > +        trace_qxl_io_set_mode(val);
> >          qxl_set_mode(d, val, 0);
> 
> Needed?  There is a tracepoint in qxl_set_mode() ...

But if qxl_set_mode can be called from multiple places it isn't
equivalent.

> 
> >      case QXL_IO_RESET:
> > -        dprint(d, 1, "QXL_IO_RESET\n");
> > +        trace_qxl_io_reset();
> >          qxl_hard_reset(d, 0);
> 
> ... likewise ...

Same answer.

> 
> >          break;
> >      case QXL_IO_MEMSLOT_ADD:
> > @@ -1337,7 +1334,7 @@ async_common:
> >                            async);
> >              goto cancel_async;
> >          }
> > -        dprint(d, 1, "QXL_IO_CREATE_PRIMARY async=%d\n", async);
> > +        trace_qxl_io_create_primary(async);
> >          d->guest_primary.surface = d->ram->create_surface;
> >          qxl_create_guest_primary(d, 0, async);
> 
> ... here too ...

Ditto. The traceevents are named qxl_io_* on purpose, they are guest io
triggered, there can be other calls to qxl_create_guest_primary.

Perhaps I'll have a single .. oh, you wrote the same thing below :)

> 
> We might want to have a "trace_qxl_io_write(addr, val)" at the start of
> the function, so we see all guest writes.  Traces for the actual ops (if
> needed at all) are probably much better placed into the functions
> executing the op as they can trace more details (i.e. qxl_set_mode has
> the tracepoint *after* looking up the mode so we can stick the mode info
> into the trace too).

Ok, that works.

> 
> cheers,
>   Gerd
>