| Message ID | 1331494004-26177-2-git-send-email-alevy@redhat.com |
|---|---|
| State | New |
| Headers | show |
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. > @@ -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? > @@ -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? > - 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. > 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? > 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 ... > @@ -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 ... > 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() ... > case QXL_IO_RESET: > - dprint(d, 1, "QXL_IO_RESET\n"); > + trace_qxl_io_reset(); > qxl_hard_reset(d, 0); ... likewise ... > 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 ... 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). cheers, Gerd
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 >
On Mon, Mar 12, 2012 at 01:43:11PM +0200, Alon Levy wrote: > 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'll also add qxl_spice_* trace points for the next patch. Does that sound excessive? you could just trace the qxl_io_write to get the io itself, or trace just qxl_spice_* to get the qxl<->spice interface, or both (qxl_*). > > 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 > > >
On 03/12/12 16:50, Alon Levy wrote: > On Mon, Mar 12, 2012 at 01:43:11PM +0200, Alon Levy wrote: >> 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'll also add qxl_spice_* trace points for the next patch. Does that > sound excessive? you could just trace the qxl_io_write to get the io > itself, or trace just qxl_spice_* to get the qxl<->spice interface, or > both (qxl_*). Makes sense to place trace points systematically like that. cheers, Gerd
On Tue, Mar 13, 2012 at 07:42:17AM +0100, Gerd Hoffmann wrote: > On 03/12/12 16:50, Alon Levy wrote: > > On Mon, Mar 12, 2012 at 01:43:11PM +0200, Alon Levy wrote: > >> 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'll also add qxl_spice_* trace points for the next patch. Does that > > sound excessive? you could just trace the qxl_io_write to get the io > > itself, or trace just qxl_spice_* to get the qxl<->spice interface, or > > both (qxl_*). > > Makes sense to place trace points systematically like that. > What about having the frequent (read: too frequent to use stderr to dump them since they clutter the screen, unless you 'stop' before each monitor command) have a postfix "_freq"? This is a stopgap, but helpful one, you can then do: trace-event qxl* on trace-event qxl*freq off Instead of remembering / having conveniently ready a longer list: trace-event qxl* on trace-event qxl_interface_get_command_enter off trace-event qxl_interface_release_resource off trace-event qxl_interface_get_command_ret off trace-event qxl_push_free_res off > cheers, > Gerd > >
Hi, > What about having the frequent (read: too frequent to use stderr to dump > them since they clutter the screen, unless you 'stop' before each > monitor command) have a postfix "_freq"? This is a stopgap, but helpful > one, you can then do: > trace-event qxl* on > trace-event qxl*freq off > > Instead of remembering / having conveniently ready a longer list: > trace-event qxl* on > trace-event qxl_interface_get_command_enter off > trace-event qxl_interface_release_resource off > trace-event qxl_interface_get_command_ret off > trace-event qxl_push_free_res off Hmm, I'd suggest to just try find better names. These all are about ring management (well, free_res is a bit special, but still ...), so maybe: qxl_ring_{command,cursor}_check (check whenever stuff is in there) qxl_ring_{command,cursor}_get (take item out of the ring) qxl_ring_res_put (stuff item into the ring) Then you can match them likewise easy with "qxl_ring_*", but you have descriptive names without the IMHO ugly _freq suffix. cheers, Gerd
On Tue, Mar 13, 2012 at 10:47:54AM +0100, Gerd Hoffmann wrote: > Hi, > > > What about having the frequent (read: too frequent to use stderr to dump > > them since they clutter the screen, unless you 'stop' before each > > monitor command) have a postfix "_freq"? This is a stopgap, but helpful > > one, you can then do: > > trace-event qxl* on > > trace-event qxl*freq off > > > > Instead of remembering / having conveniently ready a longer list: > > trace-event qxl* on > > trace-event qxl_interface_get_command_enter off > > trace-event qxl_interface_release_resource off > > trace-event qxl_interface_get_command_ret off > > trace-event qxl_push_free_res off > > Hmm, I'd suggest to just try find better names. These all are about > ring management (well, free_res is a bit special, but still ...), so maybe: > > qxl_ring_{command,cursor}_check (check whenever stuff is in there) > qxl_ring_{command,cursor}_get (take item out of the ring) > qxl_ring_res_put (stuff item into the ring) > > Then you can match them likewise easy with "qxl_ring_*", but you have > descriptive names without the IMHO ugly _freq suffix. Sounds good. > > cheers, > Gerd > >
On Tue, Mar 13, 2012 at 10:47:54AM +0100, Gerd Hoffmann wrote: > Hi, > > > What about having the frequent (read: too frequent to use stderr to dump > > them since they clutter the screen, unless you 'stop' before each > > monitor command) have a postfix "_freq"? This is a stopgap, but helpful > > one, you can then do: > > trace-event qxl* on > > trace-event qxl*freq off > > > > Instead of remembering / having conveniently ready a longer list: > > trace-event qxl* on > > trace-event qxl_interface_get_command_enter off > > trace-event qxl_interface_release_resource off > > trace-event qxl_interface_get_command_ret off > > trace-event qxl_push_free_res off > > Hmm, I'd suggest to just try find better names. These all are about > ring management (well, free_res is a bit special, but still ...), so maybe: > > qxl_ring_{command,cursor}_check (check whenever stuff is in there) > qxl_ring_{command,cursor}_get (take item out of the ring) > qxl_ring_res_put (stuff item into the ring) Hmm, actually for vga mode the names are misleading. I think I'll stick with them anyway, they do have a mode argument so you can see it's in vga mode. > > Then you can match them likewise easy with "qxl_ring_*", but you have > descriptive names without the IMHO ugly _freq suffix. > > cheers, > Gerd > >
diff --git a/hw/qxl.c b/hw/qxl.c index e17b0e3..7857731 100644 --- a/hw/qxl.c +++ b/hw/qxl.c @@ -23,6 +23,7 @@ #include "qemu-queue.h" #include "monitor.h" #include "sysemu.h" +#include "trace.h" #include "qxl.h" @@ -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; } @@ -417,7 +418,7 @@ static void interface_set_compression_level(QXLInstance *sin, int level) { PCIQXLDevice *qxl = container_of(sin, PCIQXLDevice, ssd.qxl); - dprint(qxl, 1, "%s: %d\n", __FUNCTION__, level); + trace_qxl_interface_set_compression_level(level); qxl->shadow_rom.compression_level = cpu_to_le32(level); qxl->rom->compression_level = cpu_to_le32(level); qxl_rom_set_dirty(qxl); @@ -436,7 +437,7 @@ static void interface_get_init_info(QXLInstance *sin, QXLDevInitInfo *info) { PCIQXLDevice *qxl = container_of(sin, PCIQXLDevice, ssd.qxl); - dprint(qxl, 1, "%s:\n", __FUNCTION__); + trace_qxl_interface_get_init_info(); info->memslot_gen_bits = MEMSLOT_GENERATION_BITS; info->memslot_id_bits = MEMSLOT_SLOT_BITS; info->num_memslots = NUM_MEMSLOTS; @@ -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)); + switch (qxl->mode) { case QXL_MODE_VGA: - dprint(qxl, 2, "%s: vga\n", __FUNCTION__); ret = false; qemu_mutex_lock(&qxl->ssd.lock); if (qxl->ssd.update != NULL) { @@ -518,19 +520,18 @@ static int interface_get_command(QXLInstance *sin, struct QXLCommandExt *ext) } qemu_mutex_unlock(&qxl->ssd.lock); if (ret) { - dprint(qxl, 2, "%s %s\n", __FUNCTION__, qxl_mode_to_string(qxl->mode)); + trace_qxl_interface_get_command_ret(qxl_mode_to_string(qxl->mode)); qxl_log_command(qxl, "vga", ext); } return ret; case QXL_MODE_COMPAT: case QXL_MODE_NATIVE: case QXL_MODE_UNDEFINED: - dprint(qxl, 4, "%s: %s\n", __FUNCTION__, qxl_mode_to_string(qxl->mode)); ring = &qxl->ram->cmd_ring; if (SPICE_RING_IS_EMPTY(ring)) { return false; } - dprint(qxl, 2, "%s: %s\n", __FUNCTION__, qxl_mode_to_string(qxl->mode)); + trace_qxl_interface_get_command_ret(qxl_mode_to_string(qxl->mode)); SPICE_RING_CONS_ITEM(ring, cmd); ext->cmd = *cmd; ext->group_id = MEMSLOT_GROUP_GUEST; @@ -592,7 +593,7 @@ static inline void qxl_push_free_res(PCIQXLDevice *d, int flush) } SPICE_RING_PUSH(ring, notify); - dprint(d, 2, "free: push %d items, notify %s, ring %d/%d [%d,%d]\n", + trace_qxl_push_free_res( d->num_free_res, notify ? "yes" : "no", ring->prod - ring->cons, ring->num_items, ring->prod, ring->cons); @@ -642,7 +643,7 @@ static void interface_release_resource(QXLInstance *sin, } qxl->last_release = ext.info; qxl->num_free_res++; - dprint(qxl, 3, "%4d\r", qxl->num_free_res); + trace_qxl_interface_release_resource(qxl->num_free_res); qxl_push_free_res(qxl, 0); } @@ -716,7 +717,7 @@ static int interface_flush_resources(QXLInstance *sin) PCIQXLDevice *qxl = container_of(sin, PCIQXLDevice, ssd.qxl); int ret; - dprint(qxl, 1, "free: guest flush (have %d)\n", qxl->num_free_res); + trace_qxl_interface_flush_resources(qxl->num_free_res); ret = qxl->num_free_res; if (ret) { qxl_push_free_res(qxl, 1); @@ -736,7 +737,7 @@ static void interface_async_complete_io(PCIQXLDevice *qxl, QXLCookie *cookie) qxl->current_async = QXL_UNDEFINED_IO; qemu_mutex_unlock(&qxl->async_lock); - dprint(qxl, 2, "async_complete: %d (%p) done\n", current_async, cookie); + trace_qxl_interface_async_complete_io(current_async, cookie); if (!cookie) { fprintf(stderr, "qxl: %s: error, cookie is NULL\n", __func__); return; @@ -782,11 +783,13 @@ static void interface_update_area_complete(QXLInstance *sin, qemu_mutex_unlock(&qxl->ssd.lock); return; } + trace_qxl_interface_update_area_complete(surface_id, dirty->left, + dirty->right, dirty->top, dirty->bottom, num_updated_rects); if (qxl->num_dirty_rects + num_updated_rects > QXL_NUM_DIRTY_RECTS) { /* * overflow - treat this as a full update. Not expected to be common. */ - dprint(qxl, 1, "%s: overflow of dirty rects\n", __func__); + trace_qxl_interface_update_area_complete_overflow(QXL_NUM_DIRTY_RECTS); qxl->guest_primary.resized = 1; } if (qxl->guest_primary.resized) { @@ -802,8 +805,7 @@ static void interface_update_area_complete(QXLInstance *sin, qxl->dirty[qxl_i++] = dirty[i]; } qxl->num_dirty_rects += num_updated_rects; - 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); qemu_bh_schedule(qxl->update_area_bh); qemu_mutex_unlock(&qxl->ssd.lock); } @@ -857,7 +859,7 @@ static void qxl_enter_vga_mode(PCIQXLDevice *d) if (d->mode == QXL_MODE_VGA) { return; } - dprint(d, 1, "%s\n", __FUNCTION__); + trace_qxl_enter_vga_mode(); qemu_spice_create_host_primary(&d->ssd); d->mode = QXL_MODE_VGA; memset(&d->ssd.dirty, 0, sizeof(d->ssd.dirty)); @@ -868,7 +870,7 @@ static void qxl_exit_vga_mode(PCIQXLDevice *d) if (d->mode != QXL_MODE_VGA) { return; } - dprint(d, 1, "%s\n", __FUNCTION__); + trace_qxl_exit_vga_mode(); qxl_destroy_primary(d, QXL_SYNC); } @@ -905,7 +907,7 @@ static void qxl_reset_state(PCIQXLDevice *d) static void qxl_soft_reset(PCIQXLDevice *d) { - dprint(d, 1, "%s:\n", __FUNCTION__); + trace_qxl_soft_reset(); qxl_check_state(d); if (d->id == 0) { @@ -917,8 +919,7 @@ static void qxl_soft_reset(PCIQXLDevice *d) 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(); } static void qxl_reset_handler(DeviceState *dev) @@ -949,7 +950,7 @@ static void qxl_vga_ioport_write(void *opaque, uint32_t addr, uint32_t val) PCIQXLDevice *qxl = container_of(vga, PCIQXLDevice, vga); if (qxl->mode != QXL_MODE_VGA) { - dprint(qxl, 1, "%s\n", __FUNCTION__); + trace_qxl_vga_ioport_while_not_in_vga_mode(); qxl_destroy_primary(qxl, QXL_SYNC); qxl_soft_reset(qxl); } @@ -990,9 +991,7 @@ static void qxl_add_memslot(PCIQXLDevice *d, uint32_t slot_id, uint64_t delta, guest_start = le64_to_cpu(d->guest_slots[slot_id].slot.mem_start); guest_end = le64_to_cpu(d->guest_slots[slot_id].slot.mem_end); - dprint(d, 1, "%s: slot %d: guest phys 0x%" PRIx64 " - 0x%" PRIx64 "\n", - __FUNCTION__, slot_id, - guest_start, guest_end); + trace_qxl_add_memslot_guest(slot_id, guest_start, guest_end); PANIC_ON(slot_id >= NUM_MEMSLOTS); PANIC_ON(guest_start > guest_end); @@ -1039,9 +1038,8 @@ static void qxl_add_memslot(PCIQXLDevice *d, uint32_t slot_id, uint64_t delta, memslot.generation = d->rom->slot_generation = 0; qxl_rom_set_dirty(d); - dprint(d, 1, "%s: slot %d: host virt 0x%lx - 0x%lx\n", - __FUNCTION__, memslot.slot_id, - memslot.virt_start, memslot.virt_end); + trace_qxl_add_memslot_host(memslot.slot_id, memslot.virt_start, + memslot.virt_end); qemu_spice_add_memslot(&d->ssd, &memslot, async); d->guest_slots[slot_id].ptr = (void*)memslot.virt_start; @@ -1052,21 +1050,21 @@ static void qxl_add_memslot(PCIQXLDevice *d, uint32_t slot_id, uint64_t delta, static void qxl_del_memslot(PCIQXLDevice *d, uint32_t slot_id) { - dprint(d, 1, "%s: slot %d\n", __FUNCTION__, slot_id); + trace_qxl_del_memslot(slot_id); qemu_spice_del_memslot(&d->ssd, MEMSLOT_GROUP_HOST, slot_id); d->guest_slots[slot_id].active = 0; } 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)); } static void qxl_reset_surfaces(PCIQXLDevice *d) { - dprint(d, 1, "%s:\n", __FUNCTION__); + trace_qxl_reset_surfaces(); d->mode = QXL_MODE_UNDEFINED; qxl_spice_destroy_surfaces(d, QXL_SYNC); } @@ -1108,9 +1106,6 @@ static void qxl_create_guest_primary(PCIQXLDevice *qxl, int loadvm, assert(qxl->mode != QXL_MODE_NATIVE); qxl_exit_vga_mode(qxl); - dprint(qxl, 1, "%s: %dx%d\n", __FUNCTION__, - le32_to_cpu(sc->width), le32_to_cpu(sc->height)); - surface.format = le32_to_cpu(sc->format); surface.height = le32_to_cpu(sc->height); surface.mem = le64_to_cpu(sc->mem); @@ -1119,6 +1114,9 @@ static void qxl_create_guest_primary(PCIQXLDevice *qxl, int loadvm, surface.width = le32_to_cpu(sc->width); surface.type = le32_to_cpu(sc->type); surface.flags = le32_to_cpu(sc->flags); + trace_qxl_create_guest_primary(sc->width, sc->height, sc->mem, sc->format, + sc->position, sc->stride, sc->type, + sc->flags); surface.mouse_mode = true; surface.group_id = MEMSLOT_GROUP_GUEST; @@ -1142,7 +1140,7 @@ static int qxl_destroy_primary(PCIQXLDevice *d, qxl_async_io async) if (d->mode == QXL_MODE_UNDEFINED) { return 0; } - dprint(d, 1, "%s\n", __FUNCTION__); + trace_qxl_destroy_primary(); d->mode = QXL_MODE_UNDEFINED; qemu_spice_destroy_primary_surface(&d->ssd, 0, async); qxl_spice_reset_cursor(d); @@ -1169,8 +1167,7 @@ static void qxl_set_mode(PCIQXLDevice *d, int modenr, int loadvm) .mem = devmem + d->shadow_rom.draw_area_offset, }; - dprint(d, 1, "%s: mode %d [ %d x %d @ %d bpp devmem 0x%" PRIx64 " ]\n", - __func__, modenr, mode->x_res, mode->y_res, mode->bits, devmem); + trace_qxl_set_mode(modenr, mode->x_res, mode->y_res, mode->bits, devmem); if (!loadvm) { qxl_hard_reset(d, 0); } @@ -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)); /* be nice to buggy guest drivers */ if (io_port >= QXL_IO_UPDATE_AREA_ASYNC && io_port <= QXL_IO_DESTROY_ALL_SURFACES_ASYNC) { @@ -1259,7 +1256,7 @@ async_common: } d->current_async = orig_io_port; qemu_mutex_unlock(&d->async_lock); - dprint(d, 2, "start async %d (%"PRId64")\n", io_port, val); + trace_qxl_io_start_async(io_port, val); break; default: break; @@ -1299,7 +1296,7 @@ async_common: d->oom_running = 0; break; 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); break; case QXL_IO_LOG: @@ -1309,7 +1306,7 @@ async_common: } break; case QXL_IO_RESET: - dprint(d, 1, "QXL_IO_RESET\n"); + trace_qxl_io_reset(); qxl_hard_reset(d, 0); 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); break; @@ -1347,11 +1344,11 @@ async_common: async); goto cancel_async; } - dprint(d, 1, "QXL_IO_DESTROY_PRIMARY (async=%d) (%s)\n", async, - qxl_mode_to_string(d->mode)); + trace_qxl_io_destroy_primary(async, + qxl_mode_to_string(d->mode)); if (!qxl_destroy_primary(d, async)) { - dprint(d, 1, "QXL_IO_DESTROY_PRIMARY_ASYNC in %s, ignored\n", - qxl_mode_to_string(d->mode)); + trace_qxl_io_destroy_primary_ignored( + qxl_mode_to_string(d->mode)); goto cancel_async; } break; @@ -1371,14 +1368,12 @@ async_common: ring->prod, ring->cons); } qxl_push_free_res(d, 1 /* flush */); - dprint(d, 1, "QXL_IO_FLUSH_RELEASE exit (%s, s#=%d, res#=%d,%p)\n", - qxl_mode_to_string(d->mode), d->guest_surfaces.count, - d->num_free_res, d->last_release); + trace_qxl_io_flush_release(qxl_mode_to_string(d->mode), + d->guest_surfaces.count, d->num_free_res, d->last_release); break; } case QXL_IO_FLUSH_SURFACES_ASYNC: - dprint(d, 1, "QXL_IO_FLUSH_SURFACES_ASYNC" - " (%"PRId64") (%s, s#=%d, res#=%d)\n", + trace_qxl_io_flush_surfaces_async( val, qxl_mode_to_string(d->mode), d->guest_surfaces.count, d->num_free_res); qxl_spice_flush_surfaces_async(d); @@ -1404,9 +1399,7 @@ cancel_async: static uint64_t ioport_read(void *opaque, target_phys_addr_t addr, unsigned size) { - PCIQXLDevice *d = opaque; - - dprint(d, 1, "%s: unexpected\n", __FUNCTION__); + trace_qxl_io_read_unexpected(); return 0xff; } @@ -1445,23 +1438,24 @@ static void qxl_send_events(PCIQXLDevice *d, uint32_t events) qxl_update_irq(d); } else { if (write(d->pipe[1], d, 1) != 1) { - dprint(d, 1, "%s: write to pipe failed\n", __FUNCTION__); + trace_qxl_send_events_write_to_pipe_failed(); } } } static void init_pipe_signaling(PCIQXLDevice *d) { - if (pipe(d->pipe) < 0) { - dprint(d, 1, "%s: pipe creation failed\n", __FUNCTION__); - return; - } - fcntl(d->pipe[0], F_SETFL, O_NONBLOCK); - fcntl(d->pipe[1], F_SETFL, O_NONBLOCK); - fcntl(d->pipe[0], F_SETOWN, getpid()); + if (pipe(d->pipe) < 0) { + fprintf(stderr, "%s:%s: qxl pipe creation failed\n", + __FILE__, __func__); + exit(1); + } + fcntl(d->pipe[0], F_SETFL, O_NONBLOCK); + fcntl(d->pipe[1], F_SETFL, O_NONBLOCK); + fcntl(d->pipe[0], F_SETOWN, getpid()); - qemu_thread_get_self(&d->main); - qemu_set_fd_handler(d->pipe[0], pipe_read, NULL, d); + qemu_thread_get_self(&d->main); + qemu_set_fd_handler(d->pipe[0], pipe_read, NULL, d); } /* graphics console */ @@ -1556,8 +1550,7 @@ static void qxl_dirty_surfaces(PCIQXLDevice *qxl) surface_offset -= vram_start; surface_size = cmd->u.surface_create.height * abs(cmd->u.surface_create.stride); - dprint(qxl, 3, "%s: dirty surface %d, offset %d, size %d\n", __func__, - i, (int)surface_offset, surface_size); + trace_qxl_dirty_surfaces(i, (int)surface_offset, surface_size); qxl_set_dirty(&qxl->vram_bar, surface_offset, surface_size); } } @@ -1791,7 +1784,7 @@ static void qxl_pre_save(void *opaque) PCIQXLDevice* d = opaque; uint8_t *ram_start = d->vga.vram_ptr; - dprint(d, 1, "%s:\n", __FUNCTION__); + trace_qxl_pre_save(); if (d->last_release == NULL) { d->last_release_offset = 0; } else { @@ -1804,10 +1797,10 @@ static int qxl_pre_load(void *opaque) { PCIQXLDevice* d = opaque; - dprint(d, 1, "%s: start\n", __FUNCTION__); + trace_qxl_pre_load_enter(); qxl_hard_reset(d, 1); qxl_exit_vga_mode(d); - dprint(d, 1, "%s: done\n", __FUNCTION__); + trace_qxl_pre_load_exit(); return 0; } @@ -1819,7 +1812,7 @@ static void qxl_create_memslots(PCIQXLDevice *d) if (!d->guest_slots[i].active) { continue; } - dprint(d, 1, "%s: restoring guest slot %d\n", __func__, i); + trace_qxl_create_memslots(i); qxl_add_memslot(d, i, 0, QXL_SYNC); } } @@ -1831,7 +1824,7 @@ static int qxl_post_load(void *opaque, int version) QXLCommandExt *cmds; int in, out, newmode; - dprint(d, 1, "%s: start\n", __FUNCTION__); + trace_qxl_post_load_enter(); assert(d->last_release_offset < d->vga.vram_size); if (d->last_release_offset == 0) { @@ -1842,8 +1835,7 @@ static int qxl_post_load(void *opaque, int version) d->modes = (QXLModes*)((uint8_t*)d->rom + d->rom->modes_offset); - dprint(d, 1, "%s: restore mode (%s)\n", __FUNCTION__, - qxl_mode_to_string(d->mode)); + trace_qxl_post_load_restore_mode(qxl_mode_to_string(d->mode)); newmode = d->mode; d->mode = QXL_MODE_UNDEFINED; @@ -1885,7 +1877,7 @@ static int qxl_post_load(void *opaque, int version) qxl_set_mode(d, d->shadow_rom.mode, 1); break; } - dprint(d, 1, "%s: done\n", __FUNCTION__); + trace_qxl_post_load_exit(); return 0; } diff --git a/trace-events b/trace-events index dfe28ed..0853a1b 100644 --- a/trace-events +++ b/trace-events @@ -665,3 +665,50 @@ displaysurface_resize(void *display_state, void *display_surface, int width, int # vga.c ppm_save(const char *filename, void *display_surface) "%s surface=%p" + +# hw/qxl.c +qxl_io_create_primary(bool async) "async=%d" +qxl_create_guest_primary(uint32_t width, uint32_t height, uint64_t mem, uint32_t format, uint32_t position, int32_t stride, uint32_t type, uint32_t flags) "%dx%d mem=%lx %d,%d,%d,%d,%d" +qxl_interface_attach_worker(void) "" +qxl_interface_set_compression_level(int64_t level) "%"PRId64 +qxl_interface_get_init_info(void) "" +qxl_enter_vga_mode(void) "" +qxl_exit_vga_mode(void) "" +qxl_soft_reset(void) "" +qxl_hard_reset_enter(int64_t loadvm) "loadvm=%"PRId64"" +qxl_hard_reset_exit(void) "" +qxl_vga_ioport_while_not_in_vga_mode(void) "(reset to VGA mode because of VGA io)" +qxl_add_memslot_guest(uint32_t slot_id, uint64_t guest_start, uint64_t guest_end) "%u: guest phys 0x%"PRIx64 " - 0x%" PRIx64 +qxl_add_memslot_host(uint32_t slot_id, unsigned long virt_start, unsigned long virt_end) "%u: host virt 0x%lx - 0x%lx" +qxl_del_memslot(uint32_t slot_id) "%u" +qxl_reset_memslots(void) "" +qxl_reset_surfaces(void) "" +qxl_destroy_primary(void) "" +qxl_set_mode(int modenr, uint32_t x_res, uint32_t y_res, uint32_t bits, uint64_t devmem) "mode=%d [ x=%d y=%d @ bpp=%d devmem=0x%" PRIx64 " ]" +qxl_io_unexpected_vga_mode(uint32_t io_port, const char *desc) "0x%x (%s)" +qxl_io_start_async(uint32_t io_port, int64_t val) "%u (%"PRId64")" +qxl_io_set_mode(uint64_t val) "%"PRIu64 +qxl_io_reset(void) "" +qxl_io_destroy_primary(int async, const char *mode) "%d (%s)" +qxl_io_destroy_primary_ignored(const char *mode) "%s" +qxl_io_flush_release(const char *mode, uint32_t surface_count, uint32_t num_free_res, void *last_release) "flush complete %s, s#=%d, res#=%d, %p" +qxl_io_flush_surfaces_async(uint64_t val, const char *mode, uint32_t surface_count, uint32_t num_free_res) "val=%"PRIu64", %s, s#=%d, res#=%d" +qxl_io_read_unexpected(void) "" +qxl_send_events_write_to_pipe_failed(void) "" +qxl_interface_get_command_enter(const char *mode) "%s" +qxl_interface_get_command_ret(const char *mode) "%s" +qxl_push_free_res(uint32_t free_res, const char *notify, uint32_t ring_has, uint32_t ring_size, uint32_t prod, uint32_t cons) "%d items, notify %s, ring %d/%d [%d,%d]" +qxl_interface_release_resource(uint32_t free_res) "%4d" +qxl_interface_flush_resources(uint32_t free_res) "%d" +qxl_interface_async_complete_io(uint32_t current_async, void *cookie) "%d (%p) done" +qxl_interface_update_area_complete_overflow(int max) "(%d)" +qxl_interface_update_area_complete_schedule_bh(uint32_t num_dirty) "#dirty=%d" +qxl_dirty_surfaces(int surface, int offset, int size) "surface=%d offset=%d size=%d" +qxl_pre_save(void) "" +qxl_pre_load_enter(void) "" +qxl_pre_load_exit(void) "" +qxl_create_memslots(int slot) "%d" +qxl_post_load_enter(void) "" +qxl_post_load_restore_mode(const char *mode) "%s" +qxl_post_load_exit(void) "" +qxl_interface_update_area_complete(uint32_t surface_id, uint32_t dirty_left, uint32_t dirty_right, uint32_t dirty_top, uint32_t dirty_bottom, uint32_t num_updated_rects) "surface=%d [%d,%d,%d,%d] #=%d"
dprint is still used for qxl_init_common one time prints. Signed-off-by: Alon Levy <alevy@redhat.com> --- hw/qxl.c | 140 +++++++++++++++++++++++++++------------------------------ trace-events | 47 +++++++++++++++++++ 2 files changed, 113 insertions(+), 74 deletions(-)